Почему печать на stdout так медленно? Можно ли его ускорить?


Я всегда был поражен / разочарован тем, сколько времени требуется, чтобы просто вывести на терминал с помощью инструкции печати. После некоторых недавних мучительно медленных журналов я решил заглянуть в него и был очень удивлен, обнаружив, что почти все время, затраченное на ожидание терминала для обработки результатов.

можно ли как-то ускорить запись в stdout?

Я написал скрипт ('print_timer.py' в нижней части этого вопроса) для сравнения времени при написании 100k строки в 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 op), и эффективно так же быстро, как просто сброс в мусор с /dev/null?

этой ссылке говорит о том, как терминал будет блокировать ввод-вывод, чтобы он мог "проанализируйте [вход], обновите его буфер кадров, свяжитесь с сервером X для прокрутки окна и так далее"... но я не до конца понимаю. Что может занять так много времени?

Я ожидаю, что нет никакого выхода (за исключением более быстрой реализации tty?) но я бы все равно спросил.


UPDATE: после прочтения некоторых комментариев я задался вопросом, насколько сильно влияет мой размер экрана на время печати, и это имеет некоторое значение. Действительно медленные цифры выше - это мой терминал 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

это, конечно, лучше (~4x), но не меняет мой вопрос. Это только добавляет на мой вопрос, поскольку я не понимаю, почему рендеринг экрана терминала должен замедлять запись приложения в stdout. Почему моя программа должна ждать продолжения рендеринга экрана?

все ли приложения terminal / tty не созданы равными? Мне еще предстоит поэкспериментировать. Мне действительно кажется, что терминал должен иметь возможность буферизировать все входящие данные, анализировать / визуализировать их невидимо и отображать только самые последние кусок, который виден в текущей конфигурации экрана с разумной частотой кадров. Поэтому, если я могу записать+fsync на диск за ~0,1 секунды, терминал должен быть в состоянии выполнить ту же операцию в каком-то таком порядке (возможно, с несколькими обновлениями экрана, пока он это делал).

Я все еще надеюсь, что есть настройка 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 sn" % (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 sn" % (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 sn" % (cmd, t)

print >> sys.stderr, "-----"
print >> sys.stderr, "timing summary (100k lines each)"
print >> sys.stderr, "-----"
print >> sys.stderr, summary
6 144

6 ответов:

как может быть, что запись на физический диск намного быстрее, чем запись на "экран" (предположительно, все-RAM op), и эффективно так же быстро, как просто сброс в мусор с /dev/null?

Поздравляем, вы только что обнаружили важность буферизации ввода/вывода. : -)

диск появляется чтобы быть быстрее, потому что весьма буферизованный: все в Python write() вызовы возвращаются до того, как что-либо на самом деле написано физический диск. (ОС делает это позже, объединяя многие тысячи отдельных записей в большие, эффективные куски.)

терминал, с другой стороны, делает мало или вообще не буферизует: каждый индивидуум 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

я запустил ваш тест записи файлов на моей машине, и с буферизацией, он также 0.05 s здесь для 100 000 строк.

однако, с вышеуказанными изменениями для записи без буферизации, требуется 40 секунд, чтобы записать только 1000 строк на диск. Я отказался от ожидания 100 000 строк, чтобы написать, но экстраполируя из предыдущего, это займет час.

это ставит терминал в 11 секунд в перспективе, не так ли?

так ответьте на свой первоначальный вопрос, запись на терминал на самом деле невероятно быстрая, все рассмотрено, и нет много места, чтобы сделать это намного быстрее (но отдельные терминалы различаются по тому, сколько работы они делают; см. комментарий Расса к этому ответу).

(вы можете добавить больше буферизации записи, например, с дисковым вводом-выводом, но тогда вы не увидите, что было записано на ваш терминал, пока буфер не будет сброшен. Это компромисс: интерактивность против массовой эффективности.)

Спасибо за все замечания! В конце концов, я сам ответил на него с вашей помощью. Тем не менее, он чувствует себя грязным, отвечая на ваш собственный вопрос.

Вопрос 1: Почему печать на stdout медленная?

ответ: печать в stdout составляет не по своей сути медленно. Это терминал, с которым вы работаете, который работает медленно. И это имеет практически нулевое отношение к буферизации ввода-вывода на стороне приложения (например: буферизация файлов python). Видеть под.

Вопрос 2: Можно ли ускорить?

ответ: Да, это может быть, но, по-видимому, не со стороны программы (сторона, выполняющая "печать" в stdout). Чтобы ускорить его, используйте более быстрый эмулятор терминала.

объяснение...

я попробовал себя называет 'легкий' терминальную программу под названием wterm и получил значительно лучшие результаты. Ниже приведен вывод моего тестового сценария (на внизу вопроса) при запуске в wterm в 1920x1200 в той же системе, где базовая опция печати заняла 12 секунд с использованием gnome-терминала:

-----
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.26 s гораздо лучше, чем 12s! Я не знаю, будет ли wterm более разумно о том, как он отображает экран по линиям того, как я предлагал (визуализировать "видимый" хвост с разумной частотой кадров), или он просто "делает меньше", чем gnome-terminal. Однако для целей моего вопроса у меня есть ответ. gnome-terminal медленный.

так что-если у вас есть долго работающий скрипт, который вы чувствуете, медленно, и он извергает огромное количество текста в stdout... попробуйте другой терминал и посмотреть, если это лучше!

обратите внимание, что я случайно вытащил wterm из репозиториев ubuntu / debian. этой ссылке может быть тот же терминал, но я не уверен. Я не тестировал никаких других эмуляторов терминалов.


обновление: потому что я должен был поцарапать зуд, я протестировал a целая куча других эмуляторов терминалов с тем же сценарием и полным экраном (1920x1200). Мои вручную собранные статистические данные здесь:

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

записанные времена собираются вручную, но они были довольно последовательными. Я записал лучшее (иш) значение. МММ, очевидно.

в качестве бонуса, это был интересный тур некоторых из различных эмуляторов терминалов, доступных там! Я поражен, что мой первый "альтернативный" тест оказался лучшим из группы.

ваше перенаправление, вероятно, ничего не делает, поскольку программы могут определить, указывает ли их выход 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

Я не могу говорить о технических деталях, потому что я их не знаю, но это меня не удивляет: терминал не предназначен для печати множество подобных данных. Действительно, Вы даже предоставляете ссылку на загрузку графического интерфейса, который он должен делать каждый раз, когда вы хотите что-то напечатать! Обратите внимание, что если вы вызываете скрипт с 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):
    ...

печать на терминал будет медленной. К сожалению, не написав новую реализацию терминала, я не могу понять, как вы значительно ускорите это.

в дополнение к выходу, вероятно, по умолчанию в режиме линейной буферизации, выход на терминал также вызывает поток ваших данных в терминал и последовательную линию с максимальной пропускной способностью или псевдотерминал и отдельный процесс, который обрабатывает цикл событий отображения, рендеринг символов из некоторого шрифта, перемещение битов отображения для реализации прокрутки дисплея. Последний сценарий, вероятно, распространяется на несколько процессов( например, сервер/клиент telnet, терминальное приложение, сервер отображения X11), поэтому есть проблемы с переключением контекста и задержкой.