Назад к разделу Technology

У половины наших фоновых задач был дедлайн, который никто не выбирал

Дефолт из командной строки в нашем образе контейнера молча ограничивал каждую фоновую задачу 120 секундами, включая батчи с десятками вызовов модели. Поправить число было простой половиной работы. Сложной было научить задачи умирать.

Категория
Общее
Обновлено
Автор
Stan Kharlap

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

Мы какое-то время держали эту ставку в масштабе, не замечая её. Norman делает бухгалтерию и налоговую отчётность для немецких компаний, а на практике это означает много неромантичной фоновой работы: прочитать чек, присвоить категорию, сверить платёж, пройти по queryset, подготовить отчёт. Через эту машинерию проходит почти миллион транзакций и около 40 000 новых документов в месяц. Большая часть этого живёт в очереди, и удивительно много где-то посередине вызывает языковую модель.

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

Теперь пуанта. Каждая фоновая задача, которая явно не объявила иного, работала с мягким бюджетом 120 секунд.

Логарифмическое сравнение измеренных задержек с бюджетами задач. Один детерминированный вызов инструмента имеет медиану около 60 миллисекунд и p99 около 4 секунд. Один вызов модели имеет медиану 5,5 секунды, p99 около 34 секунд и наблюдавшийся худший случай около 11 минут, который лежит далеко за старой линией бюджета в 120 секунд. Ниже три блока: массовая загрузка чеков до 95 файлов в одной задаче, каждый с OCR и проходом модели, на общем бюджете 120 секунд; импорт CSV до примерно 1800 строк с построчной категоризацией, где подвисшие задачи успели записать несколько сотен строк; и текущая схема с бюджетами в конфигурации по очередям, дефолтом 600 секунд soft и 900 секунд hard и отдельными числами для агентских очередей.
Худший случай одного вызова модели превышал бюджет, который мы выдали целому батчу из 95 файлов. Это число никогда не выбирали. Оно досталось нам от дефолта в шелле.

Никто его не задавал, поэтому никто его и не оспорил

Бюджет пришёл не из обсуждения архитектуры. Он пришёл из образа контейнера. Наш worker-entrypoint запускал пять мастеров Celery, по одному на очередь, и каждая командная строка заканчивалась чем-то вроде --soft-time-limit ${SOFT_TIME_LIMIT:-120}. Ни одно окружение никогда не выставляло SOFT_TIME_LIMIT. Значит, побеждал фолбэк, везде и всегда.

Важнее всего понять, почему это не поймали на код-ревью. Примерно половина наших сотни с небольшим задач объявляет собственные лимиты в декораторе, и они выглядели нормально. Вторая половина тоже выглядела нормально, потому что задача без лимита читается как "лимита нет". Но означает это не то. Celery выводит эффективный бюджет через дефолты пула воркера, а флаг командной строки безусловно перебивает конфигурацию приложения. То есть task_soft_time_limit в нашем модуле настроек не был источником истины, и чтение модуля настроек рассказывало удобную ложь.

Среди задач, унаследовавших эти 120 секунд, были полные проходы по queryset и циклы массового OCR. Одна из них принимает до 95 файлов в одной задаче, прогоняет по каждому OCR плюс проход модели, и имела меньше суммарного времени, чем один вызов модели в худшем случае.

Сам фикс: три строки и удалённый флаг. Убрать флаги у транзакционных очередей, перенести числа в конфигурацию, где они видны и переопределяемы, и оставить приоритет за декоратором самой задачи. Дефолт теперь 600 секунд soft и 900 hard. Агентские очереди сохраняют явные флаги, потому что их бюджеты не должны совпадать со всем остальным: батчевая работа агента получает щедрый soft-лимит, а интерактивная очередь, которую ждёт живой человек, получает жёсткий. Бюджет это продуктовое решение. Ему место там, где его увидит ревьюер, с комментарием рядом, объясняющим выбор.

Сигнал таймаута это исключение, и твой цикл его уже поймал

Вот эту часть я бы напечатал на плакате.

Soft time limit в Celery работает так: он бросает исключение внутри твоей задачи. В нашем случае это исключение наследуется напрямую от Exception. А теперь вспомни форму, к которой сходится практически любой батчевый джоб в любой кодовой базе:

for item in batch:
    try:
        process(item)
    except Exception:
        logging.exception("item failed")
        job.record_failure(item)

job.status = "completed"
job.save()

Этот цикл прав насчёт ошибок отдельных элементов и катастрофически неправ насчёт дедлайнов. Когда срабатывает soft-лимит, сигнал прерывания записывается на тот элемент, который случайно оказался в работе, помечается как его проблема и проглатывается. Дальше цикл идёт к следующему элементу, и к следующему, пока не придёт жёсткий лимит и не убьёт процесс воркера через SIGKILL. А значит, код после цикла не выполнится никогда. Строка джоба никогда не выйдет из importing. Итоговое письмо не уйдёт. Пользователь видит спиннер, который будет крутиться до тепловой смерти вселенной.

Доказательства всё это время лежали в базе. Из примерно 8300 задач импорта CSV чуть меньше сотни зависли в importing, большинство создано в предыдущий месяц, и в среднем они успели записать по несколько сотен строк, прежде чем замолчать. Тот же рисунок у массовых загрузок: горстка в processing, и ни одна не настолько свежая, чтобы ещё выполняться. Тот же рисунок в агентских таблицах, где пара сотен ранов за последний месяц стоят в running без терминального статуса. Три разные подсистемы, один баг, написанный независимо разными людьми, потому что форма этой ошибки это форма обычного защитного кода.

Фикс в том, чтобы перестать считать дедлайн отказом текущего элемента, потому что это не он. Это рантайм просит задачу уйти:

for i, item in enumerate(batch):
    try:
        process(item)
    except SoftTimeLimitExceeded:
        # Элемент здесь не виноват. Зафиксировать, докуда дошли, и уйти
        # с дороги: следующим будет жёсткий лимит, а он уже не выполняет
        # код очистки.
        job.set_failed(f"timed out after {i} of {len(batch)} items")
        raise
    except Exception:
        job.record_failure(item)

Здесь важны два свойства. Первое: прерывание пробрасывается дальше, чтобы воркер успел погасить задачу в окне между soft- и hard-лимитом, ровно для этого окно и существует. Второе: джоб финализируется до повторного броска, чтобы строка оказалась в терминальном состоянии, которое UI умеет отрисовать, а человек может обработать. "Прервано после 340 из 1772 строк, разбейте файл и попробуйте снова" это плохой результат. importing навсегда это вообще не результат.

Со вспомогательными функциями тоже пришлось быть аккуратным. Если вынести работу по одному элементу в отдельную функцию со своим catch-all, сигнал проглотится на уровень ниже и до цикла не дойдёт. Любой хелпер, оборачивающий работу модели, теперь пробрасывает прерывание явно, до своего общего обработчика.

Одна плохая строка не повод бросать queryset

Зеркальное отражение этого бага это проход, у которого обработки ошибок не было вовсе.

Несколько наших запланированных джобов были голым for invoice in qs.iterator(): с работой прямо внутри. Первая строка, бросившая исключение, завершала задачу и молча оставляла весь остаток queryset до следующего запуска по расписанию, который затем натыкался на ту же отравленную строку и снова останавливался в том же месте. В логах не было ничего вроде "этот проход не доработал", потому что с точки зрения Celery задача бросила исключение, и на этом всё.

Продакшен-картина по одному из них была наглядной: пара сотен счетов попадала в queryset прохода по просрочке, большинство из них были просрочены на месяц и более, а статус "просрочен" реально несли всего пара десятков строк. Проход давно умирал на старте.

Поэтому теперь проходы используют один маленький хелпер с намеренно сухим докстрингом: примени этот callable к каждой строке, посчитай, что получилось и что нет, изолируй ошибки по строкам и залогируй итог на уровне warning, если что-то упало. И, что критично, пробрось дальше лимит времени, потому что вот он является поводом остановиться. Различие, на котором держится вся статья, в одной функции: плохая строка означает продолжать, дедлайн означает выйти.

Итоговая строка лога важнее, чем кажется. processed=571 failed=20 на уровне warning это метрика, на которую можно поставить алерт. Молча обрезанный проход это не метрика.

Трать бюджет на модель, а не на справочную таблицу

Когда у задач появились честные дедлайны, следующим вопросом стало, на что они его тратят. Часть ответа была неловкой.

Наша встроенная таблица категорий это статические справочные данные: несколько десятков листовых строк, меняются только миграцией, без измерения по компании, и всё это влезает примерно в 128 кБ. OCR-экстрактор и сборщики промптов перечитывали её целиком для каждого документа и каждой транзакции. На батче это один полный последовательный скан на строку. Накопительно счётчики показывали полмиллиарда последовательных сканов за время жизни и десятки миллиардов прочитанных кортежей по одной этой крошечной таблице.

Ничто из этого не медленно так, как медленен медленный запрос. Каждый скан занимает меньше миллисекунды. Это медленно так, как медленны тысяча вещей по субмиллисекунде внутри построчного цикла: невидимо в профайлере и вполне заметно в общем времени батча. Кеш на время жизни процесса с lru_cache и хуком инвалидации на post_save, по тому же шаблону, что мы уже применяли для валют, убрал это. Скучно, механически, и возвращённые секунды уходят той части конвейера, которой они нужны.

Замечание о том, как мы измеряли, потому что сначала мы измерили неправильно

Ранняя версия докстринга к этому кешу уверенно утверждала, как нагрузка делится между путём запроса и батчами, на основе двух чтений статистики Postgres и разницы между ними. Число было неверным, и причину стоит передать дальше: Postgres 15 по умолчанию ставит stats_fetch_consistency в cache, что замораживает снимок статистики на всю транзакцию. Оба наших чтения были внутри одной транзакции, поэтому второе вернуло числа первого, и разница оказалась шумом в костюме находки.

При корректном повторном замере, с автокоммитом, та же таблица показала около 990 сканов в секунду в одном окне и меньше 40 через пять минут. Нагрузка всплесками, а заявленное разделение так и не было доказано. Мы отозвали утверждение прямо в докстринге, а не удалили его тихо, и только такой вариант меня устраивает.

Если из этого текста вы унесёте одну операционную привычку, пусть это будет она: снимайте pg_stat_* с автокоммитом, иначе ваши дельты это выдумка.

Для чего дедлайн нужен на самом деле

Первый рефлекс, когда джоб упал по таймауту, поднять лимит. Мы подняли лимит, и это было самое неинтересное из сделанного.

Дедлайн не препятствие, которое надо объехать. Это механизм, которым неограниченная работа становится ограниченной. И как только ты принимаешь, что вызов модели это неограниченная работа, любому батчу, который его содержит, нужны три вещи: бюджет, который кто-то осознанно выбрал и записал вместе с причиной; документированное поведение на случай, когда бюджет исчерпан, заканчивающееся тем, что джоб стоит в терминальном состоянии, видимом человеку; и изоляция по элементам, чтобы одна плохая строка не забрала с собой весь батч.

Ничто из этого не является AI-инженерией в том смысле, в каком обычно употребляют это словосочетание. В этой статье нет ни одного промпта. Но именно это в основном и отделяет агента, который работает в демо, от агента, который работает на 40 000 документах в месяц, и туда уходит непропорционально большая доля нашей работы над надёжностью. Модель это часть, которая получает внимание. Очередь это часть, которая решает, доверится ли кто-нибудь результату.

Norman берет операционную финансовую работу на себя

От invoicing до bookkeeping: Norman организует повторяющиеся финансовые процессы так, чтобы вы успевали к дедлайнам с меньшим объемом ручной работы.