パイプライン時間を測定する方法は?

パイプライン時間を測定する方法は?

私は2つの別々のコマンドで構成されたコマンドが欲しいですtime。 1 つは出力を別のコマンドにパイプします。たとえば、次の2つのスクリプトを考えてみましょう。

$ cat foo.sh
#!/bin/sh
sleep 4

$ cat bar.sh
#!/bin/sh
sleep 2

今のtime時間をどのように報告できますかfoo.sh | bar.sh? (はい、ここではパイプが意味をなさないことがわかりますが、これは単なる例です。)パイプなしでサブシェルで順番に実行すると、期待どおりに機能します。

$ time ( foo.sh; bar.sh )

real    0m6.020s
user    0m0.010s
sys     0m0.003s

ただし、パイピング時に機能させることはできません。

$ 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

同様の質問を読んだ(複数のコマンドで時間を実行し、時間出力をファイルに書き込む方法は?)スタンドアロンtime実行ファイルを試しました。

$ /usr/bin/time -p sh -c "foo.sh | bar.sh"
real 4.01
user 0.00
sys 0.00

パイプラインのみを実行する3番目のスクリプトを生成しても機能しません。

$ cat baz.sh
#!/bin/sh
foo.sh | bar.sh

それから時間:

$ time baz.sh

real    0m4.009s
user    0m0.003s
sys     0m0.000s

time興味深いことに、最初のコマンドが完了した直後に終了しないようです。次のように変更した場合bar.sh

#!/bin/sh
sleep 2
seq 1 5

繰り返しますが、以前に出力が印刷されるとtime予想していましたが、そうではありません。timeseq

$ time ( { foo.sh | bar.sh; } )
1
2
3
4
5

real    0m4.005s
user    0m0.003s
sys     0m0.000s

レポート1を印刷する前に完了するのを待っているにもかかわらず、time実行にかかる時間は計算されないようです。bar.sh

すべてのテストは、Archシステムでbash 4.4.12(1)リリースを使用して実行されました。私はプロジェクトでbashだけを使うことができ、これはそれの一部なので、zsh他の強力なシェルがこの問題を解決できるとしても、それは私にとって実行可能な解決策ではありません。

それでは、一連のパイプラインコマンドを実行するのにかかる時間をどのように取得できますか?そして、私たちがこれを行うとき、なぜ動作しませんか?time最初のコマンドが完了するとすぐに終了するようです。なぜ?

私は次の方法で個人的な時間を持つことができることを知っています。

( time foo.sh ) 2>foo.time | ( time bar.sh ) 2> bar.time

しかし、すべてのタスクを単一のタスクで時間を測定することが可能であるかどうかはまだ知りたいです。


1 これはバッファの問題ではないようです。とを使ってスクリプトを実行してみましたが、unbuffered出力する前にstdbuf -i0 -o0 -e0数字がtime印刷され続けます。

ベストアンサー1

それはい布材。

パイプラインの複数の部分が同時に実行されます。パイプ内でプロセスを同期/シリアル化する唯一のことはIOです。つまり、あるプロセスがパイプの次のプロセスに書き込み、次のプロセスが最初のプロセスによって書き込まれた内容を読み取ります。これ以外にも公演をしています。独立してお互い。

パイプ内のプロセス間で読み取りまたは書き込みが発生しないため、パイプの実行にかかる時間がsleep最も長い呼び出し時間です。

また、書いたかもしれません

time ( foo.sh & bar.sh &; wait )

ここにリリースチャットで少し変更されたいくつかのサンプルスクリプト:

#!/bin/sh
# This is "foo.sh"
echo 1; sleep 1
echo 2; sleep 1
echo 3; sleep 1
echo 4

そして

#!/bin/sh
# This is "bar.sh"
sleep 2
while read line; do
  echo "LL $line"
done
sleep 1

質問は「time ( sh foo.sh | sh bar.sh )3+3 = 6秒ではなく4秒が返されるのはなぜですか?」です。

各コマンドが実行されたおおよその時間を含む何が起こっているかを確認するには、次のようにします(出力には私の説明が含まれます)。

$ time ( env PS4='$SECONDS foo: ' sh -x foo.sh | PS4='$SECONDS bar: ' sh -x bar.sh )
0 bar: sleep 2
0 foo: echo 1     ; The output is buffered
0 foo: sleep 1
1 foo: echo 2     ; The output is buffered
1 foo: sleep 1
2 bar: read line  ; "bar" wakes up and reads the two first echoes
2 bar: echo LL 1
LL 1
2 bar: read line
2 bar: echo LL 2
LL 2
2 bar: read line  ; "bar" waits for more
2 foo: echo 3     ; "foo" wakes up from its second sleep
2 bar: echo LL 3
LL 3
2 bar: read line
2 foo: sleep 1
3 foo: echo 4     ; "foo" does the last echo and exits
3 bar: echo LL 4
LL 4
3 bar: read line  ; "bar" fails to read more
3 bar: sleep 1    ; ... and goes to sleep for one second

real    0m4.14s
user    0m0.00s
sys     0m0.10s

したがって、inへの最初の2つの呼び出しの出力バッファリングは、全体としてechoパイプラインに6秒ではなく4秒かかりますfoo.sh

おすすめ記事