Логи и метрики задач

Диагностика начинается с хендлера: именно здесь происходит работа, и здесь лог ценнее всего. Минимальный набор — пять полей на каждую попытку. Первое: тип задачи t.Type() — чтобы по строке лога сразу найти нужный код. Второе: идентификатор — asynq.GetTaskID(ctx) достаёт ID постановки из контекста; строка уникальна для каждой постановки, по ней связаны все попытки одной задачи, и дежурный отвечает на вопрос «что стало с задачей из заказа 4711» одним поиском по логам. Третье: номер попытки — asynq.GetRetryCount(ctx) возвращает, сколько попыток уже было; ноль означает первый заход, а растущий счётчик при одной и той же ошибке — прямой сигнал, что повтор не поможет. Четвёртое: длительность — time.Since(start) вокруг полезной работы; внезапный рост при неизменном коде чаще означает деградацию внешнего сервиса, чем баг. Длительность удобно сравнивать между попытками: резкий скачок на первой и на сотой попытке — разные истории. Пятое: сама ошибка — вместе с ретрай-политикой она объясняет, ушла ли задача в повтор или в архив. Пишите структурно: key=value, а не художественную прозу — парсер системы логов скажет спасибо. И держите одну строку на попытку, без дублей по пути — иначе при ретраях получится шум, в котором пропадает сигнал.

Второй слой — логи самого asynq: сервер пишет их без вашего участия, и стоит знать какие. На старте появляется «Starting processing», на остановке — «Starting graceful shutdown», затем сообщения про остановку процессора и «Exiting»: по этим строкам проверяют, что деплой прошёл чисто и серверы действительно завершились. Когда попытки задачи заканчиваются, сервер пишет предупреждение «Retry exhausted for task id=...» — полезный хвост для поиска задач, которые упали все двадцать пять раз. Эту строку легко алертить: она означает, что задача закончила жизнь в архиве и пора смотреть LastErr. Управляет этим поле Config.LogLevel со знакомой шкалой: DebugLevel, InfoLevel, WarnLevel, ErrorLevel, FatalLevel. Нюанс, о который спотыкаются: если LogLevel не задан, asynq логирует на DebugLevel — в продакшене это стены отладочных сообщений при каждом опросе очередей. Поэтому в боевом конфиге ставьте InfoLevel, а на шумных инсталляциях WarnLevel: останутся старт и остановка, исчерпанные ретраи и предупреждения, остальное уйдёт. Уровень задаётся в Config, а не переменной окружения: меняется вместе с деплоем, и это честная цена явного конфигурационного кода. В локальной разработке оставьте DebugLevel: подробности выборки задач из очередей экономят часы при непонятных зависаниях.

Логи отвечают на вопрос «что случилось с этой задачей», метрики — «как поживает очередь». Источник чисел — Inspector из пятнадцатого урока: GetQueueInfo возвращает QueueInfo со счётчиками по состояниям — Pending, Active, Scheduled, Retry, Archived, Completed, Aggregating — и общим Size, суммой всех состояний. Счётчики обработок живут рядом: Processed и Failed считаются с начала суток и сбрасываются ежедневно, ProcessedTotal и FailedTotal — накопительные с рождения очереди. Отдельного счётчика «retried» нет: число задач в retry-состоянии — это поле Retry, и растёт оно, когда попытки откладываются. Дубликаты Redis тоже не считает: уникальные задачи из двенадцатого урока отсекаются ещё на постановке, клиент возвращает ErrDuplicateTask — их можно посчитать только в своей клиентской обёртке, инкрементируя метрику при этой ошибке. Состояние Completed появляется, когда задачи оставляются с CompletedTTL, а поле Groups считает группы агрегации из десятого урока. Для истории есть метод History(queue, n): он возвращает DailyStats за последние n суток — Processed, Failed и дату, сырьё для графиков пропускной способности. И главное число для алертов — Latency, возраст самой старой pending-задачи. Обновлять срез удобно периодической задачей из девятого урока: раз в минуту читаете QueueInfo и экспортируете значения в свою систему метрик. Тот же срез печатается в лог и руками при инциденте: дежурный скрипт и экспортер используют один вызов GetQueueInfo.

Метрики хендлеров удобно собирать не в каждом хендлере, а одной обёрткой: у ServeMux из восьмого урока есть метод Use, принимающий MiddlewareFunc — функцию, которая получает Handler и возвращает Handler. Внутри оборачиваете ProcessTask: замеряете длительность через гистограмму с меткой по типу задачи и инкрементируете счётчик результата — успех или ошибка. Такой middleware добавляется одним вызовом mux.Use и работает для всех зарегистрированных типов: хендлеры остаются чистыми, а метрика появляется у новых задач автоматически. Значения в контекст кладутся тем же способом, что в семнадцатом уроке: middleware идёт первым и обогащает контекст до начала работы хендлера. Ошибку middleware обязан вернуть дальше — проглотить её значит соврать очереди, что попытка удалась: задача будет засчитана успешной и ретрая не получит. Порядок Use имеет значение: обёртки применяются в порядке добавления, и метрика, добавленная раньше логирующей, увидит тот же самый код хендлера. Типы задач — отличная метка для метрик: «упало три процента» малоинформативно, а «после деплоя упали все задачи типа email_invoice» — уже начало расследования. Кардинальность меток держите в узде: тип задачи — хорошая метка, ID задачи — нет, каждая уникальная метка рождает новый ряд в хранилище и убивает память.

Метрики без алертов — просто красивые графики, на которые смотрят после инцидента. Работающих сигналов немного. Первый — Latency из QueueInfo: возраст самой старой pending-задачи; пока воркеры успевают, он близок к нулю, и рост начинается раньше, чем очередь превратится в пробку. Второй — соотношение Retry и Archived к Processed: растущий Retry при плоском Processed означает, что зависимый сервис деградировал и попытки копятся; растущий Archived — что пошли фатальные ошибки, которые повтор не исправит. Третий — ошибки по типам задач: счётчик из middleware с меткой t.Type() покажет, что сломался конкретный тип, а не вся система. Четвёртый — Processed, упавший до нуля при непустом Size: воркеры не запущены, стоят на паузе или не видят Redis — классика первого инцидента. Для каждого сигнала нужны порог и окно, и пороги задаёт бизнес: письма и платежи терпят разное. И не алертите на всё сразу: три работающих сигнала полезнее десяти шумных. Дашборд asynqmon из шестнадцатого урока — отличный смотровой пункт, но алерт должен приходить сам, а не ждать, когда кто-то заглянет. Когда Latency растёт без видимых ошибок, проверяйте настройки конкурентности из двадцатого урока. А под Latency держите runbook: шаги из таблицы ниже должны выполняться одной рукой, не заглядывая в документацию.