☰

如何为管道计时？

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（是的，我知道管道在这里没有意义，但这只是一个例子）？如果我在子 shell 中按顺序运行它们而不使用管道，它确实会按预期工作：

$ 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一次，我期望time在之前打印输出，seq但事实并非如此：

$ 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)-release。我只能在项目中使用 bash，这是其中的一部分，所以即使zsh或其他一些强大的 shell 可以绕过它，这对我来说也不是一个可行的解决方案。

那么，如何获取一组管道命令运行所需的时间呢？而且，当我们这样做时，为什么它不起作用？看起来time第一个命令一完成就立即退出。为什么？

我知道我可以通过这样的方式获得个人时间：

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

但我仍然想知道是否有可能将整个事情作为一个单一的操作进行计时。

1 这似乎不是缓冲区问题，我尝试使用 and 运行脚本，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 )返回 4 秒而不是 3+3 = 6 秒？”

要查看发生了什么，包括执行每个命令的大致时间，可以这样做（输出包含我的注释）：

$ 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

因此，总而言之，由于对echoin的前两次调用的输出进行了缓冲，管道需要 4 秒而不是 6 秒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 秒的实时时间和 7 秒的 CPU 时间。 （至少大约。）

或这个：

$ 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 chisel 来导出持续时间

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
...

或者您可以使用csysdigJSON 输出。

答案4

太有趣了，我知道这是一个旧线程，但我发现自己处于同样的情况。我发现别名是一个简单的解决方法。至少这适用于bash和fish。不确定所有贝壳。

代替：time ( foo.sh | bar.sh )

尝试：

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

相关内容