Мы поставили сторожа на конвейер публикаций. Первую неделю он сторожил сам себя

У нас несколько фоновых агентов публикуют контент на разных площадках по расписанию — Дзен, VC, TenChat, Хабр. Если основной движок не справился за 20 минут, включается запасной. Чтобы не сидеть в логах руками и не пропускать пустые слоты, поверх этого стоит раннер: он спрашивает у каждой площадки факт публикации, сверяет с базой и, если слот не закрылся, шлёт алерт с просьбой перезапустить вручную.

Идея была простая: пусть сторож ловит наши сбои, а мы разбираем только его алерты. За неделю с 5 по 10 сентября вышло иначе — в девяти смерженных PR подряд чинили не публикации, а сам сторож. Ниже — по порядку, что он врал и почему.

Три минуты на проверку, три секунды по факту

6 сентября в лог начали падать четыре строки подряд:

проверка факта не ответила за 3 минуты — считаю недоступной
проверка факта не ответила за 3 минуты — считаю недоступной
проверка факта не ответила за 3 минуты — считаю недоступной
проверка факта не ответила за 3 минуты — считаю недоступной

Обе задачи публикации на VC в этот день провалились по таймауту — 20 минут, ноль результата, ручной перезапуск. Логичная первая мысль: питоновская проверка сама подвисает под нагрузкой. Запустил ту же команду руками в тот же час, на той же машине, пока рядом крутился агент. Ответ пришёл за 3 секунды.

Проверка была ни при чём. Тормозила обвязка — Start-Job в PowerShell поднимает не поток, а отдельный процесс PowerShell со своим окружением с нуля, и на машине, где уже жуёт ресурсы фоновый агент, только это поднятие занимает минуты. Цикл ожидания зовёт проверку каждые 30 секунд — то есть агент терял не своё время на работу, а наше время на накладные расходы обёртки.

# было: Start-Job { & python $verify $task } | Wait-Job -Timeout 180
$p = Start-Process -FilePath 'python' -ArgumentList @($VERIFY, $Task) `
      -RedirectStandardOutput $tmp -RedirectStandardError "$tmp.err" `
      -PassThru -WindowStyle Hidden
if (-not $p.WaitForExit(180000)) { ... }

Start-Process с WaitForExit по миллисекундам стоит ровно столько же, сколько сам python, без второго PowerShell и его инициализации. Таймаут в три минуты и честный откат при реальном зависании остались — просто перестали срабатывать там, где зависания не было. Ирония в том, что этот лимит я вводил именно против зависаний раннера, неделей раньше, после отдельного инцидента.

Штатная страховка выглядела как авария

Статистика прогонов Дзена за 7 дней: первый движок (codex) справляется сам 13 раз из 17, три раза уходит в таймаут и подхватывает запасной, один раз — честный fallback без таймаута. То есть система работает как спроектирована в трёх случаях из четырёх, а в четвёртом отрабатывает страховка. Но каждый такой случай уходил Роману отдельным тревожным сообщением, и за три дня их накопилось столько, что настоящие поломки в них потонули.

Поправка простая: первый за сутки успешный откат пишется в лог, а не в бота. Второй и последующие подряд — уже уходят, с указанием, сколько раз подряд выручал запасной, потому что это уже закономерность, а не штатный сбой.

Сообщили об аварии раньше, чем узнали её исход

Хуже получилось с другим сценарием: агент отчитался «пост не опубликован, моя проверка ошибочно приняла невидимый символ за расхождение», и раннер тут же переслал это Роману как факт. Через восемь минут запасной агент дотянул задачу и статья вышла, но опровержения о ложной тревоге не было — сообщение о провале уже улетело, и человек уже начал разбираться в несуществующей проблеме.

Здесь риск был не в лишнем сообщении, а в том, что кто-то мог довериться отчёту раньше отката и опубликовать материал вручную — а десять минут спустя это же сделал бы запасной агент, и мы получили бы дубль на площадке. Теперь сообщение о ложном успехе не уходит до момента, пока не станет ясен итог отката: пишем в лог, а наружу идёт либо «не смогли оба», либо тишина закрытого слота.

Норму дня мерили по чужим публикациям

8 сентября вечерний слот Дзена вообще не запустился: норма на сутки выбрана (3 из 3) — агента не запускаю. В ленте канала действительно лежали три материала за сутки, но наших — два, третий Роман опубликовал сам, руками, из личного черновика. Норма мерилась по всей ленте площадки, а лента не различает автора публикации.

Разделили два разных вопроса, которые до этого считали одним:

• норма дня — по записям нашей платформы (verify_publication --ours);

• факт публикации — по-прежнему максимум из платформы и ленты, потому что лента ловит статью, которую агент не успел зарегистрировать в базе.

Проверка на живых данных: verify dzen_publisher вернула 3, verify dzen_publisher --ours — 2. Слот в тот же вечер запустился.

Спросили факт у задачи, которая не публикует

verify_publication.py знает пять публикующих задач и на любую другую честно отвечает -1 — «неприменимо». А цикл ожидания раннера принимал -1 за перебой связи и трижды пересматривал его с паузой в 30 секунд, прежде чем поверить. Для вахты комментариев TenChat и нового комментатора Хабра это две потерянные минуты за прогон и строка «проверка факта недоступна» в логе — при разборе поломки по этой строке искали несуществующий сбой SSH. Правка — ранний выход из ожидания для задач, у которых факт публикации в принципе не считается.

Отметка «уже сообщили» переехала на пустую строку

9 сентября в 18:20 Роман получил алерт «VC.ru, день (08.09) — нет записи», а через два часа — то же самое ещё раз, будто ничего не отправляли. Отметки «уже сообщили» хранились в первой строке реестра по id, а id — это случайный UUID. В 20:17 в реестр добавились три новые задачи, и у одной UUID оказался меньше прежнего — «якорь» переехал на строку с пустой историей, и через три минуты сторож честно доложил всё заново.

Починили с двух концов: якорем теперь становится САМАЯ СТАРАЯ строка по времени первого появления, а не по случайному id, и при чтении отметок сторож смотрит на все строки хоста сразу, а не только на текущий якорь — так даже будущий переезд не превратится в повторную рассылку.

Материал вышел, а мы доложили о пропуске

Ровно противоположный случай произошёл в тот же день с утренним Дзеном: статья вышла, раннер увидел её в ленте и погасил зависшего агента — но в платформу запись не попала, потому что агента убили раньше, чем он дописал финальные шаги. Запись появилась только в 14:40, во время дневного слота. В итоге утро формально осталось «пустым», день закрылся дважды в базе, а сторож слотов отчитался о пропуске, которого на площадке не было.

Теперь раннер сверяет количество СВОИХ публикаций до и после прогона, и если по факту материал вышел, а прирост записи в платформе не случился — шлёт явный алерт «зарегистрируйте вручную» вместо того, чтобы гадать или молчать.

Контейнер две недели был мёртв, а мы об этом не знали

Отдельно от раннера — тот же принцип подвёл и в инвентаре инфраструктуры. Контейнер warp (прокси для соцсетей) две недели простоял Up 2 weeks (unhealthy): docker ps показывал его живым, снимок реестра писал «ok», а сторож пропускал докер-контейнеры целиком, потому что они «не запускаются по расписанию» и логика была рассчитана на молчание, а не на статус здоровья. Узнали только когда через него не залилась картинка и упал вечерний слот социальных сетей — прокси не отвечал вовсе.

Правка — спрашивать здоровье контейнера напрямую: docker inspect -f '{{if .State.Health}}{{.State.Health.Status}}{{else}}none{{end}}', и писать unhealthy как сбой со временем снимка, а не полагаться на факт, что контейнер вообще запущен.

Что не сработало и где просто повезло

Не все находки были одной аккуратной правкой. Комментатор Хабра почти оставил дубль под чужой статьёй: комментарий ушёл нормально, но проверка habr_comment.py искала подстроку из первых 60 знаков ответа, а в этот кусок попадал перенос абзаца — в textContent страницы абзацы идут встык, без переводов строки, и подстрока не могла совпасть никогда. Скрипт десять раз подряд решил, что комментарий не появился, и был готов отправить его снова. Спасло не наше исправление — оно появилось только на следующий день, — а разовая ошибка 403 Request not allowed у второго агента в момент, когда он мог бы продублировать пост. Повезло. Позже подстроку сузили до первого абзаца (без переносов), и проблема ушла сама.

Заодно нашёлся побочный эффект всех этих таймаутов и откатов: скопилось 24 висящие вкладки браузера — фоновые запуски, убитые по таймауту, не успевали закрыть их сами. Уборщик по расписанию теперь закрывает вкладки мёртвых процессов и невидимые вкладки наших площадок старше 45 минут, не трогая всё остальное; на первом прогоне из 24 вкладок осталось четыре чужих.

Итог

Девять смерженных правок за шесть дней, и ни одна не касалась самих публикаций — только слоя, который должен был их защищать. Каждый раз логика поломки была одинаковая: защитный механизм считал, что видит правду о системе, а на деле видел собственную выдумку — то накладные расходы обёртки принимал за зависание задачи, то ленту площадки принимал за наши публикации, то случайный порядок строк в базе принимал за порядок времени. Профилировать и проверять на живых данных пришлось не саму автоматизацию, а надзор над ней — и именно потому, что надзор появился недавно и никто ещё не грузил его под нагрузкой.