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.
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:
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...
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?
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 1920x1200. If I reduce it very small I get...
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?
The whole purpose of writing to stdout is so a human can read the output. No human being in the world can read 10,000 lines of text in 12 seconds, so what's the point of making stdout faster??? – Seun Osewa Oct 5 '10 at 17:05
@Seun Osewa: One example (that drove my question) is when doing things like print statement debugging. You want to run your program and see results as they happen. You are obviously right that most lines will fly by that you can't see, but when an exception happens (or you hit the conditional getch/raw_input/sleep statement you carefully placed) you want to be looking at the print output directly rather than constantly having to open or refresh a file view. – Russ Oct 6 '10 at 14:52
Print statement debugging is the one of the reasons why tty devices (i.e. terminals) default to line buffering instead of block buffering: the debug output isn't much use if the program hangs and the last few lines of debug output are still in a buffer instead of flushed to the terminal. – Stephen C. Steel Oct 7 '10 at 21:01
@Stephen: This is why I haven't bothered much with pursuing the huge improvements one commenter claimed by cranking up the buffer size. It entirely defeats the purpose of the debug printing! I did experiment a little bit while investigating, but saw no net improvement. I'm still curious about the discrepancy, but not really. – Russ Oct 8 '10 at 5:08
Sometimes for very long running programs, I'll just print the current line stdout every n seconds -- similar to having a refresh delay in a curses app. It's not perfect, but gives an idea of what's where I'm at once in a while. – rkulla Jan 27 '15 at 20:27
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?
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.)
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:
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.
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.)
I get I/O buffering... you certainly reminded me that I should have fsync'd for a true comparison of completion time (I'll update the question), but an fsync per line is insanity. Does a tty really need to effectively do that? Is there no terminal/os-side buffering equivalent to for files? ie: Applications write to stdout and return before terminal renders to screen, with the terminal (or os) buffering it all. The terminal could then sensibly render the tail to screen at a visible frame rate. Effectively blocking on every line seems silly. I feel I'm still missing something. – Russ Oct 4 '10 at 21:00
You can just open a handle to stdout with a big buffer yourself, using something like os.fdopen(sys.stdout.fileno(), 'w', BIGNUM). This would almost never be useful, though: almost all applications would have to remember to explicitly flush after each line of user-intended output. – Pi Delport Oct 4 '10 at 21:30
I experimented earlier with huge (up to 10MB with fp = os.fdopen(sys.__stdout__.fileno(), 'w', 10000000)) python-side buffers. Impact was nil. ie: still long tty delays. This made me think/realize that you just postpone the slow tty problem... when python's buffer finally flushes the tty still seems to do the same total amount of processing on the stream before returning. – Russ Oct 4 '10 at 23:21
Note that this answer is misleading and wrong (sorry!). Specifically it is wrong to say "there is not much room to make it faster [than 11 seconds]". Please see my own answer to the question where I show that the wterm terminal achieved the same 11s result in 0.26s. – Russ Oct 5 '10 at 1:51
Russ: thanks for the feedback! On my side, a larger fdopen buffer (2MB) definitely made a huge difference: it took the printing time down from many seconds to 0.05s, same as file output (using gnome-terminal). – Pi Delport Oct 5 '10 at 10:09
Thanks for all the comments! I've ended up answering it myself with your help. It feels dirty answering your own question, though.
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.
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.
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 1920x1200 in on the same system where the basic print option took 12s using gnome-terminal:
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 (1920x1200). My manually collected stats are here:
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.
Also, screen, (the program) should be included on the list! (Or byobu, which is a wrapper for screen with enhancements) This utility allows to have several terminals, much like tabs in X terminals. I presume that printing to the current screen's terminal is the same as printing to a plain one, but what about printing in one of screen's terminal and then switch to another with no activity? – Armando Pérez Marqués Nov 16 '10 at 20:27
Weird, some time ago I was comparing different terminals in terms of speed and gnome-terminal came out best in rather serious tests while xterm was slowest. Perhaps they worked hard on buffering since then. Also unicode support could do a big difference. – AoeAoe Apr 16 '12 at 11:01
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).
I didn't think of python checking its output FS. I wonder if python is pulling a trick behind the scenes? I expect not, but don't know. – Russ Oct 4 '10 at 16:27
@Russ: the -u option forces stdin, stdout and stderr to be unbuffered, which will be slower than being block buffered (due to overhead) – Hasturkun Oct 4 '10 at 16:56
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:
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.
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.
True! This prompted me to try reducing my terminal window size (in Gnome) to something puny (from 1920x1200). Sure enough... 2.8s print time vs 11.5s. Much better, but still... why is it stalling? You would think the stdout buffer (hmm) could handle all 100k lines and the terminal display would just grab whatever it can fit onscreen from the tail end of the buffer and get it done in one quick shot. – Russ Oct 4 '10 at 17:04
The xterm (or gterm, in this case) would render your eventual screen faster if it did not think that it had to display all of the other output along the way as well. If it were to try to go this route it would likely make the common case of small screen updates seem less responsive. When writing this type of software you can sometimes deal with it by having different modes and trying to detect when you need to move to/from a small to bulk mode of operation. You can use cat big_file | tail or even cat big_file | tee big_file.cpy | tail very often for this speed up. – nategoose Oct 4 '10 at 21:39
Not the answer you're looking for? Browse other questions tagged python linux printing stdout tty or ask your own question.
Will this python script work as intended? I want it to plug random numbers into an equation until it gets 187.2