¿Por qué la impresión en stdout es tan lenta? ¿Se puede acelerar?

Siempre me ha sorprendido / frustrado con el tiempo que se tarda simplemente en enviar al terminal una declaración de impresión. Después de un registro reciente dolorosamente lento, decidí investigarlo y me sorprendió bastante descubrir que casi todo el tiempo que pasa está esperando que la terminal procese los resultados.

¿Se puede acelerar de alguna manera la escritura en stdout?

Escribí un script (' print_timer.py' en la parte inferior de esta pregunta) para comparar el tiempo al escribir 100k líneas en stdout, en un archivo y con stdout redirigido a /dev/null. Aquí está el resultado del tiempo:

$ 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

Guau. Para asegurarme de que Python no está haciendo algo detrás de escena, como reconocer que reasigné stdout a / dev / null o algo así, realicé la redirección fuera del 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

Entonces no es un truco de Python, es solo la terminal. Siempre supe que volcar la salida a / dev / null aceleró las cosas, ¡pero nunca pensé que fuera tan significativo!

Me sorprende lo lento que es el tty. ¿Cómo puede ser que escribir en el disco físico sea MUCHO más rápido que escribir en la "pantalla" (presumiblemente una operación todo RAM), y es efectivamente tan rápido como simplemente tirar a la basura con / dev / null?

Este enlace habla sobre cómo el terminal bloqueará las E / S para que pueda "analizar [la entrada], actualizar su buffer de trama, comunicarse con el servidor X para desplazar la ventana y así sucesivamente" ... pero no lo hago Lo entiendo completamente. ¿Qué puede llevar tanto tiempo?

Espero que no haya salida (¿menos que una implementación tty más rápida?), Pero creo que preguntaría de todos modos.

ACTUALIZACIÓN: después de leer algunos comentarios, me pregunté cuánto impacto tiene realmente el tamaño de mi pantalla en el tiempo de impresión, y tiene cierta importancia. Los números realmente lentos anteriores están con mi terminal Gnome volado hasta 1920x1200. Si lo reduzco muy pequeño me sale ...

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

Eso es ciertamente mejor (~ 4x), pero no cambia mi pregunta. Solo se agrega a mi pregunta, ya que no entiendo por qué la representación de la pantalla del terminal debería ralentizar la escritura de una aplicación en stdout. ¿Por qué mi programa necesita esperar a que continúe el procesamiento de pantalla?

¿Todas las aplicaciones de terminal / tty no son iguales? Todavía tengo que experimentar. Realmente me parece que un terminal debería ser capaz de almacenar en búfer todos los datos entrantes, analizarlos / renderizarlos de manera invisible, y solo renderizar el fragmento más reciente que es visible en la configuración de pantalla actual a una velocidad de cuadro razonable. Entonces, si puedo escribir + fsync en el disco en ~ 0.1 segundos, un terminal debería poder completar la misma operación en algo de ese orden (con quizás algunas actualizaciones de pantalla mientras lo hacía).

Todavía espero que haya una configuración tty que se pueda cambiar desde el lado de la aplicación para mejorar este comportamiento para el programador. Si esto es estrictamente un problema de aplicación de terminal, ¿entonces quizás esto ni siquiera pertenece a StackOverflow?

¿Qué me estoy perdiendo?

Aquí está el programa python utilizado para generar el tiempo:

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

¿Cómo puede ser que escribir en el disco físico sea MUCHO más rápido que escribir en la "pantalla" (presumiblemente una operación todo RAM), y es efectivamente tan rápido como simplemente tirar a la basura con / dev / null?

Felicitaciones, acaba de descubrir la importancia del almacenamiento en búfer de E / S. :-)

El disco parece ser más rápido, porque está altamente protegido: todas las write()llamadas de Python regresan antes de que algo se escriba realmente en el disco físico. (El sistema operativo hace esto más tarde, combinando miles de escrituras individuales en grandes y eficientes fragmentos).

El terminal, por otro lado, hace poco o nada de almacenamiento en búfer: cada individuo print/ write(line)espera a que se complete la escritura completa (es decir, la pantalla al dispositivo de salida).

Para que la comparación sea justa, debe hacer que la prueba de archivo use el mismo almacenamiento intermedio de salida que el terminal, lo que puede hacer modificando su ejemplo para:

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

Ejecuté su prueba de escritura de archivos en mi máquina, y con el almacenamiento en búfer, también es 0.05s aquí por 100,000 líneas.

Sin embargo, con las modificaciones anteriores para escribir sin búfer, lleva 40 segundos escribir solo 1,000 líneas en el disco. Dejé de esperar 100,000 líneas para escribir, pero extrapolando de lo anterior, tomaría más de una hora .

Eso pone los 11 segundos de la terminal en perspectiva, ¿no?

Entonces, para responder a su pregunta original, escribir en una terminal es realmente increíblemente rápido, considerando todo, y no hay mucho espacio para hacerlo mucho más rápido (pero las terminales individuales varían en la cantidad de trabajo que hacen; vea el comentario de Russ sobre esto responder).

(Podría agregar más almacenamiento en búfer de escritura, como con E / S de disco, pero entonces no vería lo que estaba escrito en su terminal hasta después de que el búfer se vacíe. Es una compensación: interactividad versus eficiencia masiva).

¡Gracias por todos los comentarios! Terminé respondiendo yo mismo con tu ayuda. Sin embargo, se siente sucio responder tu propia pregunta.

Pregunta 1: ¿Por qué la impresión en stdout es lenta?

Respuesta: Imprimir en stdout no es inherentemente lento. Es la terminal con la que trabaja que es lenta. Y tiene prácticamente cero que ver con el almacenamiento en búfer de E / S en el lado de la aplicación (por ejemplo: almacenamiento en búfer de archivos python). Vea abajo.

Pregunta 2: ¿Se puede acelerar?

Respuesta: Sí puede, pero aparentemente no desde el lado del programa (el lado que hace la 'impresión' a stdout). Para acelerarlo, use un emulador de terminal diferente más rápido.

Explicación...

Probé un programa de terminal 'ligero' autodescrito llamado wtermy obtuve resultados significativamente mejores. A continuación se muestra el resultado de mi script de prueba (en la parte inferior de la pregunta) cuando se ejecuta wterma 1920x1200 en el mismo sistema donde la opción de impresión básica tardó 12 segundos usando gnome-terminal:

-----
resumen de tiempos (100k líneas cada uno)
-----
imprimir: 0.261 s
escribir en archivo (+ fsync): 0.110 s
imprimir con stdout = / dev / null: 0.050 s

¡0.26s es MUCHO mejor que 12s! No sé si wtermes más inteligente acerca de cómo se muestra en la pantalla según lo que estaba sugiriendo (renderizar la cola 'visible' a una velocidad de cuadro razonable), o si simplemente "hace menos" que gnome-terminal. Sin embargo, a los fines de mi pregunta, tengo la respuesta. gnome-terminales lento.

Entonces, si tiene un script de larga ejecución que considera lento y arroja grandes cantidades de texto a stdout ... ¡pruebe un terminal diferente y vea si es mejor!

Tenga en cuenta que casi al azar saqué wtermde los repositorios ubuntu / debian. Este enlace puede ser el mismo terminal, pero no estoy seguro. No probé ningún otro emulador de terminal.

Actualización: como tuve que rascarme la picazón, probé un montón de otros emuladores de terminal con el mismo script y pantalla completa (1920x1200). Mis estadísticas recopiladas manualmente están aquí:

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

Los tiempos registrados se recopilan manualmente, pero fueron bastante consistentes. Grabé el mejor valor (ish). YMMV, obviamente.

Como beneficio adicional, ¡fue un recorrido interesante por algunos de los diferentes emuladores de terminales disponibles! Estoy sorprendido de que mi primera prueba 'alternativa' haya sido la mejor del grupo.

Su redirección probablemente no haga nada ya que los programas pueden determinar si su FD de salida apunta a un tty.

Es probable que stdout tenga un buffer de línea cuando apunta a una terminal (lo mismo que el stdoutcomportamiento de flujo de C ).

Como un experimento divertido, intente canalizar la salida a cat.

He intentado mi propio experimento divertido, y aquí están los resultados.

$ 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

No puedo hablar sobre los detalles técnicos porque no los conozco, pero esto no me sorprende: el terminal no fue diseñado para imprimir muchos datos como este. De hecho, ¡incluso proporciona un enlace a una carga de cosas de GUI que tiene que hacer cada vez que desea imprimir algo! Tenga en cuenta que si llama a la secuencia de comandos con pythonw, no le llevará 15 segundos; Esto es completamente un problema de GUI. Redireccionar stdouta un archivo para evitar esto:

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

La impresión en el terminal va a ser lenta. Desafortunadamente, antes de escribir una nueva implementación de terminal, realmente no puedo ver cómo acelerarías esto significativamente.

Además de la salida que probablemente se establece de manera predeterminada en un modo de línea de búfer, la salida a un terminal también hace que sus datos fluyan a un terminal y a una línea serie con un rendimiento máximo, o un pseudo-terminal y un proceso separado que maneja una pantalla bucle de eventos, representando caracteres de alguna fuente, moviendo bits de pantalla para implementar una pantalla de desplazamiento. El último escenario probablemente se extiende sobre múltiples procesos (por ejemplo, servidor / cliente telnet, aplicación de terminal, servidor de visualización X11), por lo que también hay problemas de cambio de contexto y latencia.