Сэмплирование: не тонем в логах

Сэмплирование логов в zapcore реализовано как обёртка-ядро: NewSamplerWithOptions(core, tick, first, thereafter) принимает ядро и возвращает ядро — поэтому сэмплер встанет и на ручную сборку из прошлого урока, и под пресет. Механика zap sampling — арифметика на счётчиках. Параметры: tick — длительность окна, обычно time.Second; first (Initial) — сколько записей проходят целиком в начале окна; thereafter (Thereafter) — какая по счёту из дальнейших пропускается: значение 100 означает «каждая сотая». Счётчик ведётся по паре уровень плюс сообщение: сто ошибок с текстом «connection refused» — это один счётчик, а «connection refused» и «timeout» — два разных. Ключевой момент: окно прокручивается каждые tick — в новую секунду счётчики обнуляются и снова идут первые N записей. Устаревшая функция NewSampler до сих пор в пакете, но помечена Deprecated: пишите NewSamplerWithOptions, она же даёт опции вроде хука решений, о нём ниже.

Пара сто и сто — не случайность: ровно столько живёт в production-пресете. В zap.Config за это отвечает поле Sampling: указатель на zap.SamplingConfig с полями Initial и Thereafter; пресет NewProductionConfig выставляет Initial: 100, Thereafter: 100 при окне в одну секунду. Считается это так: в течение секунды первые сто записей с одинаковым уровнем и сообщением уходят как есть; далее zap держит счётчик и пропускает каждую сотую; в новую секунду всё заново. Практический вывод: если ваш сервис штормит, то есть пишет тысячи одинаковых записей в секунду, вы и так под сэмплером — просто не знали об этом. И обратный вывод: при спокойном трафике сэмплирование не включается вовсе, пока счётчик не дойдёт до сотни за окно; обычные сервисы с десятками записей в секунду живут без прореживания. Отключить сэмплер в конфиге просто — присвойте Sampling nil, но подумайте дважды: ваш сборщик логов скажет спасибо в следующий шторм.

Сэмплирование нужно там, где одна и та же запись воспроизводится в цикле, и таких мест в реальных сервисах несколько. Ретраи исходящих вызовов — хрестоматийный случай из начала урока: каждая попытка логирует провал, и при деградации зависимости частота провалов равна частоте попыток. Фоновые поллеры: очередь пуста, крон тикает раз в секунду, Info «nothing to process» капает круглосуточно. Валидаторы и парсеры в цикле по данным: один кривой файл на миллион строк превращается в миллион записей. Во всех этих случаях после сотни одинаковых записей новой информации нет — есть только стоимость: CPU на кодирование, диск и сеть на доставку, квоты в системе сбора. Сэмплирование режет именно это, сохраняя сигнал: начало шторма видно с первой записи, конец — по последней, а середина представлена десятой долей процента. Заметьте честную оговорку документации: реализация оптимизирована под скорость, а не под точность, — под нагрузкой окно может пропустить чуть больше или меньше расчётного. Для защиты от шторма это неважно, для бухгалтерии по записям — учитывайте.

Теперь неприятная часть, о которой молчат туториалы. Счётчик сэмплера — по уровню и тексту сообщения, и поля в этот ключ не входят. Ошибка «payment failed» с полем order_id равным «a-77» и ошибка «payment failed» с order_id «b-42» — один и тот же счётчик: детали живут в полях, а считается текст. Сценарий провала: за секунду проходит тысяча падений платежей с сотней разных order_id в полях, первые сто записываются, а ваш конкретный заказ c-99 выпадает из логов в числе прореженных — и расследование упирается в дыру. Лечение на уровне конвенций: в сообщении несут то, что отличает запись — «payment failed for order c-99» — и тогда уникальные события получают свой счётчик; либо дублируют критичные события в метрики, где потерь нет. Второй риск — искажение объёма: в логе сто ошибок, кажется, что шторм небольшой, а реально было сорок тысяч; сравните счётчик алертов с числом записей. Третий — арифметика: thereafter 100 при Initial 10 означает, что между сотыми пропускается девяносто из ста, — настраивайте оба числа осознанно.

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

Одна из опций NewSamplerWithOptions закрывает вопрос «а сколько мы резали»: zapcore.SamplerHook принимает функцию, которую сэмплер вызывает на каждое своё решение. Аргументы — запись и битовая маска решения: LogDropped означает, что запись отброшена, LogSampled — что пропущена как пробная. Внутри функции удобно инкрементировать атомарный счётчик и отдавать его в метрики. Это лечит второй риск из предыдущего раздела: разница между «сэмплер пропустил 104» и «шторм был на 40 тысяч» становится видимой в дашборде, а не догадкой по логам. Заведите две метрики — дропнутые и прошедшие — по уровням, и сэмплирование перестанет быть чёрным ящиком: видно, когда оно срабатывает, на каком уровне и насколько агрессивно. Для того же предназначено поле Hook в zap.SamplingConfig — хук из конфига получает те же решения, если вы живёте на пресете, а не на ручной сборке.

Сэмплер — не единственная ручка объёма, и полезно видеть иерархию. Уровень — грубая регулировка: подняли порог до Warn — Info исчез целиком; дешево, но грубо, и динамика уровня — тема отдельного урока про AtomicLevel. Сэмплирование — точечная: уровень сохраняется, прореживается только повторяющееся; это способ жить с Debug-подробностью в Info-штормах. Ротация из урока о lumberjack вообще не про объём: она делит поток на файлы, суммарный объём не уменьшая. Ретраи и очередь в самом коде — правильное место, чтобы не логировать каждую попытку: логируйте первую, последнюю и каждую десятую попытку руками, тогда сэмплеру останется только непредвиденное. Правильная конфигурация прод-сервиса обычно такова: прод-уровень Info, сэмплирование пресетное 100/100, отдельное ядро для ошибок, метрики дропов через хук. Отклоняйтесь от этого по факту нагрузки, а не на всякий случай: лишние ручки — лишние сюрпризы.

Почему прореживание нужно именно zap — то есть откуда берётся его скорость при тысячах записей в секунду, — разбирает урок про производительность: пулы, ноль аллокаций и CheckedEntry. Вторая ручка объёма — уровень, меняющийся без перезапуска, — живёт в уроке про AtomicLevel. Карта курса — на странице курса.