![\"Дерево](\"/assets/editorial/2020/structured-log-diagnosis-2020.svg\")
Авария начинается с простого поиска. Пользователь сообщает, что заказ не оформился. В журнале есть ошибка, но её нельзя связать с конкретным запросом: одно сообщение содержит длинный URL, другое — весь объект запроса, третье — текст исключения с номером заказа. Иногда рядом оказывается заголовок, похожий на токен. Диагностика останавливается. Инженер читает тысячи строк вручную, а затем ещё проверяет, не утёк ли секрет.
\nЦена ошибки складывается из трёх частей. Команда дольше восстанавливает цепочку событий. Система хранения получает лишний объём и множество уникальных значений. Доступ к журналу открывает данные, которые не требовались для ответа на диагностический вопрос. Строка с красивым текстом не решает ни одну из этих проблем сама по себе.
\nТезис: структурированный лог — это небольшой контракт события. В нём есть устойчивое имя события, владелец операции, идентификатор связи и ограниченный набор нормализованных полей. Контракт нужно сформировать до сериализации. Тогда поиск использует поля, redaction видит структуру объекта, а каждое добавленное значение можно объяснить.
\nСначала назовём вопрос. Например: «какой запрос привёл к отказу адаптера?» Для него нужны request_id, имя события, сервис, маршрут-шаблон, код результата и нормализованный код причины. Полное тело запроса не нужно. Текст исключения тоже не нужен, если в нём нет устойчивого кода, который можно проверить.
request_id связывает записи одного входного действия. Он подходит для поиска одной истории. Он не доказывает причинность и не заменяет трассировку: два сервиса могут записать события с разной задержкой, а фоновой задаче может потребоваться новый operation_id. Это ограничение важно назвать до внедрения, иначе один идентификатор начнут использовать как универсальную модель системы.
У остальных полей другой режим. event описывает тип события и должен иметь небольшой словарь. route содержит шаблон, а не конкретный путь с идентификатором заказа. service обозначает владельца границы, а не имя pod или локальный путь. error_code называет известную причину из ограниченного набора. Эти поля подходят для фильтра и группы.
| Поле | Роль | Допустимое значение | Чего не делать |
|---|---|---|---|
request_id | найти одну историю | стабильный идентификатор запроса | использовать как метрику-группу |
event | назвать тип события | adapter.response.rejected | вставлять номер заказа или текст ошибки |
route | сравнить обработчики | /orders/:orderId | писать полный URL и query string |
error_code | разделить причины | SCHEMA_MISMATCH | сохранять произвольное сообщение исключения |
authorization | не нужна для поиска события | не записывать или заменить на [REDACTED] | передавать сырой объект headers |
Поздняя маскировка ломается на границе строк. Если сначала выполнить JSON.stringify(request), а потом искать секрет регулярным выражением, правило зависит от вложенности, регистра ключа и формата значения. Неожиданный объект легко попадёт в stdout целиком. Маска должна получить объект, пройти известные ключи и только затем передать безопасную копию сериализатору.
const sensitiveKeys = new Set(['authorization', 'cookie', 'password', 'token', 'secret']);\n\nfunction redact(value, key = '') {\n if (sensitiveKeys.has(key.toLowerCase())) return '[REDACTED]';\n if (Array.isArray(value)) return value.map((item) => redact(item));\n if (value && typeof value === 'object') {\n return Object.fromEntries(\n Object.entries(value).map(([name, item]) => [name, redact(item, name)]),\n );\n }\n return value;\n}\n\nconst trainingContext = {\n request_id: 'req-demo-01',\n event: 'http.request.completed',\n headers: { authorization: 'synthetic-placeholder' },\n http: { route: '/orders/:orderId', status_code: 202 },\n};\n\nconsole.log(JSON.stringify(redact(trainingContext)));\n// Учебный пример: placeholder не является реальным секретом.В результате учебного вызова значение headers.authorization должно стать [REDACTED]. Проверять нужно именно строку, которая уйдёт в поток вывода. Проверка внутреннего объекта недостаточна: код может безопасно изменить копию, а затем случайно залогировать исходную. Также нельзя считать список ключей полной защитой. Интеграция может назвать поле credential, вложить секрет в строку или передать его под другим именем.
Надёжнее не передавать логгеру сырой запрос. Контроллер выбирает метод, шаблон маршрута и код ответа. Адаптер выбирает своё имя и нормализованный код ошибки. Redaction остаётся второй границей, а не разрешением писать любой JSON. Если поле не нужно для конкретного вопроса, его удаляют, а не маскируют «на всякий случай».
\nКардинальность — это число разных значений поля. Для event она должна быть низкой. Иначе вместо одного фильтра adapter.response.rejected появятся сотни имён: order.7421.failed, order.7422.failed и так далее. Журнал сохранит все строки, но перестанет давать устойчивую группу. Полный URL, свободный текст исключения и имя пользователя создают ту же проблему.
Высокая кардинальность иногда нужна. У request_id она намеренно высокая, потому что поле находит одну историю. Ошибка возникает, когда его начинают использовать для агрегирования или строят по нему долговременный отчёт. Для группы нужны устойчивые поля. Для единичного расследования нужен идентификатор с ограниченным сроком и понятной областью действия.
Ниже приведён синтетический JSONL-пример. Он показывает форму данных, а не результат реального инцидента. Один request_id связывает вход, отказ адаптера и ответ gateway. Внешняя причина сведена к коду. Номер заказа и тело запроса отсутствуют.
{\"timestamp\":\"2020-07-14T09:30:11.001Z\",\"level\":\"info\",\"service\":\"demo-gateway\",\"environment\":\"training\",\"event\":\"http.request.received\",\"request_id\":\"req-demo-01\",\"http\":{\"route\":\"/orders/:orderId\"}}\n{\"timestamp\":\"2020-07-14T09:30:11.024Z\",\"level\":\"warn\",\"service\":\"demo-catalog-api\",\"environment\":\"training\",\"event\":\"adapter.response.rejected\",\"request_id\":\"req-demo-01\",\"adapter\":{\"name\":\"training-inventory\",\"error_code\":\"SCHEMA_MISMATCH\"}}\n{\"timestamp\":\"2020-07-14T09:30:11.042Z\",\"level\":\"info\",\"service\":\"demo-gateway\",\"environment\":\"training\",\"event\":\"http.request.completed\",\"request_id\":\"req-demo-01\",\"http\":{\"status_code\":502}}\n\njq -c 'select(.request_id == \"req-demo-01\")' training.jsonl\n# Учебный запрос: он не доказывает поведение production.По этой цепочке можно проверить только форму расследования: найти три записи, увидеть известный код и отделить владельца отказа от gateway. Нельзя делать вывод о частоте 502, времени восстановления или работе реального адаптера. Для таких выводов нужны данные конкретной среды и отдельные измерения. Учебный пример полезен тем, что фиксирует минимальный контракт без ложной статистики.
\n| Симптом | Причина | Проверка | Действие |
|---|---|---|---|
| Ошибка найдена, но запрос не находится | request_id теряется на HTTP-границе | сравнить записи клиента и сервиса по одному учебному идентификатору | передавать контекст явно через исходящий клиент |
| В событии виден токен или cookie | сырой объект сериализовали раньше redaction | проверить финальную stdout-строку на запрещённые значения | выбирать поля вручную и маскировать до сериализации |
| Каждая ошибка создаёт новый event | динамическое имя содержит id или свободный текст | посчитать варианты event на учебной выборке | оставить устойчивое имя и добавить ограниченный error_code |
| Группа по сервису постоянно меняется | в service попали pod, путь или версия процесса | сравнить значение с владельцем логической границы | отделить service от instance и deployment-метаданных |
| Лог красивый, но JSON не разбирается | строка собрана вручную или содержит неэкранированный ввод | прогнать каждую строку через JSON.parse | сериализовать объект штатным JSON-генератором и санитизировать ввод |
request_id и описать поведение для отсутствующего или невалидного значения.Структурированный лог не создаёт трассировку. Он не показывает дочерние spans, не исправляет рассинхрон часов и не объясняет фоновые задачи, если для них не определён отдельный идентификатор. Для распределённого критического пути понадобится трассировочный контракт.
\nRedaction защищает только известные формы. Он не распознаёт любой секрет и не заменяет классификацию данных, права доступа, срок хранения и контроль конфигурации. Высокая кардинальность не всегда вредна: уникальный идентификатор полезен для одной истории, но опасен как поле длительной агрегации. Правило зависит от назначения поля.
\nКритерий готовности проверяемый: каждая учебная строка проходит JSON.parse; три связанные записи находятся по одному request_id; event, service и route не содержат динамических идентификаторов; запрещённые ключи не выходят в исходном виде; отрицательный путь сохраняет нормализованный error_code. Если хотя бы одно условие не выполняется, контракт ещё не готов.
Проблема заметна поздно: нужное событие найдено, но рядом лежит целый объект запроса, длинный URL и строка, похожая на credential. Другой поиск не работает, потому что имя события каждый раз включает номер заказа или текст внешней ошибки. Цена — не только неудобная диагностика. Журнал становится местом, куда утекают лишние данные, а одинаковые случаи невозможно посчитать или сравнить без ручной очистки.
\nЛечить это после первого серьёзного сбоя дорого: код уже привык писать «всё, что есть под рукой», а доступ к журналу обычно шире доступа к исходному запросу. Поэтому правила redaction и кардинальности нужны в точке формирования события. В этой статье нет настоящих инцидентов, секретов или production-логов: только синтетическая запись и локальный fixture. Задача — научиться отличать поле, нужное для ответа, от поля, которое журналу не принадлежит.
\nПервый класс — безопасный операционный контекст. Это время, уровень, сервис, имя события, шаблон маршрута, код ответа и request_id. Они помогают связать одну историю и не требуют выгружать тело запроса. Второй класс — ограниченный контекст: технический код внешней ошибки, нормализованное состояние, короткое имя адаптера. Его добавляют, если есть точный вопрос диагностики и форма значения известна. Третий класс — запрещённый или redacted: учётные данные, cookies, заголовок authorization, пароль, полный body и произвольный объект пользователя.
\nРазделение не означает, что второй класс всегда безопасен. Даже поле error.message может включить в себя входные данные внешней системы. Поэтому практический контракт предпочитает error.code и собственное имя события, а текст оставляет коротким и контролируемым. Если подробность действительно нужна, её нельзя добавлять в общий JSON по умолчанию: сначала определяется доступ, срок хранения и отдельный путь проверки. В этой минимальной схеме подробность отсутствует, а не прячется в красивом имени поля.
| Класс | Примеры | Зачем они нужны | Действие перед записью |
|---|---|---|---|
| Базовый | timestamp, service, event, request_id | связать и прочитать один запрос | писать в устойчивом формате |
| Ограниченный | adapter.name, error.code, http.status_code | отделить известную ветвь отказа | добавлять только владельцем операции |
| Redact | authorization, cookie, password, token | не нужны для поиска события | заменить до JSON или не передавать объект |
| Не логировать | body, полный URL, целый объект пользователя | случайная форма и лишние данные | заменить на шаблон маршрута или нормализованный код |
Ошибка redaction часто начинается с позднего шага: код уже сделал JSON.stringify(req), затем регулярное выражение пытается вычеркнуть секрет из текста. Вложенный ключ, другой регистр или неожиданная форма легко проходят мимо такой маски. Надёжнее принять маленький объект контекста, пройти его по известным ключам и только потом сериализовать. Документация Pino описывает redaction путями полей; это тот же принцип: правило должно знать структуру, а не угадывать фрагмент строки.
const sensitiveKeys = new Set(['authorization', 'cookie', 'password', 'token', 'secret']);\n\nfunction redact(value, key = '') {\n if (sensitiveKeys.has(key.toLowerCase())) return '[REDACTED]';\n if (Array.isArray(value)) return value.map((item) => redact(item));\n if (value && typeof value === 'object') {\n return Object.fromEntries(Object.entries(value).map(([name, item]) => [name, redact(item, name)]));\n }\n return value;\n}\n\nconst trainingContext = {\n request_id: 'req-demo-20200714-01',\n event: 'http.request.completed',\n headers: { authorization: 'synthetic-placeholder-not-a-secret' },\n http: { route: '/training/orders/:orderId', status_code: 202 }\n};\nprocess.stdout.write(JSON.stringify(redact(trainingContext)) + "\\n");\n// authorization is emitted as [REDACTED]; no real credential is present in this fixture.Этот пример не обещает поймать каждый секрет во всех структурах. Он фиксирует минимум: известные чувствительные ключи не должны дойти до stdout в исходном виде. В реальном проекте список расширяется по фактическим форматам интеграций, а тесты добавляют каждый уже известный путь. Если библиотека поддерживает redaction конфигурацией, правило всё равно следует проверять на том JSON, который действительно выходит из процесса. Название опции — не доказательство результата.
\nЕсть и более простая защита: не давать логгеру сырой объект. Контроллер сам выбирает method, route и status_code; адаптер сам выбирает adapter.name и error.code. Тогда redaction остаётся страховочной сеткой, а не единственным барьером. Чем меньше произвольных объектов пересекает границу логирования, тем легче редактору и ревьюеру увидеть, откуда появилось поле.
Кардинальность показывает, сколько разных значений может иметь поле. У event она должна быть низкой: десятки устойчивых имён, а не одна новая строка на исключение. У route тоже низкая: шаблон /training/orders/:orderId, а не конкретный путь. У request_id она намеренно высокая, потому что его задача — найти одну историю. Ошибка начинается, когда все эти поля используют одинаково — например, группируют по request_id или добавляют номер заказа в имя события.
Не надо превращать эту заметку в рассказ о зрелой платформе метрик. Здесь достаточно заранее записать, какие поля допускаются как фильтр одного случая, а какие могут быть группой для короткого локального отчёта. Даже если команда пока читает JSONL через jq, это решение уже меняет качество диагностики: следующий разработчик не создаст сто вариантов события ради удобства одного сообщения.
| Поле | Ожидаемая кардинальность | Разрешённое использование | Антипаттерн |
|---|---|---|---|
event | низкая | фильтр и небольшая группа | order.7421.failed |
service | низкая | граница владельца | имя с номером pod или локальным путём |
route | низкая | сравнить обработчики | полный URL с id и query string |
request_id | высокая | найти одну историю | использовать как измерение агрегата |
error.code | ограниченная | разделить известные причины | писать произвольный текст исключения |
Все идентификаторы, маршруты и значения в примерах ниже учебные и синтетические. Это не журнал реального пользователя и не отчёт о production-инциденте.
\n{"timestamp":"2020-07-14T09:30:11.001Z","level":"info","service":"demo-gateway","environment":"training","event":"http.request.received","request_id":"req-demo-20200714-01","message":"Synthetic request accepted","http":{"route":"/training/orders/:orderId"}}\n{"timestamp":"2020-07-14T09:30:11.024Z","level":"warn","service":"demo-catalog-api","environment":"training","event":"adapter.response.rejected","request_id":"req-demo-20200714-01","message":"Synthetic adapter response rejected","adapter":{"name":"training-inventory","error_code":"TRAINING_SCHEMA_MISMATCH"}}\n{"timestamp":"2020-07-14T09:30:11.042Z","level":"info","service":"demo-gateway","environment":"training","event":"http.request.completed","request_id":"req-demo-20200714-01","message":"Synthetic request completed","http":{"status_code":502}}\n\n# Учебная проверка: поле request_id связывает записи; error_code называет нормализованную причину.\njq -c 'select(.request_id == "req-demo-20200714-01")' training.jsonlДиагноз здесь не «адаптер плохой». Проверяемая цепочка короче: gateway принял учебный запрос, API записал нормализованный TRAINING_SCHEMA_MISMATCH, gateway завершил его 502. Если нужен следующий шаг, он относится к контракту учебного адаптера, а не к поиску несуществующего токена в журнале. Если в ответе появляется полное тело внешней системы, это новый дефект контракта логирования, а не удобный контекст.
Маска полезна только там, где объект окончательно превращается в JSON. Поэтому fixture должен проверять не внутренний JavaScript-объект, а результат сериализации: в нём есть обязательные безопасные поля, а вместо учебного placeholder в headers.authorization стоит ровно [REDACTED]. Такая проверка ловит порядок операций. Если разработчик случайно записал исходный контекст раньше, чем вызвал redaction, тест видит запрещённое значение в строке и не даёт считать код защищённым только по названию функции.
У redaction есть предел. Он не исправит поле, которое автор назвал access вместо token, и не решит, что делать с вложенной строкой, куда внешний сервис уже склеил данные. Поэтому список ключей — не замена ревью. Ревью задаёт два вопроса: откуда взялось значение и можно ли ответить на диагностический вопрос без него? Если второй ответ «да», поле удаляется. Если «нет», для него фиксируется нормализованная форма, путь redaction и учебный пример, который проверяет именно этот путь.
Практический порядок важнее количества масок. Сначала не передавать объект запроса. Затем выбрать короткий контекст. Затем заменить известные чувствительные узлы. Наконец, проверить сериализованный результат. При таком порядке новая интеграция не получает неявное право приносить любой JSON. Она должна добавить поле к контракту и объяснить его цену, иначе требование «сохранить для отладки» станет бесконечным исключением.
\nВысокая кардинальность редко выглядит угрозой в одном примере. Один номер заказа, одна строка внешней ошибки и один полный URL кажутся безобидными. Проблема появляется, когда они становятся формой поля: через неделю журнал содержит множество вариантов, где одинаковое событие нельзя отличить от нового. Поэтому правило проверяют не количеством строк, а источником значения. Если оно рождается из идентификатора, текста пользователя, query string или свободного исключения, ему не место в event, route или имени сервиса.
Нормализация не обязана скрывать причину. Вместо текста можно выбрать error.code из маленького списка, вместо полного URL — route template, вместо динамического события — пару «устойчивое имя события + локальный технический код». Тогда человек всё ещё видит, куда идти: adapter.response.rejected и TRAINING_SCHEMA_MISMATCH ведут к адаптеру и его контракту. Но поиск не создаёт отдельную категорию на каждый учебный заказ или случайную фразу.
Такой разбор связывает безопасность и диагностику без громких обещаний. В журнале остаётся ровно столько контекста, чтобы объяснить одну известную ветвь, а не восстановить целое production-событие. Следующее улучшение может потребовать отдельного формата ошибок, доступа к хранилищу или модели трассировки. Но до него полезно закрепить базовую дисциплину: событие имеет ограниченный словарь, один request_id ищется отдельно, а чувствительное значение не должно быть принято в журнал даже «временно».
\n