问题:为什么打印到标准输出这么慢?可以加快速度吗?

我一直对使用print语句简单地输出到终端需要多长时间感到惊讶/沮丧。在经历了最近令人痛苦的缓慢日志记录之后,我决定进行调查,并惊讶地发现几乎所有的时间都在等待终端处理结果。

可以以某种方式加快对stdout的写入速度吗?

我编写了一个脚本(print_timer.py此问题底部的’ ‘)来比较将100k行写入stdout,文件以及将stdout重定向到时的时序/dev/null。计时结果如下:

$ 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终端被炸毁为1920×1200。如果我减小很小,我得到…

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

I’ve always been amazed/frustrated with how long it takes to simply output to the terminal with a print statement. After some recent painfully slow logging I decided to look into it and was quite surprised to find that almost all the time spent is waiting for the terminal to process the results.

Can writing to stdout be sped up somehow?

I wrote a script (‘print_timer.py‘ at the bottom of this question) to compare timing when writing 100k lines to stdout, to file, and with stdout redirected to /dev/null. Here is the timing result:

$ 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

Wow. To make sure python isn’t doing something behind the scenes like recognizing that I reassigned stdout to /dev/null or something, I did the redirection outside the script…

$ 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

So it isn’t a python trick, it is just the terminal. I always knew dumping output to /dev/null sped things up, but never figured it was that significant!

It amazes me how slow the tty is. How can it be that writing to physical disk is WAY faster than writing to the “screen” (presumably an all-RAM op), and is effectively as fast as simply dumping to the garbage with /dev/null?

This link talks about how the terminal will block I/O so it can “parse [the input], update its frame buffer, communicate with the X server in order to scroll the window and so on”… but I don’t fully get it. What can be taking so long?

I expect there is no way out (short of a faster tty implementation?) but figure I’d ask anyway.


UPDATE: after reading some comments I wondered how much impact my screen size actually has on the print time, and it does have some significance. The really slow numbers above are with my Gnome terminal blown up to 1920×1200. If I reduce it very small I get…

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

That is certainly better (~4x), but doesn’t change my question. It only adds to my question as I don’t understand why the terminal screen rendering should slow down an application writing to stdout. Why does my program need to wait for screen rendering to continue?

Are all terminal/tty apps not created equal? I have yet to experiment. It really seems to me like a terminal should be able to buffer all incoming data, parse/render it invisibly, and only render the most recent chunk that is visible in the current screen configuration at a sensible frame rate. So if I can write+fsync to disk in ~0.1 seconds, a terminal should be able to complete the same operation in something of that order (with maybe a few screen updates while it did it).

I’m still kind of hoping there is a tty setting that can be changed from the application side to make this behaviour better for programmer. If this is strictly a terminal application issue, then this maybe doesn’t even belong on StackOverflow?

What am I missing?


Here is the python program used to generate the timing:

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

回答 0

写入物理磁盘比写入“屏幕”(大概是全RAM操作)要快得多,并且实际上与使用/ dev / null转储到垃圾中一样快?

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

磁盘似乎速度更快,因为它具有很高的缓冲能力:write()在将任何内容实际写入物理磁盘之前,所有Python的调用都将返回。(操作系统稍后执行此操作,将成千上万的单个写入合并为一个大而有效的块。)

另一方面,终端几乎不执行缓冲或不进行缓冲:每个人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.05s的测试。

但是,通过上述修改以无缓冲方式写入数据,只需要40秒就可以将1,000行写入磁盘。我放弃了等待100,000行的写操作,但是从以前的内容推论得出,这将花费一个多小时

这使航站楼的11秒成为现实,不是吗?

因此,要回答您最初的问题,考虑到所有因素,实际上写信到终端的速度非常快,并且没有太多的空间可以使它更快(但是各个终端的工作量有所不同;请参阅Russ对此的评论)回答)。

(您可以像使用磁盘I / O一样添加更多的写缓冲,但是直到刷新缓冲区之后,您才能看到向终端写入的内容。这是一个折衷方案:交互性与大容量效率。)

How can it be that writing to physical disk is WAY faster than writing to the “screen” (presumably an all-RAM op), and is effectively as fast as simply dumping to the garbage with /dev/null?

Congratulations, you have just discovered the importance of I/O buffering. :-)

The disk appears to be faster, because it is highly buffered: all Python’s write() calls are returning before anything is actually written to physical disk. (The OS does this later, combining many thousands of individual writes into a big, efficient chunks.)

The terminal, on the other hand, does little or no buffering: each individual print / write(line) waits for the full write (i.e. display to output device) to complete.

To make the comparison fair, you must make the file test use the same output buffering as the terminal, which you can do by modifying your example to:

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

I ran your file writing test on my machine, and with buffering, it also 0.05s here for 100,000 lines.

However, with the above modifications to write unbuffered, it takes 40 seconds to write only 1,000 lines to disk. I gave up waiting for 100,000 lines to write, but extrapolating from the previous, it would take over an hour.

That puts the terminal’s 11 seconds into perspective, doesn’t it?

So to answer your original question, writing to a terminal is actually blazingly fast, all things considered, and there’s not a lot of room to make it much faster (but individual terminals do vary in how much work they do; see Russ’s comment to this answer).

(You could add more write buffering, like with disk I/O, but then you wouldn’t see what was written to your terminal until after the buffer gets flushed. It’s a trade-off: interactivity versus bulk efficiency.)


回答 1

感谢所有的评论!我最终在您的帮助下自行回答。不过,回答您自己的问题感觉很脏。

问题1:为什么打印到标准输出速度慢?

答:打印到标准输出并不是天生就慢。您正在使用的终端很慢。它与应用程序端的I / O缓冲(例如python文件缓冲)几乎为零。见下文。

问题2:可以加快速度吗?

答:是的,可以,但是似乎不是从程序方面(将“打印”到stdout的那一侧)进行。为了加快速度,请使用更快的其他终端仿真器。

说明…

我尝试了一个自描述为“轻量级”的终端程序,wterm并获得了明显更好的结果。下面是在wterm同一系统上以1920×1200 运行时,我的测试脚本的输出(位于问题的底部),该系统使用gnome-terminal的基本打印选项花费了12s:

-----
时序摘要(每条10万行)
-----
打印:0.261 s
写入文件(+ fsync):0.110 s
用stdout = / dev / null打印:0.050 s

0.26s比12s好得多!我不知道是否wterm更聪明地按照我的建议进行渲染(以合理的帧频渲染“可见”尾巴),或者是否“做得比”少gnome-terminal。为了我的问题,我得到了答案。 gnome-terminal是慢的。

所以-如果您运行的脚本长时间运行,感觉很慢,并且会向stdout喷出大量文本,请尝试其他终端,看看它是否更好!

请注意,我几乎是wterm从ubuntu / debian存储库中随机提取的。 该链接可能是同一终端,但是我不确定。我没有测试任何其他终端模拟器。


更新:因为必须要抓痒,所以我用相同的脚本和全屏(1920×1200)测试了一堆其他终端模拟器。我的手动收集的统计信息在这里:

wterm 0.3秒
间隔0.3秒
接收0.3秒
mrxvt 0.4s
konsole 0.6秒
药师0.7s
接线柱7s
xterm 9s
gnome终端12s
xfce4端子12s
巴拉终端18s
xvt 48s

记录的时间是手动收集的,但是它们是相当一致的。我记录了最好的(ish)值。YMMV,显然。

另外,它是对其中可用的各种终端仿真器的一次有趣的浏览!我很惊讶我的第一个“替代”测试竟然是同类中最好的。

Thanks for all the comments! I’ve ended up answering it myself with your help. It feels dirty answering your own question, though.

Question 1: Why is printing to stdout slow?

Answer: Printing to stdout is not inherently slow. It is the terminal you work with that is slow. And it has pretty much zero to do with I/O buffering on the application side (eg: python file buffering). See below.

Question 2: Can it be sped up?

Answer: Yes it can, but seemingly not from the program side (the side doing the ‘printing’ to stdout). To speed it up, use a faster different terminal emulator.

Explanation…

I tried a self-described ‘lightweight’ terminal program called wterm and got significantly better results. Below is the output of my test script (at the bottom of the question) when running in wterm at 1920×1200 in on the same system where the basic print option took 12s using gnome-terminal:

-----
timing summary (100k lines each)
-----
print                         : 0.261 s
write to file (+fsync)        : 0.110 s
print with stdout = /dev/null : 0.050 s

0.26s is MUCH better than 12s! I don’t know whether wterm is more intelligent about how it renders to screen along the lines of how I was suggesting (render the ‘visible’ tail at a reasonable frame rate), or whether it just “does less” than gnome-terminal. For the purposes of my question I’ve got the answer, though. gnome-terminal is slow.

So – If you have a long running script that you feel is slow and it spews massive amounts of text to stdout… try a different terminal and see if it is any better!

Note that I pretty much randomly pulled wterm from the ubuntu/debian repositories. This link might be the same terminal, but I’m not sure. I did not test any other terminal emulators.


Update: Because I had to scratch the itch, I tested a whole pile of other terminal emulators with the same script and full screen (1920×1200). My manually collected stats are here:

wterm           0.3s
aterm           0.3s
rxvt            0.3s
mrxvt           0.4s
konsole         0.6s
yakuake         0.7s
lxterminal        7s
xterm             9s
gnome-terminal   12s
xfce4-terminal   12s
vala-terminal    18s
xvt              48s

The recorded times are manually collected, but they were pretty consistent. I recorded the best(ish) value. YMMV, obviously.

As a bonus, it was an interesting tour of some of the various terminal emulators available out there! I’m amazed my first ‘alternate’ test turned out to be the best of the bunch.


回答 2

重定向可能什么也不做,因为程序可以确定其输出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

Your redirection probably does nothing as programs can determine whether their output FD points to a tty.

It’s likely that stdout is line buffered when pointing to a terminal (the same as C’s stdout stream behaviour).

As an amusing experiment, try piping the output to cat.


I’ve tried my own amusing experiment, and here are the results.

$ 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

回答 3

我无法谈论技术细节,因为我不知道这些细节,但这并不令我感到惊讶:该终端并非为打印此类数据而设计的。的确,您甚至提供了指向您每次打印某些内容时必须要做的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):
    ...

I can’t talk about the technical details because I don’t know them, but this doesn’t surprise me: the terminal was not designed for printing lots of data like this. Indeed, you even provide a link to a load of GUI stuff that it has to do every time you want to print something! Notice that if you call the script with pythonw instead, it does not take 15 seconds; this is entirely a GUI issue. Redirect stdout to a file to avoid this:

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

回答 4

打印到终端将很慢。不幸的是,如果没有编写新的终端实现,我真的看不到您如何显着加快这一步。

Printing to the terminal is going to be slow. Unfortunately short of writing a new terminal implementation I can’t really see how you’d speed this up significantly.


回答 5

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

In addition to the output probably defaulting to a line-buffered mode, output to a terminal is also causing your data to flow into a terminal and serial line with a maximum throughput, or a pseudo-terminal and a separate process that is handling a display event loop, rendering characters from some font, moving display bits to implement a scrolling display. The latter scenario is probably spread over multiple processes (e.g. telnet server/client, terminal app, X11 display server) so there are context switching and latency issues too.


声明:本站所有文章,如无特殊说明或标注,均为本站原创发布。任何个人或组织,在未征得本站同意时,禁止复制、盗用、采集、发布本站内容到任何网站、书籍等各类媒体平台。如若本站内容侵犯了原著者的合法权益,可联系我们进行处理。