Пакеты для логирования и трассировки Node.js для инцидентов

Почему инциденты кажутся медленными без хороших логов

Большинство инцидентов начинается с простого вопроса: какой именно запрос упал? Если ваши логи — это обычный текст, а каждая строка выглядит чуть по-разному, на один только ответ может уйти первые 10–20 минут.

Размытая запись вроде «таймаут» или «ошибка базы данных» редко помогает сама по себе. Всё равно нужно понять, когда это произошло, какой маршрут вызвал проблему, какой пользователь или аккаунт был затронут и случилось ли всё до или после обращения к другому сервису. Когда этих деталей нет, люди заполняют пробелы догадками.

Именно поэтому пакеты для логирования и трассировки Node.js так важны во время инцидентов. Их задача не в том, чтобы сделать логи красивее. Их задача — превратить стену текста в записи, которые можно фильтровать, группировать и прослеживать.

Проблема становится ещё заметнее, когда логи, трассировки и код не идут по одному следу. Один человек ищет в логах ошибку 500, другой открывает инструмент для трассировки, третий читает код обработчика. Если в каждой системе разные названия или вообще нет request ID, команда не может понять, смотрит ли она вообще на один и тот же сбой.

Небольшие команды чувствуют это сильнее, чем большие. Во время алерта один и тот же человек часто проверяет production-логи, сравнивает деплои и просматривает код на предмет недавних изменений. Каждый пропущенный timestamp или ID добавляет ещё один ручной шаг.

Небольшой набор стандартных полей решает больше, чем многие ожидают. Если каждая строка лога содержит timestamp, уровень, имя сервиса, request ID и trace ID, поиск становится намного быстрее. Вы перестаёте читать строку за строкой и начинаете сужать проблему за секунды.

Представьте платёжный API, у которого на пять минут резко выросла задержка. Без структурированного логирования в Node.js вы можете увидеть поток ошибок и не заметить никакой закономерности. С едиными полями можно выделить один маршрут запроса, увидеть медленный вызов внешнего сервиса и сопоставить его с тем же trace. Разница между этим и хаотичным разбором на 40 минут часто огромна.

Начните с полей, которые будете искать

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

Хорошая базовая схема скучна — и это правильно. Добавляйте уровень лога, timestamp, имя сервиса и среду в каждую запись. Если один сервис пишет prod, а другой production, поиск становится грязным именно тогда, когда дорога каждая минута.

Для запросов добавляйте контекст, который помогает пройти один путь через приложение. Request ID должен быть везде, что связано с HTTP-запросом. Если вам известны маршрут, ID пользователя, ID аккаунта или tenant ID, добавляйте и их. Когда пользователь не вошёл в систему, оставьте поле пустым или не указывайте его, но имя поля должно оставаться одинаковым везде.

Небольшой базовый набор обычно покрывает большую часть отладки инцидентов:

• level, timestamp, service, environment
• requestId, route, userId
• durationMs, statusCode
• errorName, errorMessage, errorStack
• имя внешнего сервиса, метод, статус и задержка

К ошибкам нужен особый подход. Не сваливайте всю ошибку в одну строку. Храните имя ошибки, сообщение и stack в отдельных полях, чтобы можно было искать TimeoutError, не цепляя каждое сообщение о таймауте в trace stack. Это также сильно упрощает построение дашбордов и алертов.

Метрики времени быстро окупаются. Фиксируйте длительность запроса, код ответа и детали по внешним вызовам, например имя провайдера, группу endpoint'ов, число повторов и задержку. Если платёжный API начинает отвечать за 4 секунды вместо 400 миллисекунд, вы заметите это за минуты.

Последовательность важнее совершенства. Если один сервис пишет request_id, а другой — reqId, вы потратите время на исправление запросов прямо во время инцидента. Выберите один стиль именования, запишите его и используйте во всех Node.js-сервисах.

Лучшая схема логов — та, которую команда помнит в 2 часа ночи и которой доверяет с первого поиска.

Как добавить request ID по всему приложению

Request ID превращает шумный инцидент в одну нить, за которой можно идти. Когда один checkout зависает или один API-запрос падает, вам нужен один и тот же ID в edge-логе, логах приложения, отчёте об ошибке и в ответе, который ушёл клиенту. Без этого люди сравнивают timestamp'ы и гадают. Это медленно и обычно ведёт не туда.

Создавайте ID на границе. Если клиент прислал доверенный x-request-id, сохраняйте его. Если нет — сгенерируйте новый в первом middleware и верните его в заголовке ответа. Этот маленький шаг помогает обеим сторонам. Клиент может назвать ID в обращении, а ваша команда — найти точный запрос вместо просмотра большого временного окна.

В Express чистый способ протащить этот ID через асинхронную работу — AsyncLocalStorage. Задайте store один раз, когда запрос начинается. После этого ваш логгер сможет читать текущий ID откуда угодно: внутри вызовов сервисов, логики повторных попыток или кода, который выполняется на несколько уровней глубже. Это важно, потому что инциденты редко остаются только в одном handler'е. Один запрос может затронуть auth, billing, email и очередь, прежде чем закончится.

Добавляйте request ID в каждую строку лога по умолчанию. Делайте так же для обработанных ошибок, необработанных ошибок и ответов, которые могут просматривать support-команды. Если ваш инструмент для алертов собирает дополнительный контекст, добавляйте ID и туда. Одна поисковая строка должна открывать весь путь целиком.

Не останавливайтесь на веб-сервере. Передавайте тот же ID downstream-сервисам в заголовках и добавляйте его в метаданные задач очереди, когда отправляете фоновые работы. Если платёжный провайдер таймаутится, а потом вы повторяете попытку в worker'е, этот worker должен сохранить исходный ID. Иначе история обрывается ровно там, где инцидент становится интереснее.

Support-команда тоже должна использовать этот ID. Когда клиент говорит: «моя оплата крутилась 30 секунд», саппорт может вставить request ID в тикет. Тогда у инженерной команды появляется чистая точка входа. Request ID — это не полноценная система трассировки, но для небольших команд он очень быстро убирает массу хаоса.

Пакеты, которые небольшая команда может быстро подключить

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

Из большинства пакетов для логирования и трассировки Node.js я бы начал с Pino и добавлял только то, что закрывает реальный пробел. Pino пишет JSON-логи, остаётся быстрым под нагрузкой и требует минимальной настройки. Это важно, когда вам нужны согласованные логи уже сейчас, а не после долгого проекта по уборке.

Если ваше приложение работает на Express или Fastify, pino-http — самый быстрый дополнительный модуль. Он логирует каждый запрос, статус-код, задержку и базовые данные запроса с очень небольшим количеством кода. Там же можно добавить request ID, а потом использовать его везде по этому же потоку.

AsyncLocalStorage помогает сохранять контекст запроса доступным без передачи ID через каждый вызов функции. Именно эту часть многие команды пропускают, а потом жалеют об этом во время инцидента. Когда один checkout-запрос таймаутится, вам нужно, чтобы каждая строка лога от этого запроса была сгруппирована под одним и тем же ID.

Практичный стек

Лёгкая настройка обычно выглядит так:

• Pino для логов приложения в JSON
• pino-http для логов запросов в Express или Fastify
• AsyncLocalStorage для request ID и общего контекста
• SDK OpenTelemetry с авто-инструментированием для трассировок

OpenTelemetry даёт спаны для HTTP-вызовов, запросов к базе и других распространённых библиотек. Авто-инструментирование экономит время, потому что полезные трассировки можно увидеть ещё до ручной настройки. Для небольшой команды этого часто достаточно, чтобы понять, что медленный endpoint на самом деле тормозит из-за базы данных или зависания внешнего API.

Winston всё ещё имеет смысл, если вам рано нужны кастомные transport'ы, например отправка логов в несколько мест в разных форматах. Но для нового сервиса я бы не выбирал его по умолчанию. Pino обычно проще держать в чистоте.

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

Настройка, которую можно запустить за один день

Начните с малого. Выберите один логгер, один инструмент для трассировки и одно место, где вы будете смотреть оба инструмента во время алерта. Для многих команд Pino для логов и OpenTelemetry для трассировок уже достаточно, чтобы быстро получить реальные сигналы. С пакетами для логирования и трассировки Node.js главная ловушка — добавить слишком много до первого теста.

Сначала пропишите схему логов, а уже потом трогайте middleware. Один раз решите точные названия полей и используйте их везде: timestamp, level, service, env, request_id, trace_id, route, user_id, job_name, error_name и error_message покрывают большую часть инцидентной работы. Если одна часть приложения пишет requestId, а другая — req_id, поиск станет грязным именно тогда, когда время особенно важно.

Добавьте middleware для request ID на самой первой точке входа. В Express это значит первое middleware, которое видит запрос, до auth, валидации или бизнес-логики. Если доверенный upstream уже прислал ID, сохраните его. Если нет — сгенерируйте новый, привяжите его к запросу и создайте дочерний логгер из этого контекста.

Если вам нужны request IDs в Express без ручной передачи через каждую функцию, используйте AsyncLocalStorage. Он оставляет текущий контекст запроса доступным глубже в стеке вызовов. Это экономит время позже, особенно когда handler вызывает сервис, сервис идёт в базу данных, а затем worker подхватывает последующую задачу.

Инструментируйте то, что обычно ломается первым:

• входящие HTTP-запросы
• исходящие HTTP-вызовы к другим API
• запросы к базе данных
• фоновые задачи и очереди

Этого набора хватает для большинства реальных инцидентов. Таймаут платёжного запроса может начаться в API-роуте, зависнуть на внешнем вызове, повториться в worker'е и оставить только частичные следы, если все четыре зоны не разделяют одни и те же ID.

Отправляйте логи и трассировки в дашборд, который команда и так открывает во время алертов. Простая схема, которую люди реально проверяют, лучше модной, которую игнорируют. Если команда уже живёт в Grafana, Sentry или другом знакомом инструменте, подключите поиск туда и сделайте так, чтобы request ID легко вставлялся в один запрос.

Завершите день одним искусственно созданным сбоем. Запустите запрос, который обращается к другому сервису, трогает базу и пишет ошибку. Затем проверьте, позволяет ли один request_id или trace_id пройти весь путь без догадок. Если да, настройка готова к реальному инциденту.

Реальный инцидент с таймаутом платежа

В 10:12 ошибки checkout резко растут сразу после деплоя. Support видит сообщение «платёж не прошёл», но в логах приложения только куча ошибок 500. Без структурированного логирования в Node.js команда бы читала обычный текст и гадала, сломалось ли приложение, база данных или платёжный провайдер.

На этот раз у каждого запроса есть request ID в Express. Инженер берёт один неудачный checkout и идёт по одному и тому же req_id через API, order service и логи базы данных. Этот один ID связывает действие пользователя, запись заказа и один вызов базы, который вдруг занимает 4,8 секунды вместо обычных 30–40 миллисекунд.

Трассировка добавляет недостающую часть. В OpenTelemetry для Node.js видно два медленных спана подряд. Сначала приложение ждёт этот запрос к базе данных. Потом оно вызывает внешний платёжный API, а тот отвечает ещё через 8 секунд. Таймаут checkout установлен на 10 секунд, поэтому запрос не успевает завершить платёжный поток.

Обычные логи сделали бы это похожим на падение платёжного сервиса. Структурированные поля делают картину очевидной. Все проблемные записи имеют одинаковые значения route=/checkout, status=timeout и region=eu-west. Запросы из us-east и ap-south продолжают проходить.

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

Исправление получается маленьким, потому что доказательства понятны. Команда откатывает только это одно изменение, а не весь релиз и не обвиняет платёжного провайдера. Checkout быстро восстанавливается, а остальной деплой остаётся на месте.

Вот почему пакеты для логирования и трассировки Node.js так помогают при отладке инцидентов. Request ID связывают историю воедино. Трассировки показывают, куда ушло время. Структурированные логи показывают, какие запросы падают одинаково. Этого часто достаточно, чтобы заменить 45 минут догадок одним откатом и одним последующим исправлением.

Ошибки, которые отнимают время во время алертов

Самые вредные ошибки в логировании кажутся мелочами в моменте. В 2 часа ночи они превращают исправление за 10 минут в час догадок.

Одна распространённая проблема — слишком много логов. Команды выгружают целые request body в логи, потому что это кажется безопасным: «потом пригодится». Потом прилетает алерт, а в логах — пароли, токены, данные карт или личная информация, которую вообще нельзя там хранить. И всё равно нужного ответа нет. Несколько чистых полей лучше, чем огромный комок текста, каждый раз.

Ещё одна ошибка — называть одну и ту же сущность по-разному в разных сервисах. Одно приложение пишет requestId, другое — req_id, а worker использует trace. Теперь поиск ломается на каждом переходе. Структурированное логирование в Node.js помогает только тогда, когда поля остаются одинаковыми.

Как выглядит отсутствие контекста

Многие команды пишут ошибки так: «database failed» или «payment timeout». Эти слова почти ничего не говорят. Во время отладки инцидентов вам нужны маршрут, код ошибки, stack, имя сервиса и request ID в одном событии. Без этого два разных сбоя могут выглядеть одинаково.

У трассировки есть своя ловушка. Команды настолько снижают sampling, что медленный или сломанный путь вообще не появляется в трассировках. Они экономят немного денег и теряют именно тот trace, который был нужен. Для ошибок и медленных запросов лучше держать более широкий sampling, даже если обычный трафик вы снимаете реже.

Разделение access logs и app logs тоже отнимает время. Если nginx, Express и background worker логируют отдельно и без общего ID, вы не сможете пройти один запрос от границы до базы данных. В итоге приходится сравнивать timestamp'ы на глаз, а это мучительно и часто неверно.

Небольшая команда может избежать большей части этого с коротким набором правил:

• Никогда не логируйте полные тела запросов, если сначала не замаскировали чувствительные поля.
• Выберите одно имя поля для каждой сущности и используйте его везде.
• Для каждой реальной ошибки логируйте stack, код, маршрут и request ID.
• Держите трассировки ошибок на более высокой частоте sampling, чем обычный трафик.
• Сделайте так, чтобы access logs и app logs использовали один и тот же request ID.

Если запрос checkout падает три раза за пять минут, вы должны проследить один запрос end to end за секунды. Если это невозможно, настройку логирования пора дорабатывать.

Быстрые проверки перед следующим алертом

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

Если на это уходит больше минуты-двух, проблема обычно не в количестве логов. Проблема в отсутствии структуры, ID или контекста на самой ошибке.

Проведите короткую проверку с вашими текущими пакетами для логирования и трассировки Node.js:

• Возьмите неудачный запрос из приложения и найдите его по request ID.
• Проследите тот же запрос через HTTP-handler, вызов базы данных и любую очередь или background job.
• Откройте запись ошибки и проверьте, есть ли stack trace, HTTP status, маршрут и общая длительность в миллисекундах.
• Просмотрите несколько строк логов на наличие секретов и убедитесь, что токены, пароли и данные карт замаскированы.
• Попросите коллегу, который не работал над этой задачей, прочитать след и объяснить, что произошло.

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

Хороший error log должен читаться как короткая хронология. Вам нужны маршрут, request ID, ID пользователя или tenant ID, если он есть, код статуса, длительность и сам stack ошибки. Без длительности таймауты выглядят случайными. Без маршрута несвязанные ошибки смешиваются. Без stack'а все сбои начинают выглядеть одинаково.

Трассировка особенно важна, когда один запрос прыгает через границы. Checkout может попасть в API, ждать PostgreSQL и ставить retry job в очередь. Если trace обрывается на границе очереди, во время алерта вы всё равно будете гадать. OpenTelemetry для Node.js может помочь, но только если request ID или trace ID остаётся видимым и в логах тоже.

Redaction нужно проверять по-настоящему, а не галочкой. Запустите фиктивный login failure с dummy token и убедитесь, что сырой секрет не попадает ни в stdout, ни в хранилище логов, ни в атрибуты trace. Один утекший токен во время инцидента создаёт второй инцидент.

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

Что делать дальше для лёгкого запуска

Выберите один сервис и пока оставьте остальное в покое. Если checkout или login будит людей ночью, начните с него. Добавьте структурированное логирование в Node.js, request ID на каждый входящий запрос и трассировки для медленного пути, который обычно и создаёт боль.

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

• Каждый запрос получает один request_id на границе и сохраняет его во время async-работы.
• В каждой строке лога есть service, route, environment и duration, когда это уместно.
• Ошибки каждый раз пишут одни и те же поля, плюс error name и stack.
• Трассировки сохраняют упавшие и медленные запросы, а не вообще всё.
• В логи никогда не попадают пароли, токены или полные данные карт.

Этого достаточно для первого шага. Вам не нужно покрывать всё: каждый worker, queue и cron job — уже в первый день.

После запуска используйте следующий реальный инцидент как тест. Возьмите логи и трассировки по этому request ID, а потом задайте два прямых вопроса: что помогло и что отняло время? Уберите шумные поля, снизьте уровень слишком разговорчивых логов и добавьте одно недостающее поле, если команде пришлось гадать.

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

Если вам нужна помощь с выбором компактной настройки, консультирование Fractional CTO от Oleg Sotnikov поможет сопоставить стек с вашей командой и не сделать его слишком громоздким. Хороший первый шаг простой: один сервис, один путь запроса, один алерт, который обработали быстрее, чем в прошлый раз.