☰

파이프라인 시간을 측정하는 방법은 무엇입니까?

tag-icon • tag-icon bash shell pipe time
파이프라인 시간을 측정하는 방법은 무엇입니까?

나는 두 개의 개별 명령으로 구성된 명령을 원합니다 time. 하나는 출력을 다른 명령으로 파이프합니다. 예를 들어 다음 두 스크립트를 고려해보세요.

$ 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

파이프라인만 실행하는 세 번째 스크립트를 생성하면 작동하지도 않습니다.

$ 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 에 대한 처음 두 호출의 출력 버퍼링으로 인해 전체적으로 echo파이프라인에 6초가 아닌 4초가 소요됩니다 foo.sh.

답변2

이것이 더 나은 예입니까?

$ time perl -e 'alarm(3); 1 while 1;' | perl -e 'alarm(4); 1 while 1;'
Alarm clock

real    0m4.004s
user    0m6.992s
sys     0m0.004s

스크립트 busyloop은 각각 3초, 4초 동안 지속되었으며, 병렬 실행으로 인해 실제 시간은 총 4초, CPU 시간은 7초가 걸렸습니다. (적어도 대략적으로는)

아니면 이거:

$ time ( sleep 2; echo) | ( read x; sleep 3 )

real    0m5.004s
user    0m0.000s
sys     0m0.000s

병렬로 실행되지 않으므로 총 시간은 5초입니다. 모두 잠자는 데 소비되므로 CPU 시간이 사용되지 않습니다.

답변3

가능한 경우 sysdig추적기를 삽입할 수 있습니다.언제든지 코드를 수정하여 필요한 쓰기를 추가할 수 있다고 가정합니다./dev/null

echo '>::blah::' >/dev/null
foo.sh | bar.sh
echo '<::blah::' >/dev/null

(그러나 이는 "단일 작업" 요구 사항을 충족하지 않습니다.) 그런 다음 다음을 통해 항목을 기록합니다.

$ sudo sysdig -w blalog "span.tags contains blah"

그런 다음 기간을 내보내려면 sysdig 끌이 필요할 수 있습니다.

description = "Exports sysdig span tag durations";
short_description = "Export span tag durations.";
category = "Tracers";

args = {}

function on_init()
    ftags = chisel.request_field("span.tags")
    flatency = chisel.request_field("span.duration")
    chisel.set_filter("evt.type=tracer and evt.dir=<")
    return true
end

function on_event()
    local tags = evt.field(ftags)
    local latency = evt.field(flatency)
    if latency then
        print(tostring(tags) .. "\t" .. tonumber(latency) / 1e9)
    end
    return true
end

디렉토리 에 저장되면 sysdig/chisels파일을 spantagduration.lua다음과 같이 사용할 수 있습니다.

$ sysdig -r blalog -c spantagduration
...

csysdig또는 JSON 출력을 사용할 수 있습니다 .

답변4

너무 재밌네요. 오래된 스레드라는 건 알지만 저도 같은 상황에 처해 있었습니다. 앨리어싱이 쉬운 해결 방법이라는 것을 알았습니다. 적어도 이것은 bash와 fish에서 작동합니다. 모든 껍질에 대해 잘 모르겠습니다.

바꾸다:time ( foo.sh | bar.sh )

노력하다:

alias foobar="foo.sh | bar.sh" time foobar

관련 정보