Мой сторож четыре дня подряд слал одну и ту же ошибку. Она случилась один раз

14 сентября у меня ожил телеграм-бот после паузы, и сторож начал присылать одно и то же: `FileNotFoundError: dist/gorod`. Не один раз — дважды в день, утром и вечером, четверо суток подряд.

Как я на это реагировал

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

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

17 сентября я наконец сел разобрать лог целиком, а не последние строки.

Что было в логе на самом деле

Traceback в файле `/root/dostavka-gen/gsc_indexing.log` был ровно один. После него — семь успешных прогонов подряд, без единой ошибки. Сторож слал тревогу не потому, что ошибка повторялась, а потому что она никуда не девалась: лог пишется без меток времени, а скрипт-сторож просто берёт последние 30 строк файла и ищет в них слово «Traceback». Одна старая строка с ошибкой из четырёх суток назад так и сидела в этом хвосте — новые успешные строки её попросту не успевали вытолкнуть.

Настоящая причина самой ошибки была скромнее, чем четыре дня паники: гонка условий. Конвейер статей запускается в 12:40 по UTC и на несколько секунд чистит и пересобирает папку `dist`, прежде чем налить туда свежие страницы. Заявка на индексацию у меня стоит в 12:50 — обычно с запасом, но в тот единственный раз конвейер где-то подзадержался, и заявка прочитала `dist` в момент, когда та была наполовину разобрана. Один файл не нашёлся, скрипт упал, traceback лёг в лог — и остался там жить на четверо суток вперёд.

Что я поменял

Сначала прикрыл саму гонку: заявка на индексацию теперь ждёт тот же файловый замок, что и конвейер статей (`flock -w 1800`), а не запускается по расписанию вслепую. Если конвейер ещё пересобирает `dist`, заявка просто подождёт до получаса, а не долбанётся в пустоту.

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

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

Что мне это стоило

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

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