Pourquoi l'impression vers stdout est-elle si lente ? Peut-on l'accélérer ?

Question

J'ai toujours été étonné/frustré par le temps qu'il faut pour simplement envoyer une sortie au terminal avec une instruction print. Après une récente journalisation douloureusement lente, j'ai décidé de me pencher sur la question et j'ai été assez surpris de constater que presque todo le temps passé à attendre que le terminal traite les résultats.

Peut-on accélérer l'écriture vers stdout d'une manière ou d'une autre ?

J'ai écrit un script (' print_timer.py au bas de cette question) pour comparer les temps d'écriture de 100k lignes sur stdout, sur fichier, et avec stdout redirigé sur /dev/null . Voici le résultat du chronométrage :

$ 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. Pour être sûr que python ne fait pas quelque chose en coulisse comme reconnaître que j'ai réassigné stdout à /dev/null ou autre, j'ai fait la redirection en dehors du 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

Ce n'est donc pas un truc de python, c'est juste le terminal. J'ai toujours su que le vidage de la sortie vers /dev/null accélérait les choses, mais je n'avais jamais pensé que c'était si important !

Je suis étonné de voir à quel point le tty est lent. Comment se fait-il que l'écriture sur le disque physique soit BEAUCOUP plus rapide que l'écriture sur l'"écran" (vraisemblablement une opération tout-RAM), et qu'elle soit effectivement aussi rapide que le simple vidage dans la poubelle avec /dev/null ?

Ce lien parle de la façon dont le terminal va bloquer les entrées/sorties pour qu'il puisse "analyser [l'entrée], mettre à jour son tampon d'image, communiquer avec le serveur X afin de faire défiler la fenêtre, etc.". ... mais je ne comprends pas tout. Qu'est-ce qui peut prendre autant de temps ?

Je suppose qu'il n'y a pas de solution (à part une implémentation plus rapide du tty ?) mais je me suis dit que je demanderais quand même.

---

MISE À JOUR : après avoir lu certains commentaires, je me suis demandé quel impact la taille de mon écran avait sur le temps d'impression, et cela a effectivement une certaine importance. Les chiffres très lents ci-dessus sont obtenus avec mon terminal Gnome agrandi à 1920x1200. Si je le réduis très petit, j'obtiens...

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

C'est certainement mieux (~4x), mais cela ne change pas ma question. Cela ne fait que ajoute à ma question car je ne comprends pas pourquoi le rendu de l'écran du terminal devrait ralentir une application écrivant sur stdout. Pourquoi mon programme doit-il attendre le rendu d'écran pour continuer ?

Toutes les applications de type terminal/tty ne sont-elles pas égales ? Je n'ai pas encore expérimenté. J'ai vraiment l'impression qu'un terminal devrait être capable de mettre en mémoire tampon toutes les données entrantes, de les analyser/rendre invisibles et de ne rendre que le morceau le plus récent visible dans la configuration actuelle de l'écran à une fréquence d'images raisonnable. Donc, si je peux écrire+fsync sur le disque en ~0,1 seconde, un terminal devrait être capable de réaliser la même opération en quelque chose de cet ordre (avec peut-être quelques mises à jour de l'écran pendant qu'il le fait).

J'espère toujours qu'il y a un paramètre de tty qui peut être modifié du côté de l'application pour améliorer ce comportement pour le programmeur. S'il s'agit strictement d'un problème d'application de terminal, alors cette question n'a peut-être même pas sa place sur StackOverflow ?

Qu'est-ce que je rate ?

---

Voici le programme python utilisé pour générer le 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

Answer 1

Comment se peut-il que l'écriture sur le disque physique soit BEAUCOUP plus rapide que l'écriture sur l'"écran" (vraisemblablement une opération tout-RAM), et qu'elle soit effectivement aussi rapide qu'un simple vidage à la poubelle avec /dev/null ?

Félicitations, vous venez de découvrir l'importance de la mise en mémoire tampon des E/S. :-)

Le disque apparaît est plus rapide, car il est fortement mis en mémoire tampon : toutes les fonctions de Python write() Les appels sont retournés avant que quelque chose ne soit réellement écrit sur le disque physique. (Le système d'exploitation le fait plus tard, en combinant plusieurs milliers d'écritures individuelles en un gros morceau efficace).

Le terminal, quant à lui, ne fait que peu ou pas de mise en mémoire tampon : chaque individu print / write(line) attend le complet l'écriture (c'est-à-dire l'affichage sur le périphérique de sortie) pour terminer.

Pour que la comparaison soit équitable, vous devez faire en sorte que le fichier de test utilise le même tampon de sortie que le terminal, ce que vous pouvez faire en modifiant votre exemple :

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

J'ai effectué votre test d'écriture de fichier sur ma machine, et avec la mise en mémoire tampon, il est également de 0,05s ici pour 100 000 lignes.

Cependant, avec les modifications ci-dessus pour écrire sans tampon, il faut 40 secondes pour écrire seulement 1 000 lignes sur le disque. J'ai renoncé à attendre l'écriture de 100.000 lignes, mais en extrapolant à partir de ce qui précède, il faudrait plus d'une heure .

Cela met les 11 secondes du terminal en perspective, n'est-ce pas ?

Donc, pour répondre à votre question initiale, l'écriture sur un terminal est en fait extrêmement rapide, tout bien considéré, et il n'y a pas beaucoup de place pour la rendre beaucoup plus rapide (mais les terminaux individuels varient dans la quantité de travail qu'ils font ; voir le commentaire de Russ à cette réponse).

(Vous pourriez ajouter un tampon d'écriture supplémentaire, comme pour les E/S sur disque, mais vous ne verriez alors pas ce qui a été écrit sur votre terminal avant que le tampon ne soit vidé. C'est un compromis : interactivité contre efficacité en masse).

Answer 2

Merci pour tous les commentaires ! J'ai fini par y répondre moi-même avec votre aide. Mais ça fait mal de répondre à sa propre question.

Question 1 : Pourquoi l'impression vers stdout est-elle lente ?

Réponse : L'impression sur la sortie d'état est no intrinsèquement lent. C'est le terminal avec lequel vous travaillez qui est lent. Et cela n'a pratiquement rien à voir avec la mise en mémoire tampon des E/S du côté de l'application (par exemple, la mise en mémoire tampon des fichiers python). Voir ci-dessous.

Question 2 : Peut-on accélérer le processus ?

Réponse : Oui, c'est possible, mais apparemment pas du côté du programme (le côté qui effectue l'impression vers stdout). Pour accélérer le processus, utilisez un émulateur de terminal différent et plus rapide.

Explication...

J'ai essayé un programme de terminal autoproclamé "léger" appelé wterm et a obtenu de manière significative de meilleurs résultats. Voici la sortie de mon test script (au bas de la question) lorsqu'il est exécuté en mode wterm à 1920x1200 sur le même système où l'option d'impression de base prenait 12s en utilisant 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 est BEAUCOUP mieux que 12s ! Je ne sais pas si wterm est plus intelligente quant à la façon dont elle rend l'image à l'écran, comme je le suggérais (rendre la queue "visible" à une fréquence d'images raisonnable), ou si elle en fait simplement "moins" que gnome-terminal . Pour les besoins de ma question, j'ai la réponse, cependant. gnome-terminal est lent.

Donc - Si vous avez un long script en cours d'exécution qui vous semble lent et qui crache des quantités massives de texte vers stdout... essayez un autre terminal et voyez si c'est mieux !

Notez que j'ai tiré au hasard wterm depuis les dépôts ubuntu/debian. Ce lien pourrait être le même terminal, mais je ne suis pas sûr. Je n'ai pas testé d'autres émulateurs de terminal.

---

Mise à jour : Parce que je devais gratter la démangeaison, j'ai testé un tas d'autres émulateurs de terminal avec le même script et en plein écran (1920x1200). Mes statistiques collectées manuellement sont ici :

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

Les temps enregistrés sont collectés manuellement, mais ils étaient assez cohérents. J'ai enregistré la meilleure valeur (ou presque). YMMV, évidemment.

En prime, c'était une visite intéressante de quelques-uns des différents émulateurs de terminal disponibles sur le marché ! Je suis surpris que mon premier test "alternatif" se soit avéré être le meilleur de tous.

Answer 3

Votre redirection ne fait probablement rien car les programmes peuvent déterminer si leur FD de sortie pointe vers un tty.

Il est probable que stdout soit mis en tampon de ligne lorsqu'il pointe vers un terminal (de la même façon que le C stdout comportement du flux).

A titre d'expérience amusante, essayez d'envoyer la sortie à cat .

---

J'ai tenté ma propre expérience amusante, et voici les résultats.

$ 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

Answer 4

Je ne peux pas parler des détails techniques parce que je ne les connais pas, mais cela ne me surprend pas : le terminal n'a pas été conçu pour imprimer des quantités de données comme celles-ci. En effet, vous fournissez même un lien vers un tas de trucs GUI qu'il doit faire à chaque fois que vous voulez imprimer quelque chose ! Remarquez que si vous appelez le script avec pythonw au lieu de cela, il ne prend pas 15 secondes ; c'est entièrement un problème d'interface graphique. Redirection stdout dans un fichier pour éviter cela :

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

Answer 5

L'impression sur le terminal va être lente. Malheureusement, à moins d'écrire une nouvelle implémentation du terminal, je ne vois pas vraiment comment vous pourriez accélérer cela de manière significative.