Призрак в проводе: как мы два дня искали сетевой баг, которого не существовало
· 4 min read
Self-hosted раннер обслуживает CI пяти репозиториев на одной физической виртуалке. И вот он начал вести себя странно. Job для engine висел в очереди GitHub Actions больше суток. Он просто стоял. Сам супервизор синхронно рестартовал себя каждые две с половиной — три минуты круглые сутки. Мы назвали эту проблему «карусель». Два дня мы гонялись за призрачным багом.
Симптом и первая ложная зацепка
Раньше мы уже сталкивались с настоящим сетевым багом в этой инфраструктуре. Это была классическая «чёрная дыра» NAT в VirtualBox. Из-за неё TCP-соединение внутри гостевой виртуалки молча умирало без FIN/RST, и гостевая система считала его вечно живым. Тот баг мы нашли и закрыли полторы недели назад.
Супервизор снова начал виснуть, теперь уже на хостовой стороне. Рефлекс сработал моментально. Нам показалось, что это та же болезнь в новой форме. Ощущение было настолько убедительным, что расследование ушло в сторону на целый день. Watchdog детектировал зависание, убивал процесс и поднимал его заново. Каждый новый экземпляр стабильно вис через 150–190 секунд. Такая идеальная регулярность должна была насторожить нас гораздо раньше.
Эскалация: пакеты, дамп памяти, реестр питания
Дальше начался добросовестный и абсолютно бесполезный забег по сетевым гипотезам. Мы отключили сторонний NDIS-фильтр VirtualBox на физическом Wi-Fi адаптере. Сбросили режим энергосбережения MIMO на сетевой карте. Ничего из этого не сработало.
Запуск pktmon во время зависания показал абсолютно здоровую сеть. Новые TCP-соединения к GitHub устанавливались за 60 миллисекунд. «Зависший» процесс в это время якобы ничего не мог отправить. Мы почему-то решили, что зависание происходит до отправки пакета, и продолжили копать не туда.
Дамп памяти через WinDbg с загруженным SOS показал двадцать два потока. Ни один из них не сидел внутри HTTP-вызова. Мы нашли подозрительные модули вроде драйвера антивируса или проверки сертификатов crypt32. Все эти красивые кандидаты в причины сбоя рассыпались при проверке.
Параллельно обнаружилась интересная деталь. Хост уходил в Modern Standby по таймауту простоя синхронно с зависанием. Восемь эпизодов из восьми совпали с уходом в сон. Мы отключили таймаут сна полностью. Карусель рестартов продолжилась с той же периодичностью. Корреляция была, связи — нет.
Второй взгляд решает половину дела
Пока одни ковыряли сеть, вторая сессия смотрела на проблему шире. Выяснилось, что watchdog считал зависанием абсолютную тишину в логе. Когда очередь пуста, опрос GitHub API ничего не пишет. Он просто спит двадцать секунд и повторяет попытку. Несколько таких тихих циклов выглядят для таймера неотличимо от мёртвого процесса.
Мы проверили гипотезу напрямую. Сняли счётчики ввода-вывода процесса ReadTransferCount и WriteTransferCount с разницей в 25 секунд. Байты реально двигались. Процесс был жив, просто ему нечего было логировать. В watchdog добавили проверку этих же счётчиков. Рестарты прекратились. Однако engine всё ещё отказывался запускаться.
Настоящая причина
Мы сделали прямой тест тем же токеном, которым пользуется сам супервизор. Запрос runs?status=queued для engine выдал ноль результатов. Личным токеном через gh api тот же job находился мгновенно. Права доступа были в порядке.
Разгадка скрывалась в ответе API. У самого рана поле status было "pending". А вот у job внутри этого рана статус был "queued". Наш код фильтровал раны по статусу на верхнем уровне. Фильтр никогда не совпадал. GitHub развёл статус рана и статус job’а. Одна кривая строчка фильтра физически не давала коду найти зависший job.
Мы убрали фильтр на уровне рана. Вложенная проверка на уровне job’а отлично справлялась сама. Первая же попытка нашла и выполнила оба зависших задания. Парсинг, рендер, деплой на Cloudflare Pages и тесты прошли зелёным.
Маленький постскриптум: фикс своего же фикса
Снятие фильтра породило новую мелкую проблему. Код начал забирать десятки последних ранов на каждый репозиторий и делать отдельный запрос job’ов для каждого. Вместо пары вызовов в тик получалась сотня. Карусель рестартов вернулась через несколько минут из-за реального падения I/O в ноль. Мы дописали клиентскую фильтрацию, чтобы пропускать раны со статусом completed. Объём вызовов нормализовался.
Что унести с собой
Добросовестная диагностика иногда уводит глубоко в лес. Инструменты вроде WinDbg и снифферов трафика честно показывали здоровую сеть. Мы просто интерпретировали их сигналы в пользу своей изначальной теории. Самым дешёвым и эффективным оказался простой вызов API с нужным токеном.
В следующем эпизоде разберёмся с юридическими границами кода. Мы вынесли семейство рендереров в отдельный приватный плагин, чтобы чётко отделить наши внутренние разработки от логики, появившейся благодаря работе с внешним форматом. Настоящий clean room рефакторинг.