Наш публикатор сутки врал «опубликовано», хотя поста не было
8 сентября днём я заметил, что паблик ВКонтакте не обновлялся с самого утра. Открываю отчёт публикатора — там всё зелёное: «опубликовано», рядом даже ссылка на пост. Перехожу по ссылке в саму ВК — поста там нет. Ни утреннего, ни вчерашнего вечернего.
Дальше было то, что обычно называют «долго искали», хотя на деле всё оказалось довольно быстро — если бы я сразу не поверил собственным логам.
Первая версия была простая: решил, что дело в токене, полез проверять доступ к API ВК и тут же получил ответ «Flood control» на самом безобидном запросе. Обрадовался: вот и причина, площадка просто ограничила аккаунт. Но когда стал разбираться, откуда взялось ограничение и почему об этом никто не сообщил раньше, вскрылась история интереснее.
Внутри пайплайна есть узел, который принимает ответ от площадки и докладывает наверх, что публикация прошла. Он был устроен так, что писал `status: published` вообще не глядя на то, что реально ответила площадка. Если ссылки на пост не было — потому что публикация не удалась, — в это поле подставлялось пустое значение. Наш приёмник на другом конце ждал в этом месте строку и, получив пустышку, честно отвечал ошибкой. Но и эту ошибку узел молча проглатывал через пустой обработчик исключений — и всё равно докладывал: колбэк отправлен, всё хорошо.
То есть друг друга маскировали сразу две неправды. Площадка не приняла публикацию. Наш узел заявил, что приняла. А когда собственная система попыталась возразить и вернуть ошибку — эту попытку тоже никто не услышал. Настоящий текст ответа площадки — то самое «Flood control» — вообще не долетал до логов: он обрезался до хвоста технического сообщения на пару символов, без сути. Поэтому сутки казалось, что площадка вообще не отвечает, хотя она вполне вежливо и внятно отказывала — просто мы сами не дали себе это увидеть.
Хуже другое: мы сами усугубили ситуацию. Система ждёт ответа от площадки пятнадцать минут и, если тишина, повторяет попытку — до трёх раз. За два дня в сторону уже заблокированного по флуду аккаунта улетело восемь таких попыток подряд. Каждая — это заново залитое видео и новая попытка публикации поста в очередь. Хорошо, что ограничение оказалось временным, а не постоянной блокировкой: если бы площадка расценила этот повторный стук как злоупотребление, отделаться было бы сложнее.
И вот что неприятно осознавать: точно такая же болезнь сидела ещё в пяти-шести похожих узлах для других площадок. Все они писали «успех» по факту того, что вызов API отработал без исключения, а не по факту того, что контент реально появился на площадке. Урок звучит почти банально, но обошёлся в день разбирательств: успешный ответ функции — не то же самое, что доставленный результат. Функция может честно отработать и вернуть код 200 на своём уровне, а по факту снаружи не появится ничего.
Что мы починили:
— узел больше не докладывает «успех» наверх, если площадка ответила ошибкой;
— поле со ссылкой на пост заполняется только тогда, когда ссылка реально есть, а не пустышкой;
— текст ответа площадки теперь доходит до логов целиком, а не обрубком технического сообщения;
— поставили отдельного сторожа, который раз в час сам дёргает площадку одним лёгким запросом и, как только ограничение снимается, сразу пишет нам в телеграм.
На разбор и проверку ушёл почти целый день, хотя самих правок в коде — несколько строк. Основное время съело именно то, что зелёные логи не давали повода искать проблему там, где она реально была: система убедительно врала сама себе, а заодно и мне.
Вывод для себя сформулировал так: если система умеет отчитываться «успех», у неё обязательно должен быть отдельный, не глотающийся канал, чтобы честно сказать «нет» — причём именно там, где ответ реально проверяется автоматикой, а не там, где мне удобно поставить галочку руками. Пока такого канала для ошибки нет, «площадка не отвечает» и «система тихо соврала» выглядят абсолютно одинаково — и одинаково опасны, потому что обе выключают внимание именно тогда, когда оно нужнее всего.