dimhold.by
← Статьи

8 часов снимков без единого разрыва. Четверть пойманных новых процессов дал мой логгер

Мне хотелось знать, что делает мой ноутбук, пока я сплю. В ночь на 29 сентября одна из моих сессий Claude Code запустила на нём цикл с whotop 0.4.1: whotop ls --all --json каждые 5 минут до 8 утра. whotop это мой инспектор процессов, я написал его, чтобы выяснять, кто держит порт. На ноутбуке Windows. Сборку Windows мой лог не записывает, как и версии Chrome, Postgres и Claude Code. Цикл ещё писал строку в индекс на каждый снимок. Если между двумя снимками проходило больше 7 минут, он ставил пометку GAP, чтобы я увидел, когда ноутбук уснул.

В файле нет ни одного GAP. 96 снимков с 23:57 до 07:57 по часам ноутбука, с шагом 303-305 секунд. Сон короче пары минут так не заметить, но ничего похожего на сон я не увидел.

Машина была занята всю ночь

В начале было 486 процессов, к 00:13 их стало 510, утром 467. Минимум, 460, был в 03:14 и ещё раз в 06:21. За ночь лог увидел 1615 разных процессов. 415 из них были в каждом снимке, то есть прожили всю ночь. Остальные приходили и уходили. Новым я считал процесс, который стартовал позже первого снимка. Ключ это pid плюс время старта, потому что Windows переиспользует номера pid. Получилось 1129 новых процессов.

Прежде чем называть это шумом, надо было отрезать то, что шумом не было. До 01:58 мои агентские сессии ещё работали: шли сборки и ssh на сервер, где тоже шла сборка. Последней командой была сборка для продакшена в 01:58:56. После неё до утра ни один агент не запускал команд, кроме самого цикла логгера. Значит, тихая часть ночи это 6 часов, с 01:59 до 07:57. За это время лог поймал 711 новых процессов.

Больше всех шумел логгер

Я разложил новые процессы по родителям. Самой большой группой оказался сам whotop. Каждый снимок это node, который запускает PowerShell, а тому достаётся консольный хост. Выходит 3 процесса каждые 5 минут. За всю ночь это 285 из 1129, 25 процентов. После 01:59 это 216 из 711, 30 процентов.

Потом я сверил время старта остальных процессов с логгером. Оказалось, что доля может быть намного больше. На Windows whotop читает таблицу процессов через Get-CimInstance Win32_Process, порты через Get-NetTCPConnection и службы через Get-CimInstance Win32_Service. Всё это идёт через WMI. А WMI загружает своих провайдеров в отдельный процесс WmiPrvSE. После 01:59 появилось 70 новых WmiPrvSE. 40 из них стартовали через 0,39-0,56 секунды после node логгера. С bash в моих сессиях Claude Code вышло так же. Все 46 стартовали через 0,37-0,74 секунды после логгера и ни разу в другой момент. Они пришли из 6 разных сессий. Только одна из них та, что крутит цикл. Вместе с ними стартовали 28 консольных хостов. Если их запускает логгер, то это 330 из 711, 46 процентов тихой части ночи.

0 50 100 150 200 250 202 00:00 220 01:00 149 02:00 115 03:00 107 04:00 112 05:00 106 06:00 118 07:00 последняя команда агента 01:58 мой логгер хосты WMI Chrome Windows агенты и прочее
Новые процессы по часу снимка, в котором их увидели впервые. За ночь 1129, из них 285 это сам логгер. После 01:58 ни один агент не запускал команд.

Кто ещё просыпался

На втором месте Chrome. После 01:59 он запустил 169 новых процессов: 96 процессов расширений и 73 рендерера страниц. Это от 22 до 34 в час до самых 8 утра. В командной строке написано --extension-process, но не написано, какое расширение, поэтому я не знаю, кто перезапускается так часто.

Сама Windows запустила 97. Больше всего svchost, их 69. Командная строка у них скрыта, я вижу только имя. Интереснее те, у кого имя говорящее. Пара установщика модулей Windows (TiWorker вместе с TrustedInstaller) стартовала за ночь 9 раз, 5 из них после 01:59, последний раз в 04:39. Процессы поискового индексатора приходили за ночь 7 раз, 4 из них после 01:59 и 3 из них между 07:26 и 07:35. CompatTelRunner, телеметрия совместимости, стартовал в 03:19 и в 03:34 запустил вторую копию себя. Microsoft описывает обслуживание как работу, которая идёт, когда машина простаивает и питается от сети. Это сходилось бы, если ноутбук стоял на зарядке, но в логе этого нет. Журнал планировщика заданий я тоже не снимал, поэтому сказать, какие из этих запусков были обслуживанием, не могу.

Postgres запустил 23 дочерних процесса, вразброс по всем 6 часам. 5 из них тоже стартовали сразу после логгера.

Кто прожил всю ночь

Среди 415 долгожителей было 9 процессов claude.exe, один из них демон. Самый старый стартовал 21 сентября, за неделю до лога. У серверов разработки было 43 процесса и 14 слушающих портов на всех. Самый старый из них стартовал сразу после полуночи 25 сентября, почти за 4 дня до лога. Я написал whotop, потому что однажды убил не тот node, когда искал, кто держит порт. Нужен ли был ещё хоть один из этих 14, лог не говорит.

Чего лог не видит

0 мин 5 мин 10 мин 15 мин снимок снимок снимок живёт всю ночь виден 3 раза короткий, попал в снимок виден 1 раз короткий, между снимками не виден
Снимок раз в 303-305 секунд видит только то, что живо в этот момент. 978 из 1129 новых процессов видны ровно в одном снимке, так что на самом деле их больше.

Снимок раз в 5 минут видит только то, что живо в этот момент. Процесс, который прожил 2 секунды между двумя снимками, в лог не попадает вообще. Здесь я дважды передумал насчёт bash. Сначала я решил, что их запускает снимок, потом, что это просто выборка. Время старта выше вернуло меня к первой версии. Но очень короткий процесс, запущенный в случайный момент, тоже виден, только если он жив во время запроса. Значит, он тоже выглядел бы привязанным к логгеру. Лог эти 2 случая не различает. Как выглядит случайный старт у процессов подольше, показывает Chrome. Его 169 новых процессов пойманы в самом разном возрасте и ни разу сразу после логгера.

978 из 1129 новых процессов видны ровно в одном снимке, так что на самом деле стартов больше. А логгер выглядит большим ещё и потому, что это единственный процесс, который гарантированно жив во время каждого снимка. Его 3 процесса не теряются никогда.

И ещё лог это только список того, кто работает. Сколько ресурсов они съели, в нём нет вообще. whotop работал без прав администратора, поэтому в каждом снимке 158-183 процесса не показали свою командную строку. Для Postgres это значит, что я не могу отличить autovacuum от клиентского подключения. Я снял только эту одну ночь.