Je veux time
une commande qui se compose de deux commandes distinctes avec une sortie de tuyauterie à l'autre. Par exemple, considérez les deux scripts ci-dessous:
$ cat foo.sh
#!/bin/sh
sleep 4
$ cat bar.sh
#!/bin/sh
sleep 2
Maintenant, comment puis-je time
signaler le temps pris par foo.sh | bar.sh
(et oui, je sais que la pipe n'a aucun sens ici, mais ce n'est qu'un exemple)? Cela fonctionne comme prévu si je les exécute séquentiellement dans un sous-shell sans tuyauterie:
$ time ( foo.sh; bar.sh )
real 0m6.020s
user 0m0.010s
sys 0m0.003s
Mais je ne peux pas le faire fonctionner lors de la tuyauterie:
$ time ( foo.sh | bar.sh )
real 0m4.009s
user 0m0.007s
sys 0m0.003s
$ time ( { foo.sh | bar.sh; } )
real 0m4.008s
user 0m0.007s
sys 0m0.000s
$ time sh -c "foo.sh | bar.sh "
real 0m4.006s
user 0m0.000s
sys 0m0.000s
J'ai lu une question similaire ( comment exécuter le temps sur plusieurs commandes ET écrire la sortie de temps dans un fichier? ) Et j'ai également essayé l' time
exécutable autonome :
$ /usr/bin/time -p sh -c "foo.sh | bar.sh"
real 4.01
user 0.00
sys 0.00
Cela ne fonctionne même pas si je crée un troisième script qui exécute uniquement le canal:
$ cat baz.sh
#!/bin/sh
foo.sh | bar.sh
Et puis le temps que:
$ time baz.sh
real 0m4.009s
user 0m0.003s
sys 0m0.000s
Fait intéressant, il n'apparaît pas comme s'il time
quitte dès que la première commande est effectuée. Si je change bar.sh
pour:
#!/bin/sh
sleep 2
seq 1 5
Et là time
encore, je m'attendais à ce que la time
sortie soit imprimée avant le seq
mais ce n'est pas le cas:
$ time ( { foo.sh | bar.sh; } )
1
2
3
4
5
real 0m4.005s
user 0m0.003s
sys 0m0.000s
On dirait que time
ne compte pas le temps qu'il a fallu pour exécuter bar.sh
malgré l'attente de sa fin avant d'imprimer son rapport 1 .
Tous les tests ont été exécutés sur un système Arch et en utilisant la version bash 4.4.12 (1). Je ne peux utiliser que bash pour le projet dont il s'agit, donc même si zsh
un autre shell puissant peut le contourner, ce ne sera pas une solution viable pour moi.
Alors, comment puis-je obtenir le temps nécessaire à l'exécution d'un ensemble de commandes dirigées? Et pendant que nous y sommes, pourquoi ça ne marche pas? Il semble que time
la sortie soit immédiate dès que la première commande est terminée. Pourquoi?
Je sais que je peux obtenir les temps individuels avec quelque chose comme ça:
( time foo.sh ) 2>foo.time | ( time bar.sh ) 2> bar.time
Mais je voudrais quand même savoir s'il est possible de chronométrer le tout en une seule opération.
1 Cela ne semble pas être un problème de tampon, j'ai essayé d'exécuter les scripts avec unbuffered
et stdbuf -i0 -o0 -e0
et les chiffres étaient toujours imprimés avant la time
sortie.
Réponses:
Il est travaille.
Les différentes parties d'un pipeline sont exécutées simultanément. La seule chose qui synchronise / sérialise les processus dans le pipeline est IO, c'est-à-dire qu'un processus écrit dans le processus suivant dans le pipeline et le processus suivant lit ce que le premier écrit. En dehors de cela, ils s'exécutent indépendamment les uns des autres.
Puisqu'il n'y a pas de lecture ou d'écriture entre les processus de votre pipeline, le temps nécessaire pour exécuter le pipeline est celui de l'
sleep
appel le plus long .Vous pourriez aussi bien avoir écrit
Terdon a publié quelques exemples de scripts légèrement modifiés dans le chat :
et
La question était "pourquoi
time ( sh foo.sh | sh bar.sh )
retourne 4 secondes au lieu de 3 + 3 = 6 secondes?"Pour voir ce qui se passe, y compris l'heure approximative à laquelle chaque commande est exécutée, on peut le faire (la sortie contient mes annotations):
Donc, pour conclure, le pipeline prend 4 secondes, pas 6, en raison de la mise en mémoire tampon de la sortie des deux premiers appels vers
echo
infoo.sh
.la source
ksh93
n'attendent que le dernier composant du pipeline (sleep 3 | sleep 1
durerait 1 seconde). le shell Bourne n'a pas detime
mot-clé, mais dansksh93
, lorsqu'il est exécuté avectime
, tous les composants sont attendus.sleep 10 | sleep 1
prend une seconde touttime sleep 10 | sleep 1
en 10 secondes en ksh93. Dans le shell Bourne,time sleep 10 | sleep 1
cela prendrait une seconde, mais vous obtiendriez le temps de sortie (poursleep 10
seulement et à partir de/usr/bin/time
) du bleu 9 secondes plus tard.time
chronomètre correctement le pipeline, mais modifie le comportement du shell dans ksh93.(sleep 10 | sleep 1)
prend 1 seconde,time (sleep 10 | sleep 1)
prend 10 secondes.{ (sleep 10 | sleep 1); echo x; }
sortiesx
après 1 seconde,time { (sleep 10 | sleep 1); echo x; }
sortiesx
après 10 secondes. Même chose si vous mettez ce code dans une fonction et chronométrez la fonction.ksh93
comme danszsh
(-o promptsubst
ici), vous pouvez fairetypeset -F SECONDS
pour obtenir un nombre de secondes moins approximatif (POSIXsh
n'en a pasSECONDS
)Serait-ce un meilleur exemple?
Les scripts busyloop pendant 3 et 4 secondes (resp.), Ce qui prend un total de 4 secondes en temps réel en raison de l'exécution parallèle, et 7 secondes de temps CPU. (au moins environ.)
Ou ca:
Ceux-ci ne fonctionnent pas en parallèle, donc le temps total pris est de 5 secondes. Tout est passé à dormir, donc pas de temps CPU utilisé.
la source
Si vous en avez,
sysdig
vous pouvez insérer des traceurs à des points arbitraires, en supposant que vous pouvez modifier le code pour ajouter les écritures nécessaires à/dev/null
(mais cela échoue à votre exigence "d'opération unique"), puis enregistrez les choses via
puis vous aurez probablement besoin d'un burin sysdig pour exporter uniquement les durées
qui une fois enregistré dans votre
sysdig/chisels
répertoire en tant que fichierspantagduration.lua
peut être utilisé commeOu vous pouvez jouer avec
csysdig
ou la sortie JSON.la source