为什么向标准输出打印信息很慢?能否加快速度?

203
我一直对使用print语句输出到终端所需的时间感到惊讶/沮丧。最近有些缓慢的日志记录之后,我决定调查一下,并非常惊讶地发现,几乎所有的时间都花在等待终端处理结果上。
写入stdout能否以某种方式加速?
我编写了一个脚本(本问题底部的“print_timer.py”)来比较向stdout、文件和将stdout重定向到/dev/null时写入100k行的时间。以下是计时结果:
$ python print_timer.py
this is a test
this is a test
<snipped 99997 lines>
this is a test
-----
timing summary (100k lines each)
-----
print                         :11.950 s
write to file (+ fsync)       : 0.122 s
print with stdout = /dev/null : 0.050 s

哇。为了确保Python没有在幕后执行一些操作,例如识别我重复分配stdout到/dev/null等操作,我在脚本外进行了重定向...

$ python print_timer.py > /dev/null
-----
timing summary (100k lines each)
-----
print                         : 0.053 s
write to file (+fsync)        : 0.108 s
print with stdout = /dev/null : 0.045 s

因此,这不是Python的技巧,只是终端。我一直知道将输出转储到/dev/null可以加快速度,但从未想过它如此重要!

令我惊奇的是tty有多慢。如何才能使写入物理磁盘比写入“屏幕”(可能是全RAM操作)更快,并且实际上与使用/dev/null简单转储一样快?

此链接讨论了终端将阻止I/O,以便“解析[输入],更新其帧缓冲区,与X服务器通信以滚动窗口等等”,但我并不完全明白。为什么会需要这么长时间呢?

我希望没有其他方法(除了更快的tty实现?),但无论如何都想问问。


更新:在阅读了一些评论后,我想知道我的屏幕尺寸对打印时间的实际影响有多大,结果影响还是很大的。上面那些极慢的数字是在我的 Gnome 终端放大到 1920x1200 的情况下得出的。如果我将其缩小,打印时间就会减少...

-----
timing summary (100k lines each)
-----
print                         : 2.920 s
write to file (+fsync)        : 0.121 s
print with stdout = /dev/null : 0.048 s

那肯定更好(~4倍),但这并没有改变我的问题。它只是在我的问题上增加了,因为我不明白为什么终端屏幕渲染会减慢写入stdout的应用程序。为什么我的程序需要等待屏幕渲染才能继续?
所有终端/tty应用程序都不是平等创建的吗?我还没有尝试过。真的很像终端应该能够缓冲所有传入的数据,无形地解析/渲染它,并以合理的帧速率仅呈现当前屏幕配置中可见的最新块。所以如果我可以在约0.1秒内写入+ fsync到磁盘,终端应该能够以相同的顺序完成相同的操作(在执行此操作时可能会更新几次屏幕)。
我仍然希望有一个tty设置可以从应用程序端更改,使程序员的行为更好。如果这严格是终端应用程序问题,那么这甚至可能不属于StackOverflow?
我错过了什么?

这是用于生成计时的Python程序:

import time, sys, tty
import os

lineCount = 100000
line = "this is a test"
summary = ""

cmd = "print"
startTime_s = time.time()
for x in range(lineCount):
    print line
t = time.time() - startTime_s
summary += "%-30s:%6.3f s\n" % (cmd, t)

#Add a newline to match line outputs above...
line += "\n"

cmd = "write to file (+fsync)"
fp = file("out.txt", "w")
startTime_s = time.time()
for x in range(lineCount):
    fp.write(line)
os.fsync(fp.fileno())
t = time.time() - startTime_s
summary += "%-30s:%6.3f s\n" % (cmd, t)

cmd = "print with stdout = /dev/null"
sys.stdout = file(os.devnull, "w")
startTime_s = time.time()
for x in range(lineCount):
    fp.write(line)
t = time.time() - startTime_s
summary += "%-30s:%6.3f s\n" % (cmd, t)

print >> sys.stderr, "-----"
print >> sys.stderr, "timing summary (100k lines each)"
print >> sys.stderr, "-----"
print >> sys.stderr, summary

12
写入标准输出的整个目的是为了让人类能够阅读输出。世界上没有人可以在12秒内阅读10000行文本,那么使stdout更快的意义何在? - Seun Osewa
22
一个例子(引发我的问题)是在执行类似 print statement debugging 的操作时。你想要运行程序并直接看到结果。很显然,大多数行都会飞快地通过而你无法看到,但当异常发生(或你遇到了你仔细放置的条件getch/raw_input/sleep语句)时,你希望直接查看打印输出,而不是不断地打开或刷新文件视图。 - Russ
3
打印语句调试是终端设备(即终端)默认采用行缓冲而不是块缓冲的原因之一:如果程序挂起并且最后几行调试输出仍然在缓冲区中而没有刷新到终端上,那么调试输出将毫无用处。 - Stephen C. Steel
@Stephen:这就是为什么我没有花太多时间追求评论者声称通过增加缓冲区大小来获得巨大改进的原因。这完全违背了调试打印的目的!虽然我在调查时进行了一些实验,但并没有看到净改进。我仍然对这种差异很好奇,但不是非常关心。 - Russ
有时候对于运行时间非常长的程序,我会每隔n秒钟在stdout上打印当前行 -- 类似于在curses应用程序中设置刷新延迟。这并不完美,但偶尔可以让我知道自己在哪里。 - rkulla
4
不!不要再说了!将输出写入标准输出是为了在标准位置输出。不要将标准输出和终端混为一谈。整个问题都是错误的。将输出写入标准输出并不比写入其他文件慢。写入终端是很慢的。标准输出不是终端。请原谅我大声喊叫,但我想再重复一遍。不要混淆标准输出和tty。它们是两个非常不同的东西,只是通常相关联。 - William Pursell
6个回答

189

如何解释写入物理磁盘的速度远远快于写入“屏幕”(可能是完全基于RAM的操作),并且实际上与简单地将数据倾倒到/dev/null相当?

恭喜,您刚刚发现了I/O缓冲的重要性。:-)

磁盘似乎更快,因为它高度缓冲:所有Python的write()调用在实际写入物理磁盘之前就已经返回了。(操作系统稍后会将许多个单独的写入组合成一个大的、有效的块进行写入。)

另一方面,终端几乎没有缓冲:每个单独的print/write(line)等待完整的写入(即显示到输出设备)完成。

为了公平比较,您必须使文件测试使用与终端相同的输出缓冲区,您可以通过修改示例来实现:

fp = file("out.txt", "w", 1)   # line-buffered, like stdout
[...]
for x in range(lineCount):
    fp.write(line)
    os.fsync(fp.fileno())      # wait for the write to actually complete
我在我的机器上运行了你的文件写入测试,并启用了缓冲区,在这里100,000行也只需要0.05秒。
但是,如果按照上述修改使用非缓冲写入,则仅将1,000行写入磁盘就需要40秒。我已经放弃等待写入100,000行,但从之前的数据来看,需要超过一个小时
这让终端的11秒显得微不足道,不是吗?
因此,回答你最初的问题,考虑到所有情况,向终端写入实际上非常快,没有太多提高速度的余地(但单个终端在执行工作方面确实存在差异;请参见Russ对此答案的评论)。
(你可以添加更多的写入缓冲区,例如磁盘I/O,但然后你将不能看到写入到终端的内容,直到缓冲区被刷新。这是一种权衡:交互性与批量效率之间的权衡。)

6
我遇到了I/O缓冲问题...你提醒我应该进行fsync以获得真正的完成时间比较(我将更新问题),但是对于每一行进行fsync是疯狂的。难道一个tty确实需要这样吗?难道没有类似于文件的终端/操作系统侧面的缓冲等效物吗?也就是说,应用程序写入标准输出并在终端渲染到屏幕之前返回,终端(或操作系统)会将所有内容缓冲起来。然后终端可以以可见帧率合理地渲染尾部到屏幕上。针对每一行都有效阻塞似乎很傻。我感觉我仍然缺少某些东西。 - Russ
你可以使用类似于 os.fdopen(sys.stdout.fileno(), 'w', BIGNUM) 的方法自己打开一个带有大缓冲区的标准输出句柄。但这几乎永远不会有用,因为几乎所有应用都必须记得在每行用户预期输出后显式刷新。 - Pi Delport
1
我之前尝试过使用巨大的(高达10MB,使用fp = os.fdopen(sys.__stdout__.fileno(),'w',10000000))Python端缓冲区。但是对性能没有任何影响。也就是说,终端延迟仍然很长。这让我想到/意识到,你只是推迟了慢速终端的问题...当Python的缓冲区最终刷新时,终端似乎仍然需要在返回之前对流执行相同总量的处理。 - Russ
9
请注意,这个答案是误导性的和错误的(抱歉!)。特别是错误地说“没有太多的余地使它比11秒更快”。请查看我对该问题的回答,我展示了wterm终端在0.26秒内实现了相同的11秒结果。 - Russ
2
Russ:感谢您的反馈!在我的这一端,一个更大的fdopen缓冲区(2MB)确实产生了巨大的影响:它将打印时间从几秒钟降至0.05秒,与文件输出相同(使用gnome-terminal)。 - Pi Delport

109

感谢所有评论! 在你们的帮助下,我最终自己回答了这个问题。不过自问自答感觉有点不妥吧。

问题1:为什么输出到标准输出很慢?

回答: 输出到标准输出本身并慢。 慢的是你使用的终端。 这与应用程序端的I/O缓冲(例如:Python文件缓冲)几乎没有关系。请看下面的解释。

问题2:如何加速输出?

回答:可以加速输出,但似乎不能从程序端(即输出到标准输出的一方)实现。要加速,请使用速度更快的不同终端模拟器。

说明……

我尝试使用一个自称“轻量级”的终端程序称作wterm,得到了非常好的结果。以下是在1920x1200的wterm上运行我的测试脚本时的输出结果,而在相同系统上使用gnome-terminal的基本打印选项需要12秒:

-----
时间摘要(每100K行)
-----
print                         : 0.261 s
write to file (+fsync)        : 0.110 s
print with stdout = /dev/null : 0.050 s

0.26秒比12秒要好得多!我不知道wterm是否更聪明地呈现屏幕,沿着我提出的想法(以合理的帧速率呈现“可见”的尾部),还是仅仅比gnome-terminal“做得少”。不过就我的问题而言,我已经得到了答案。 gnome-terminal很慢。

所以——如果您有一个长时间运行的脚本,需要在标准输出中输出大量文本,请尝试使用不同的终端模拟器,看看它是否更好!

请注意,我几乎是从 ubuntu/debian 仓库中随机选择了 wterm这个链接 可能是同一个终端,但我不确定。 我没有测试其他终端仿真器。
更新:因为我想试试,所以我用相同的脚本和全屏(1920x1200)测试了一堆其他终端仿真器。 我手动收集的统计数据在此处:
wterm           0.3秒
aterm           0.3秒
rxvt            0.3秒
mrxvt           0.4秒
konsole         0.6秒
yakuake         0.7秒
lxterminal      7秒
xterm           9秒
gnome-terminal  12秒
xfce4-terminal  12秒
vala-terminal   18秒
xvt             48秒
记录的时间是手动收集的,但它们非常一致。 我记录了最佳值。 显然,你的情况可能有所不同。
作为奖励,这是一个有趣的游览,可以看到各种可用的终端仿真器! 令人惊讶的是,我的第一个“替代”测试竟然是最好的。

1
你也可以尝试使用aterm。这是在我的测试中使用你的脚本得出的结果。Aterm - 打印:0.491秒,写入文件(+fsync):0.110秒,使用stdout = /dev/null打印:0.087秒wterm - 打印:0.521秒,写入文件(+fsync):0.105秒,使用stdout = /dev/null打印:0.085秒 - frogstarr78
1
urxvt和rxvt有什么区别? - Daenyth
3
此外,“screen”程序应该包括在列表中!(或者是增强版的“screen”包装器“byobu”)。这个实用程序允许有多个终端,就像X终端中的选项卡一样。我认为向当前“screen”的终端输出与向普通终端输出相同,但是如果在一个“screen”的终端中打印,然后切换到另一个终端而没有活动会发生什么? - Armando Pérez Marqués
1
有点奇怪,前段时间我在比较不同终端的速度时,gnome-terminal 在相当严格的测试中表现最佳,而 xterm 最慢。也许他们从那时起就在努力改进缓冲区了。 此外,Unicode 支持可能会产生很大的差异。 - Tomas Pruzina
3
在苹果电脑上使用iTerm2时,出现了以下信息:print: 0.587秒,写入文件(+fsync):0.034秒,在/dev/null的标准输出下打印:0.041秒。在iTerm2中运行'screen'时,则为:print: 1.286秒,写入文件(+fsync):0.043秒,在/dev/null的标准输出下打印:0.033秒 - rkulla
显示剩余5条评论

14

你的重定向可能没有任何作用,因为程序可以确定它们的输出FD是否指向TTY。

当stdout指向终端时,很可能是行缓冲的(与C的stdout流行为相同)。

作为一个有趣的实验,请尝试将输出管道传输给cat


我尝试了一项有趣的实验,以下是结果。

$ python test.py 2>foo
...
$ cat foo
-----
timing summary (100k lines each)
-----
print                         : 6.040 s
write to file                 : 0.122 s
print with stdout = /dev/null : 0.121 s

$ python test.py 2>foo |cat
...
$ cat foo
-----
timing summary (100k lines each)
-----
print                         : 1.024 s
write to file                 : 0.131 s
print with stdout = /dev/null : 0.122 s

我没有想到Python会检查它的输出FS。我想知道Python是否在幕后耍了什么花招?我不认为会有,但我不确定。 - Russ
+1 是为了指出缓冲区中非常重要的差异。 - Peter G.
@Russ:-u选项强制stdinstdoutstderr无缓冲,这会比块缓冲慢(因为有额外开销)。 - Hasturkun

4

由于我不了解技术细节,所以无法详细说明,但这并不让我感到惊讶:终端并非为大量数据打印而设计。实际上,每次要打印内容时,它甚至需要执行一堆GUI操作!请注意,如果使用pythonw调用脚本,则不会花费15秒钟;这完全是GUI问题。为避免这种情况,请将stdout重定向到文件中:

import contextlib, io
@contextlib.contextmanager
def redirect_stdout(stream):
    import sys
    sys.stdout = stream
    yield
    sys.stdout = sys.__stdout__

output = io.StringIO
with redirect_stdout(output):
    ...

3

在终端打印输出会很慢。不幸的是,除非编写新的终端实现,否则我真的看不出如何显着加快这个过程。


2

除了输出可能默认为行缓冲模式外,输出到终端还会导致数据流入具有最大吞吐量的终端和串行线,或伪终端和处理显示事件循环、从某种字体渲染字符、移动显示位以实现滚动显示的单独进程。后一种情况可能分布在多个进程中(例如telnet服务器/客户端、终端应用程序、X11显示服务器),因此也存在上下文切换和延迟问题。


真的!这促使我尝试将终端窗口大小(在Gnome中)缩小到某个微小的大小(从1920x1200)。果然……2.8秒的打印时间对比11.5秒。好多了,但为什么还是会停顿呢?你会认为stdout缓冲区(嗯)可以处理所有10万行,终端显示器只需从缓冲区的末尾获取屏幕上可以放置的任何内容,并以一个快速的动作完成此操作。 - Russ
如果xterm(或在这种情况下是gterm)不认为它必须同时显示所有其他输出,那么它将更快地呈现您最终的屏幕。 如果它尝试走这条路,它可能会使小屏幕更新的常见情况看起来不太响应。 在编写此类软件时,有时可以通过具有不同模式并尝试检测何时需要从小型到批量操作模式切换来处理它。 您可以经常使用cat big_file | tail甚至cat big_file | tee big_file.cpy | tail来加速。 - nategoose

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接