Dlaczego drukowanie na standardowe wyjście jest tak wolne? Czy można to przyspieszyć?

Zawsze byłem zdumiony / sfrustrowany tym, ile czasu zajmuje po prostu wyprowadzenie na terminal z instrukcją print. Po niedawnym, boleśnie powolnym logowaniu postanowiłem się temu przyjrzeć i byłem dość zaskoczony, że prawie cały czas spędzony na czekaniu, aż terminal przetworzy wyniki.

Czy można w jakiś sposób przyspieszyć pisanie na stdout?

Napisałem skrypt (' print_timer.py' na dole tego pytania), aby porównać czasy podczas zapisywania 100 tys. Wierszy na stdout, do pliku iz przekierowaniem do stdout /dev/null. Oto wynik pomiaru czasu:

$ 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

Łał. Aby upewnić się, że Python nie robi czegoś za kulisami, jak rozpoznawanie, że przypisałem standardowe wyjście do / dev / null lub coś w tym stylu, wykonałem przekierowanie poza skryptem ...

$ 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

Więc to nie jest sztuczka Pythona, to tylko terminal. Zawsze wiedziałem, że zrzucanie danych wyjściowych do / dev / null przyspiesza działanie, ale nigdy nie sądziłem, że jest to aż tak istotne!

Zadziwia mnie, jak powolny jest tty. Jak to możliwe, że zapisywanie na dysku fizycznym jest DUŻO szybsze niż zapisywanie na "ekranie" (przypuszczalnie operacja all-RAM) i jest tak samo szybkie, jak po prostu zrzucanie do śmieci za pomocą / dev / null?

To łącze mówi o tym, jak terminal będzie blokował I / O, aby mógł "analizować [wejście], aktualizować bufor ramki, komunikować się z serwerem X w celu przewijania okna i tak dalej" ... ale ja tego nie robię w pełni to zrozum. Co może trwać tak długo?

Spodziewam się, że nie ma wyjścia (poza szybszą implementacją tty?), Ale i tak zapytam.

AKTUALIZACJA: po przeczytaniu kilku komentarzy zastanawiałem się, jak duży wpływ na czas drukowania ma rozmiar mojego ekranu i ma to pewne znaczenie. Naprawdę wolne liczby powyżej dotyczą mojego terminala Gnome wysadzonego do 1920x1200. Jeśli zmniejszę to bardzo małe, otrzymam ...

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

To jest z pewnością lepsze (~ 4x), ale nie zmienia mojego pytania. Dodaje to tylko do mojego pytania, ponieważ nie rozumiem, dlaczego renderowanie ekranu terminala powinno spowolnić pisanie aplikacji na standardowe wyjście. Dlaczego mój program musi czekać na kontynuację renderowania ekranu?

Czy wszystkie aplikacje terminala / tty nie są sobie równe? Ja jeszcze nie eksperymentowałem. Naprawdę wydaje mi się, że terminal powinien być w stanie buforować wszystkie przychodzące dane, analizować / renderować je w niewidoczny sposób i renderować tylko najnowszy fragment, który jest widoczny w bieżącej konfiguracji ekranu z rozsądną liczbą klatek na sekundę. Więc jeśli mogę napisać + fsync na dysk w ~ 0,1 sekundy, terminal powinien być w stanie wykonać tę samą operację w czymś w tej kolejności (może z kilkoma aktualizacjami ekranu, gdy to robił).

Nadal mam nadzieję, że istnieje ustawienie tty, które można zmienić po stronie aplikacji, aby poprawić to zachowanie dla programisty. Jeśli jest to wyłącznie problem z aplikacją terminalową, to może nawet nie należy do StackOverflow?

czego mi brakuje?

Oto program w Pythonie używany do generowania synchronizacji:

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

Jak to możliwe, że zapisywanie na dysku fizycznym jest DUŻO szybsze niż zapisywanie na "ekranie" (przypuszczalnie operacja all-RAM) i jest tak samo szybkie, jak po prostu zrzucanie do śmieci za pomocą / dev / null?

Gratulacje, właśnie odkryłeś znaczenie buforowania we / wy. :-)

Dysk wydaje się być szybszy, ponieważ jest silnie buforowany: wszystkie write()wywołania Pythona powracają, zanim cokolwiek zostanie zapisane na dysku fizycznym. (System operacyjny robi to później, łącząc wiele tysięcy pojedynczych zapisów w duże, wydajne fragmenty).

Z drugiej strony terminal wykonuje niewielkie lub żadne buforowanie: każda osoba print/ write(line)czeka na zakończenie pełnego zapisu (tj. Wyświetlania na urządzeniu wyjściowym).

Aby porównanie było sprawiedliwe, musisz sprawić, by test pliku używał tego samego buforowania wyjścia co terminal, co możesz zrobić, modyfikując swój przykład na:

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

Uruchomiłem twój test zapisu plików na moim komputerze i przy buforowaniu, tutaj również wynosi 0,05 s dla 100 000 linii.

Jednak z powyższymi modyfikacjami do zapisu niebuforowanego, zapisanie tylko 1000 linii na dysku zajmuje 40 sekund. Zrezygnowałem z czekania na napisanie 100 000 wierszy, ale ekstrapolując z poprzedniego, zajęłoby to ponad godzinę .

To stawia 11 sekund terminalu w perspektywie, prawda?

Odpowiadając na twoje pierwotne pytanie, pisanie do terminala jest w rzeczywistości niesamowicie szybkie, biorąc pod uwagę wszystkie rzeczy, i nie ma dużo miejsca, aby to zrobić znacznie szybciej (ale poszczególne terminale różnią się ilością wykonywanej pracy; zobacz komentarz Russa na ten temat odpowiedź).

(Możesz dodać więcej buforowania zapisu, tak jak w przypadku dyskowych operacji we / wy, ale wtedy nie zobaczysz, co zostało zapisane na twoim terminalu, dopóki bufor nie zostanie opróżniony. To kompromis: interaktywność a wydajność masowa).

Dzięki za wszystkie komentarze! Skończyło się na tym, że sam na to odpowiedziałem z twoją pomocą. Jednak odpowiadanie na własne pytanie jest nieprzyjemne.

Pytanie 1: Dlaczego drukowanie na standardowe wyjście jest wolne?

Odpowiedź: Drukowanie na standardowe wyjście nie jest z natury powolne. To terminal, z którym pracujesz, działa wolno. I ma prawie zero wspólnego z buforowaniem we / wy po stronie aplikacji (np. Buforowanie plików w języku Python). Zobacz poniżej.

Pytanie 2: Czy można to przyspieszyć?

Odpowiedź: Tak, ale pozornie nie od strony programu (strona wykonująca „drukowanie” na standardowe wyjście). Aby to przyspieszyć, użyj szybszego innego emulatora terminala.

Wyjaśnienie...

Wypróbowałem opisany przez siebie „lekki” program terminalowy o nazwie wtermi uzyskałem znacznie lepsze wyniki. Poniżej znajduje się wynik mojego skryptu testowego (na dole pytania) podczas uruchamiania w wterm1920x1200 w tym samym systemie, w którym podstawowa opcja drukowania zajęła 12 sekund przy użyciu gnome-terminal:

-----
podsumowanie czasu (po 100 tys. wierszy)
-----
wydruk: 0,261 s
zapisz do pliku (+ fsync): 0,110 s
drukuj z stdout = / dev / null: 0,050 s

0,26 s to DUŻO lepsze niż 12 s! Nie wiem, czy wtermjest bardziej inteligentne, jeśli chodzi o to, jak renderuje się na ekranie zgodnie z tym, jak sugerowałem (renderuj „widoczny” ogon przy rozsądnej liczbie klatek na sekundę), czy po prostu „robi mniej” niż gnome-terminal. Jednak na moje pytanie mam odpowiedź. gnome-terminaljest wolny.

Tak więc - jeśli masz długo działający skrypt, który uważasz za powolny i wypluwa ogromne ilości tekstu na standardowe wyjście ... wypróbuj inny terminal i zobacz, czy jest lepszy!

Zwróć uwagę, że prawie losowo pobierałem wtermz repozytoriów ubuntu / debian. Ten link może być tym samym terminalem, ale nie jestem pewien. Nie testowałem żadnych innych emulatorów terminala.

Aktualizacja: Ponieważ musiałem podrapać swędzenie, przetestowałem cały stos innych emulatorów terminala z tym samym skryptem i pełnym ekranem (1920x1200). Moje ręcznie zebrane statystyki są tutaj:

wterm 0.3s
aterm 0.3s
rxvt 0.3s
mrxvt 0.4s
konsole 0.6s
yakuake 0,7 s
lxterminal 7s
xterm 9s
gnome-terminal 12s
xfce4-zacisk 12s
vala-terminal 18s
XVT 48s

Zarejestrowane czasy są zbierane ręcznie, ale były dość spójne. Zarejestrowałem najlepszą (ish) wartość. YMMV, oczywiście.

Jako bonus, była to interesująca wycieczka po niektórych dostępnych emulatorach terminali! Jestem zdumiony, że mój pierwszy test „alternatywny” okazał się najlepszy ze wszystkich.

Twoje przekierowanie prawdopodobnie nic nie daje, ponieważ programy mogą określić, czy ich wyjściowe FD wskazuje na terminal.

Jest prawdopodobne, że stdout jest buforowane wierszowo, gdy wskazuje na terminal (tak samo jak stdoutzachowanie strumienia C ).

W ramach zabawnego eksperymentu spróbuj przekierować wyjście do cat.

Wypróbowałem własny, zabawny eksperyment i oto wyniki.

$ 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

Nie mogę mówić o szczegółach technicznych, ponieważ ich nie znam, ale to mnie nie dziwi: terminal nie został zaprojektowany do drukowania wielu takich danych. Rzeczywiście, podajesz nawet łącze do zbioru elementów graficznego interfejsu użytkownika, które musi on wykonać za każdym razem, gdy chcesz coś wydrukować! Zauważ, że jeśli pythonwzamiast tego wywołasz skrypt za pomocą , nie zajmie to 15 sekund; jest to całkowicie kwestia GUI. Przekieruj stdoutdo pliku, aby tego uniknąć:

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

Drukowanie na terminalu będzie powolne. Niestety, nie mówiąc o napisaniu nowej implementacji terminala, nie wiem, jak można to znacznie przyspieszyć.

Oprócz wyjścia prawdopodobnie domyślnie ustawionego w trybie buforowanym linii, wyjście do terminala powoduje również przepływ danych do terminala i linii szeregowej z maksymalną przepustowością lub do pseudoterminalu i oddzielnego procesu obsługującego wyświetlacz pętla zdarzeń, renderowanie znaków z jakiejś czcionki, przesuwanie bitów wyświetlania w celu zaimplementowania przewijanego wyświetlacza. Ten drugi scenariusz jest prawdopodobnie rozłożony na wiele procesów (np. Serwer / klient telnet, aplikacja terminalowa, serwer wyświetlania X11), więc występują również problemy z przełączaniem kontekstu i opóźnieniami.