Логирование запросов к модели: что писать, чтобы разбирать инциденты

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

НАБЛЮДЕНИЕЧто видно, когда всё записаноИ чего не видно, когда логов нетРасход по времениПоследний час12:00:10:20:30:40:5013:00Всплеск в 12:40 — ночной пересчёт отчётовРазбивка по сценариямПоддержка62%Разбор документов24%Фоновые отчёты14%Без такой разбивки экономить приходится вслепую
Разбивка по сценариям показывает, куда на самом деле уходит бюджет

Что писать по каждому запросу

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

  • **Идентификатор запроса** от провайдера. Без него поддержка не найдёт ваш случай.
  • **Название модели и её версия.** Ответы меняются при обновлении версии, и это надо уметь доказать.
  • **Токены на входе и на выходе по отдельности.** Они стоят по-разному, и смешивать их бессмысленно.
  • **Сценарий и пользователь.** Иначе расход не разложить.
  • **Время ответа** — отдельно до первого фрагмента и до последнего, если используется потоковая выдача.
  • **Код и текст ошибки**, если запрос не удался.
ПОЛЯЧто писать в журнал по каждому запросуИдентификатор запроса — без него поддержка не найдёт случайНазвание модели и версияТокены на входе и на выходе по отдельностиСценарий и пользователь — для разбивки расхода!Текст запроса целиком — только если он не содержит персональных данныхПоследний пункт решается один раз и записывается в регламент, а не оставляется на усмотрение разработчика.
Последний пункт решается один раз и записывается в регламент

Что писать нельзя

Заголовок авторизации. Никогда, ни в каком виде. Ключ, попавший в лог, считается скомпрометированным, а логи хранятся дольше и доступны шире, чем кажется.

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

Оставлять это на усмотрение разработчика нельзя — решения окажутся разными в разных частях системы.

Разбивка расхода по сценариям

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

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

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

Метрики, за которыми стоит следить

Четыре величины покрывают большинство ситуаций.

МетрикаО чём говорит
Токенов в суткиОбщая динамика расхода
Средний размер запросаРаздувание контекста
Доля ошибок по типамУпор в лимиты или сбои
Время до первого фрагментаОщущение скорости у пользователя

Второй показатель обычно самый информативный. Если он растёт при неизменном числе запросов, значит, в контекст что-то добавляется — и это надо найти до конца месяца.

Настройте уведомление на резкий скачок расхода. Первым признаком утечки ключа обычно бывает не взлом, а необъяснимый рост числа запросов ночью.

Хранение

Полные записи нужны недолго — от недели до месяца, этого хватает на разбор инцидентов. Агрегированные цифры за день имеет смысл хранить дольше: по ним видно динамику за квартал.

Такое разделение решает и вопрос объёма, и вопрос персональных данных: подробности живут коротко, а долгосрочная статистика их не содержит.

С чего начать, если логов нет совсем

Не пытайтесь сделать всё сразу. Порядок внедрения, который работает:

  1. Записывать идентификатор запроса, модель и токены. Это одна строка на вызов и покрывает большинство инцидентов.
  2. Добавить метку сценария. Именно она превращает журнал в инструмент управления расходом.
  3. Настроить суточную сводку: сколько запросов, сколько токенов, сколько ошибок.
  4. Добавить уведомление на резкий скачок.
  5. И только потом — подробности вроде текстов и таймингов по этапам.

Первые два пункта делаются за час и дают восемьдесят процентов пользы.

Как выглядит разбор инцидента

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

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

Дальше смотрите размер контекста: он у верхней границы окна. Значит, часть подмешанных документов могла не попасть в запрос.

Проверяете гипотезу: берёте тот же вопрос, сокращаете контекст, повторяете. Ответ верный. Причина найдена за десять минут.

Без журнала тот же разбор занял бы день и, скорее всего, закончился бы выводом «модель иногда ошибается». Разница целиком в трёх полях: версия, размер контекста, идентификатор запроса.

Как этим пользоваться

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

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

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

Написать