Могучий strace
подвел меня. Как это возможно?
time foo
показывает, что foo
для запуска требуется несколько секунд («реальный»), но используется незначительное время процессора, как в пользовательском пространстве («пользователь»), так и в ядре («sys»). Для любопытных foo
определяется ниже.
Поэтому он проводит большую часть своего времени в ожидании чего-то другого, а не выполнения инструкций процессора. Обычно я вижу, как он ожидает strace
- то есть какой системный вызов блокируется на длительный период времени. К сожалению, этот подход не сработал.
strace -ttt -T -C -w foo
показывает системные вызовы, отметку времени и сводку (реального) времени, проведенного в системных вызовах. Но этот конкретный процесс показал, как тратит незначительное общее (реальное) время внутри системных вызовов.
foo
на самом деле journalctl -b -u dev-hugepages.mount
. За исключением того, что мне пришлось каждый раз менять последний аргумент на другой системный блок, чтобы воспроизвести это. Другими словами, задержка, которую я исследую, произошла в первый раз, когда я пытаюсь получить журналы для какого-либо одного системного устройства. РЕДАКТИРОВАТЬ : после ответа на главный вопрос, я также понял причину, по которой у меня была эта проблема воспроизводить задержку .
Время, затрачиваемое на этот процесс, является специфической проблемой, по-видимому, это происходит не во всех системах. https://github.com/systemd/systemd/issues/7963
источник
journalctl
запускает только один процесс. У меня есть ощущение,journalctl
что по какой-то причине используется один дополнительный поток - в iirc был один вызов clone (). Я думаю, что это означает, что вы технически правы, но это также технически не имеет отношения к вопросу.time
смотрит на процесс в целом и показывает, что процесс в целом довольно сонный (блокирование чего-либо).strace
не показал достаточно спит. Не имеет значения, если второй поток спит, основной поток также должен быть очень сонным, чтобы объяснитьtime
результат.Ответы:
Обычная причина для решения этой проблемы, заключается в том, что процесс блокирует ошибки страницы. Это чтение или, возможно, запись в файлы, выполняемые через отображение памяти
mmap()
. Возможно, вы заметили некоторыеmmap()
из следов системных вызовов.Если бы вы использовали
/usr/bin/time
программу вместоtime
встроенной оболочки, вы могли бы также заметить:major
pagefaults - это те, которые требуют ввода-вывода файловой системы.minor
сбои страниц гораздо менее значительны (вероятно, только «промах TLB»).Я подозреваю
inputs
, что общее количество прочитанных страниц. В настоящее время я думаю, что отображаемые на файл страницы всегда имеют одинаковый размер. 4096 байт в большинстве случаев, но вы можете проверитьgetconf PAGESIZE
.Таким образом, это составляет ~ 290 мегабайт, считывание со скоростью более 100 мегабайт в секунду, стандартная скорость для жесткого диска, подобного моему. Тайна разгадана!
Также обратите внимание, что вы предполагаете, что у вас есть целый свободный процессор для этого процесса. В противном случае процесс может быть просто заблокирован, ожидая, пока другие процессы выдадут ЦП.
strace
только показывает, когда процесс входит (и затем покидает) ядро из-за системного вызова. Или когда сигнал unix доставлен. Однако существуют другие типы прерываний, которыеstrace
вообще не отображаются. Так что они включаютисточник