Логирование и трассировка: как найти причину сбоя за минуты, а не за часы

Седьмая статья серии «Архитектура и производительность» продолжает разговор о наблюдении за системой. В предыдущей — Метрики и мониторинг — мы разобрались, как узнать, что сломалось: доля ошибок 5xx выросла, время ответа p95 уползло вверх, очередь растёт. Но метрика — это число, а число не объясняет причину: оно говорит «плохо» и молчит о том, почему.

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

Типичная сцена. Магазин на шести сервисах. В 19:40 кнопка «Оформить» начинает «крутиться», метрики показывают рост доли ошибок с 0,2% до 9%. Вы идёте в логи первого сервиса — там таймаут, во втором пусто, в третьем запросов нет вовсе. Через два часа выясняется, что виноват четвёртый: он попал в медленный запрос к базе, а весь поиск шёл глазами по времени, потому что ни одна запись не была связана с другой. Трассировка и правильный лог разбирают эту историю за пять минут.

Разберём по-простому: чем плохой лог отличается от хорошего, что такое структурированное логирование, чем ELK отличается от Loki, как работает распределённая трассировка через Jaeger и OpenTelemetry, что такое propagation request-ID (передача сквозного номера запроса) и — обязательно — что в лог писать нельзя. В конце покажем план внедрения в уже работающее приложение.

Часть I. Зачем нужны логи и почему обычный лог-файл не спасает

1. Лог — это журнал, а не отладочный принт

Логи пишут для трёх разных задач, и путать их нельзя:

• разбор инцидента — что произошло и почему; нужны детали конкретного запроса;
• аудит — кто и когда трогал чужие данные (вход, изменение цены, выгрузка клиентов); здесь важнее не детали, а полнота и неизменность записи;
• поведенческий анализ — где пользователи спотыкаются; тут логи сырьё для счёта, а не для чтения.

Один правильно устроенный поток закрывает все три. «Отладочные» print и var_dump, оставленные в коде, не закрывают ни одной: у них нет ни единого формата времени, ни уровня, ни связи с запросом.

Отдельно про WordPress: там всё сваливается в один файл wp-content/debug.log, если включена константа WP_DEBUG_LOG. Для разработки это нормально, для продакшена почти непригодно: записи идут свободным текстом и PHP-предупреждениями от чужих плагинов. Разумная схема — выключить WP_DEBUG_LOG на проде и писать свои события структурированно через готовый логгер (например, Monolog), оставив системный журнал только для фатальных ошибок.

2. Уровни логирования: от debug до error

Уровень (log level) — это оценка важности записи по стандартной шкале. Держаться её стоит не ради красоты: уровень — главный регулятор объёма.

Три правила: в проде по умолчанию info и выше (постоянный debug — гигабайты в день и забитый диск, то есть собственноручная авария вместо наблюдения); warning — не место для «мне лень писать error» (справились сами — warning, задача не выполнена — error; иначе оповещения по error из статьи про метрики начинают шуметь); шкала одинакова во всех сервисах (если у одного warning ставится для штатной работы, а у другого только для настоящих предупреждений, сравнивать сервисы невозможно).

3. Где текстовый лог ломается

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

А) Нельзя найти один запрос. Шесть сервисов, у каждого свой файл, время чуть различается: вы ищете «19:40:12, ошибка оплаты», а в первом сервисе это 19:40:12, во втором 19:40:12,4, в третьем часы идут со своим смещением.

Б) Нельзя посчитать. «Сколько раз за сутки при оплате вышла ошибка?» по тексту означает переписать миллионы строк и сравнивать руками формулировки, которые код генерирует по-разному.

В) Нельзя связать. Запись «DB connection failed» не говорит, к какому заказу и запросу она относится. Без связей в распределённой системе лог бесполезен.

Ответ — сделать запись не строкой, а набором полей. Это и есть структурированное логирование.

Часть II. Структурированное логирование: JSON вместо текста

4. Одна строка — один объект

Структурированное логирование (structured logging) — это когда каждая запись является объектом с именованными полями, а не предложением на естественном языке. Технически это одна строка JSON: формат называют JSON Lines, или NDJSON — по документу на строку, файл читается потоково, никакого разбора целого текста.

{
  "ts": "2026-10-14T19:40:12.431+03:00",
  "level": "error",
  "service": "payment-service",
  "env": "prod",
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "span_id": "00f067aa0ba902b7",
  "request_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "route": "POST /api/v1/orders",
  "user_id": 98123,
  "status": 502,
  "duration_ms": 3004,
  "event": "payment.charge_failed",
  "message": "gateway timeout while charging order",
  "context": {
    "order_id": 4711,
    "amount": 2490,
    "currency": "RUB",
    "gateway_code": "UPSTREAM_TIMEOUT",
    "attempt": 2
  }
}

{
  "ts": "2026-10-14T19:40:12.431+03:00",
  "level": "error",
  "service": "payment-service",
  "env": "prod",
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "span_id": "00f067aa0ba902b7",
  "request_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "route": "POST /api/v1/orders",
  "user_id": 98123,
  "status": 502,
  "duration_ms": 3004,
  "event": "payment.charge_failed",
  "message": "gateway timeout while charging order",
  "context": {
    "order_id": 4711,
    "amount": 2490,
    "currency": "RUB",
    "gateway_code": "UPSTREAM_TIMEOUT",
    "attempt": 2
  }
}

Что здесь важного глазами пользователя лога:

• ts — время в едином формате с таймзоной; без даты логи за сутки сливаются в кашу.
• level, service, env — важность и адресат; первое, что вы фильтруете.
• trace_id / span_id — сквозной номер запроса и номер шага внутри него (Часть IV и Часть V).
• route, status, duration_ms — машинно-читаемое описание запроса. Перцентили времени считаются прямо из этих полей, то есть часть работы метрик делается бесплатно.
• event — машинный код события в стиле «область.сущность.действие». Надёжнее текста: формулировка сообщения меняется при рефакторинге, а код события — контракт, по которому ищут и на который строят оповещение.
• message — человекочитаемое объяснение одним предложением. Оно для вас глазами, всё остальное — для поиска.
• context — детали ситуации; свободная часть, но только после маскирования секретов (Часть VI).

5. Минимальный обязательный набор полей

Не нужно выдумывать двадцать полей. Договоритесь о шести обязательных и пишите их в каждой записи:

Полезные дополнения: для HTTP-обработчиков — route, method, status, duration_ms, user_id; для фоновых задач — queue и job_id (как устроены очереди — в Очереди сообщений); для обращений к базе — sql_digest и rows (про медленные запросы — в Оптимизация баз данных).

Чего в записях быть не должно: password, token, authorization, номеров карт, полных адресов и паспортов. Это обязательное правило, разбор в Части VI.

6. Как это выглядит в коде на PHP

Monolog — фактический стандарт в PHP-мире; нужен JSON-форматировщик, то есть обработчик (handler), который пишет объект в строку:

<?php
// logging.php — общий логгер для всех сервисов
use Monolog\Logger;
use Monolog\Handler\StreamHandler;
use Monolog\Formatter\JsonFormatter;

function makeLogger(string $service): Logger
{
    $log = new Logger($service);

    // php://stdout — чтобы записи подхватывал Docker или системный лог
    $handler = new StreamHandler('php://stdout', Logger::INFO);
    $handler->setFormatter(new JsonFormatter());
    $log->pushHandler($handler);

    // Общие поля для всех записей этого процесса
    $log->pushProcessor(function ($record) use ($service) {
        $record->extra['service'] = $service;
        $record->extra['env']     = getenv('APP_ENV') ?: 'prod';
        return $record;
    });

    return $log;
}

$log = makeLogger('payment-service');

$log->error('gateway timeout while charging order', [
    'event'       => 'payment.charge_failed',
    'request_id'  => current_request_id(),   // достаем из заголовка, см. Часть V
    'route'       => 'POST /api/v1/orders',
    'status'      => 502,
    'duration_ms' => 3004,
    'context'     => ['order_id' => 4711, 'attempt' => 2],
]);

<?php
// logging.php — общий логгер для всех сервисов
use Monolog\Logger;
use Monolog\Handler\StreamHandler;
use Monolog\Formatter\JsonFormatter;

function makeLogger(string $service): Logger
{
    $log = new Logger($service);

    // php://stdout — чтобы записи подхватывал Docker или системный лог
    $handler = new StreamHandler('php://stdout', Logger::INFO);
    $handler->setFormatter(new JsonFormatter());
    $log->pushHandler($handler);

    // Общие поля для всех записей этого процесса
    $log->pushProcessor(function ($record) use ($service) {
        $record->extra['service'] = $service;
        $record->extra['env']     = getenv('APP_ENV') ?: 'prod';
        return $record;
    });

    return $log;
}

$log = makeLogger('payment-service');

$log->error('gateway timeout while charging order', [
    'event'       => 'payment.charge_failed',
    'request_id'  => current_request_id(),   // достаем из заголовка, см. Часть V
    'route'       => 'POST /api/v1/orders',
    'status'      => 502,
    'duration_ms' => 3004,
    'context'     => ['order_id' => 4711, 'attempt' => 2],
]);

И важное: не логируйте каждый успешный запрос. Поток «запрос принят, 200 OK, 42 мс» имеет смысл, но обычно его пишет веб-сервер (Nginx), и хранят его коротко. Ценность приложения — в событиях: оплаты, списания, ошибки внешних вызовов, смены состояния заказа.

Часть III. Куда складывать логи: ELK против Loki и Promtail

7. Связка ELK: три инструмента в одной цепочке

ELK — сокращение от Elasticsearch, Logstash, Kibana.

приложение (JSON-строки)
   -> Logstash        собирает, разбирает, обогащает, фильтрует
   -> Elasticsearch   хранит и индексирует КАЖДОЕ слово каждой записи
   -> Kibana          интерфейс поиска и графиков

• Elasticsearch — поисковый движок, строящий индекс по всем полям и по всему тексту. Позволяет за доли секунды искать «все записи, где встречается UPSTREAM_TIMEOUT, а сервис не payment-service».
• Logstash — конвейер обработки: читает вход, разбирает, подставляет геолокацию по IP, отбрасывает мусор, отправляет в Elasticsearch. В лёгких случаях его заменяют простые сборщики вроде Filebeat.
• Kibana — веб-интерфейс: поиск, сохранённые фильтры, графики, дашборды.

Сильная сторона ELK — полнотекстовый поиск: если вы не знаете ни времени, ни сервиса, ни поля, а помните только слово, Elasticsearch его найдёт. Слабая — цена. Индексация каждого слова требует памяти и диска, обычно в несколько раз больше, чем сами логи. На одном VPS это самый частый способ «съесть» сервер.

8. Loki и Promtail: индексировать только метки

Grafana Loki устроен сознательно иначе: в логах нужно искать не по всем словам, а по небольшому числу меток, а дальше читать и фильтровать голый текст. Отсюда лозунг «индексируем метки, а не содержимое».

приложение (JSON-строки)
   -> Promtail  читает файлы/stdout, вытаскивает метки (service, env, level)
   -> Loki      хранит сжатые чанки текста + указатель на метки
   -> Grafana   тот же экран, что и для метрик из прошлой статьи

• Promtail — маленький агент-сборщик: читает логи (файлы, stdout контейнеров), разбирает JSON-строки, назначает метки, отправляет в Loki.
• Loki — хранилище. Дешёвое: текстовые чанки просто сжимаются, индекс крошечный.
• Grafana — интерфейс. Огромный практический плюс: метрики из Prometheus и логи из Loki живут в одном окне, и с графика «всплеск ошибок» вы одним кликом переходите к записям того же времени и того же сервиса.

Запрос в Loki — это фильтрация меток плюс текстовая проверка:

{service="payment-service", env="prod"} |= "UPSTREAM_TIMEOUT" | json | duration_ms > 1000

Читается так: «возьми записи сервиса payment-service из прода, оставь те, где в тексте встречается UPSTREAM_TIMEOUT, разбери строку как JSON и отфильтруй по числу дольше секунды». Медленнее полнотекстового поиска при большом объёме, зато в разы дешевле по железу.

9. Что выбрать: честное сравнение

Как выбрать. Один-два сервера, десятки тысяч строк в сутки, команда из двух-пяти человек — Loki: дешевле, не требует отдельной экспертизы, встаёт рядом с Prometheus из статьи про метрики. Десятки сервисов, требования искать по годовому архиву и произвольному тексту — ELK, и планируйте под него отдельный кластер и отдельное время на обслуживание.

Промежуточный вариант, часто самый правильный: горячие логи (последние 3–7 дней) в Loki для дежурного разбора, редкий глубокий архив — в сжатом виде на диске или в объектном хранилище. Искать «в марте прошлого года» — редкая задача, платить за мгновенный доступ к ней каждый день не нужно.

И предупреждение про объём: логи растут сами. Настройте срок хранения (retention) и следите за свободным диском как за метрикой — алерт «диск кончится через сутки» ловит эту аварию заранее.

Часть IV. Распределённая трассировка: как увидеть один запрос целиком

10. Что такое trace и span

Распределённая трассировка (distributed tracing) — способ записать и показать, по каким сервисам прошёл один пользовательский запрос и сколько занял каждый шаг. Два центральных понятия:

• span (букв. «отрезок») — один измеренный шаг: обработка запроса во фронтенде, вызов каталога, запрос к базе, обращение к платёжному шлюзу. У span есть имя, начало, длительность, родитель и атрибуты (URL, код ответа, имя таблицы).
• trace («след») — дерево всех span одного запроса, объединённых общим trace-ID. Один запрос пользователя = один trace = несколько десятков span.

Визуально это «водопад» (waterfall) — горизонтальные полосы на шкале времени:

trace 4bf92f35...   всего 3.12 с

edge (nginx)                    |████                             0.01 с
frontend  GET /cart             |  ██████████████████             1.90 с
  auth-service  check token     |   ████                          0.08 с
  catalog       GET /items      |      ██████                     0.35 с
  cart-service  POST /reserve   |         ████████████████████    1.42 с
    DB SELECT items             |           ██                    0.05 с
    payment  POST charge        |              █████████████████  3.00 с  <-- таймаут
      gateway (внешний)         |                 ██████████████  3.00 с

Один взгляд — и видно: 3 секунды из 3,12 занимает обращение к платёжному шлюзу, а cart-service просто его ждал. Никакого гадания, в каком из шести логов копать.

11. Jaeger и OpenTelemetry: кто за что отвечает

Здесь важно не перепутать стандарт и хранилище.

• OpenTelemetry (сокращённо OTel) — набор библиотек и соглашений: как измерять span, как называть атрибуты, как передавать контекст между сервисами и как отправлять всё это наружу (OTLP — протокол передачи телеметрии). Это «как собирать». Есть для разных языков, включая PHP.
• Jaeger — система, которая собирает trace, хранит и рисует водопад. Это «куда складывать и где смотреть». Аналоги: Tempo от Grafana (логичный выбор, если наблюдаемость уже в Grafana), Zipkin, облачные сервисы.

приложение --OTel SDK--> коллектор OpenTelemetry
                              |
              +---------------+----------------+
              |               |                |
         Jaeger (trace)  Loki (логи)   Prometheus (метрики)

Коллектор (collector) — промежуточная программа: принимает телеметрию от всех сервисов, обогащает, фильтрует и рассылает по получателям. Приложение должно уметь говорить только с ним, а не с каждым хранилищем отдельно.

Что Jaeger даёт поверх логов: карту зависимостей (граф «кто кого вызывает», построенный сам собой из trace), сравнение времени по любому span и переход в логи — из водопада вы одним фильтром уходите в строки именно этого запроса, потому что каждая лог-запись повторяет его trace-ID.

12. Дорого и много: семплирование

Полная трассировка каждого запроса на большом трафике невозможна: trace в несколько десятков span весит больше самой лог-строки. Поэтому применяют семплирование (sampling, выборочность) — сохраняют не все следы, а долю.

• голова-ориентированное (head-based) — решение принимается в начале: «каждый сотый запрос пишем целиком». Дёшево и предсказуемо, но редкая ошибка с вероятностью 1 к 1000 может ни разу не попасть в выборку.
• хвост-ориентированное (tail-based) — решение после завершения запроса: «пишем целиком все trace с ошибкой или дольше секунды, плюс 1% остальных». Идеально для разбора сбоев, но требует, чтобы коллектор держал trace целиком до решения.

Здравый смысл для небольшого проекта: 100% для всего, что дольше секунды или с статусом ≥ 500, 1–5% для остального. Проверять пределы такого режима удобно под нагрузкой — методики прогонов в Нагрузочное тестирование.

Часть V. Сквозной номер запроса: propagation request-ID

13. Что такое propagation и как номер путешествует

Propagation (распространение, передача) — приём, при котором идентификатор запроса передаётся из одного места в другое: из браузера в сервер, из сервера в сервер, из сервера в очередь и обратно. Без передачи контекста trace рассыпается на несвязанные куски: каждый сервис знает про свой шаг, но никто не собирает их в одну картину.

Стандартом де-факто стал заголовок traceparent из спецификации W3C Trace Context:

traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

Четыре части через дефис: версия формата (00), trace-ID (32 шестнадцатеричных символа, один на весь запрос), span-ID текущего шага (16 символов) и флаги (01 — «запись включена», то есть запрос решили сохранить). Рядом встречается tracestate — свободное место для полей вендоров, и X-Request-ID — исторически первый и до сих пор популярный простой вариант «просто номера запроса» без span.

Путешествует номер так:

1. Браузер номера не имеет — его ставит первая точка: краевой сервер (Nginx) или фронтенд-скрипт.
2. Сервис A читает заголовок, пишет trace-ID в каждую свою запись, открывает span.
3. Сервис A вызывает сервис B и обязательно кладёт traceparent в заголовок исходящего HTTP-запроса.
4. Сервис B делает то же самое и передаёт дальше — в сервис C и в базу.
5. Если работа уходит в очередь, trace-ID едет в метаданных сообщения: так логи потребителя связываются с запросом, который пользователь начал несколько минут назад.
6. Ответ возвращается клиенту с номером, и по нему можно найти весь след.

Важный нюанс: если входящего номера нет — вы его генерируете, а не оставляете пустым. Правило «у каждой записи есть request_id» сильнее правила «номер пришёл снаружи».

14. Браузер и сервер: ставим trace-ID на каждый запрос

Со стороны клиента логично порождать номер один раз на пользовательское действие (например, на отправку формы) и подставлять его во все сетевые вызовы этого действия. Ниже — маленький модуль без фреймворков, в духе Fetch API и REST.

// trace.js — сквозной номер запроса на стороне браузера

// Генерируем идентификатор: crypto.randomUUID даёт валидный набор hex-символов
function newTraceId() {
  return (crypto.randomUUID?.() ?? '').replaceAll('-', '');
}

// Один trace живёт до конца действия пользователя
let currentTrace = newTraceId();

// Обертка над fetch: добавляет traceparent и читает ответ
export async function apiFetch(path, options = {}) {
  const headers = new Headers(options.headers ?? {});
  headers.set('traceparent', `00-${currentTrace}-00f067aa0ba902b7-01`);
  headers.set('x-request-id', currentTrace);

  const started = performance.now();
  let response;
  try {
    response = await fetch(path, { ...options, headers });
  } catch (networkError) {
    console.warn('request failed', { trace: currentTrace, path });
    throw networkError;
  }

  const tookMs = Math.round(performance.now() - started);

  // Сервер мог начать новый trace на редиректе - сверяемся с его номером
  const serverTrace = response.headers.get('traceresponse')?.split('-')[1];
  if (serverTrace && serverTrace !== currentTrace) currentTrace = serverTrace;

  // Медленные и ошибочные запросы отправляем в собственный сборщик логов
  if (!response.ok || tookMs > 1000) {
    navigator.sendBeacon?.('/client-logs', new Blob([JSON.stringify({
      level: response.ok ? 'warning' : 'error',
      event: 'client.request_slow',
      trace_id: currentTrace,
      route: path,
      status: response.status,
      duration_ms: tookMs,
      ts: new Date().toISOString(),
    })], { type: 'application/json' }));
  }

  return response;
}

Что здесь полезно по-человечески: пользователь сообщает «у меня не оформляется заказ», вы просите номер из консоли — и у вас в руках trace-ID, по которому весь путь запроса лежит в Jaeger целиком. Это в разы быстрее, чем выяснять, в каком из шести сервисов копать.

На сервере номер подхватывает одна общая функция (PHP без фреймворка, как в Проектирование API): она разбирает traceparent, при отсутствии или ошибке в заголовке генерирует корректные идентификаторы, пишет trace-ID в контекст запроса и отдаёт номер обратно в заголовке traceresponse, чтобы его видел клиент и служба поддержки.

15. Не только HTTP: номер в очереди и в фоновых задачах

Отдельная ловушка — асинхронщина. Прямой вызов передаёт контекст заголовком, а очередь сообщений нет, потому что отправитель и потребитель не связаны во времени. Поэтому trace-ID кладут в метаданные сообщения и восстанавливают в потребителе.

{
  "id": "job-77120",
  "queue": "orders.paid",
  "body": { "order_id": 4711, "amount": 2490, "currency": "RUB" },
  "headers": {
    "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"
  },
  "published_at": "2026-10-14T19:40:09Z",
  "attempt": 1
}

Потребитель достаёт traceparent из headers, продолжает trace и пишет свои info-записи с тем же trace-ID. Тогда «пользователь нажал оплатить в 19:40:09 → письмо ушло в 19:40:31» — один след, а не два рассказа. Подробно про retry, attempt и мёртвые очереди — в Очереди сообщений.

Фоновые задачи WordPress (wp-cron) — тот же случай: генерируйте номер при запуске задания, пишите его в каждую запись и сохраняйте как метаданные задания, чтобы потом ответить «что происходило с этим письмом».

Часть VI. Что писать в лог, а что категорически нельзя

16. Почему лог — это канал утечки

Логи недооценивают как носитель секретов. Между тем лог-файл читается десятками людей (разработчики, DevOps, поддержка, аналитики), собирается в централизованное хранилище с более широким доступом, чем у вашей базы, хранится месяцами, тогда как «секундные» данные вроде одноразовых токенов давно не нужны, часто копируется в тикеты и чаты и иногда попадает в публичные артефакты — скриншот консоли в задаче, архив из обращения в поддержку.

Правило железное: в лог не попадает ничего, что нельзя показать любому человеку из числа читающих. Персональные данные (ПДн) — это не только паспорт: e-mail, телефон, адрес, IP-адрес в сочетании с идентификатором пользователя тоже относятся к персональным, и их обработка регулируется законом.

17. Красный и зелёный списки

Красный список — не писать никогда:

Отдельно про дампы окружения: в $_ENV и $_SERVER живут ключи баз данных и токены. Ошибка «залогируем весь контекст» стоит дороже всего остального из списка.

Зелёный список — писать смело и много: идентификаторы (request_id, trace_id, user_id — внутренний номер, не почта, order_id); маршрут и результат (метод, путь, HTTP-статус, код доменной ошибки gateway_code, имя исключения); длительности (общее время, время внешних вызовов и обращений к базе); признаки окружения (service, env, версия приложения, имя хоста или контейнера); количества (размер ответа, число строк, attempt — номер попытки); решения системы («выбран бэкенд №3», «кэш промахнулся», «включен резервный путь»).

18. Маскирование: не «не пиши», а «не пройдёт»

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

<?php
// redact-processor.php — процессор Monolog: режем секреты до записи на диск
const SENSITIVE_KEYS = [
    'password', 'passwd', 'token', 'access_token', 'refresh_token',
    'authorization', 'cookie', 'set-cookie', 'secret', 'api_key', 'apikey',
    'cvv', 'cvc', 'card_number', 'pan', 'email', 'phone', 'ip',
];

function maskValue(string $key, mixed $value): string
{
    // Для идентифицирующих данных сохраняем форму, но убираем содержание
    if (in_array($key, ['email', 'phone', 'ip'], true) && $value !== null) {
        return substr(md5((string) $value), 0, 12) . '…';   // необратимый отпечаток
    }
    return '[redacted]';
}

function redactArray(array $data): array
{
    foreach ($data as $key => $value) {
        if (is_string($key) && in_array(strtolower($key), SENSITIVE_KEYS, true)) {
            $data[$key] = maskValue($key, $value);
        } elseif (is_array($value)) {
            $data[$key] = redactArray($value);            // идем вглубь структур
        } elseif (is_object($value)) {
            $data[$key] = redactArray(get_object_vars($value));
        }
    }
    return $data;
}

$log->pushProcessor(function ($record) {
    $record->context = redactArray($record->context);
    $record->extra   = redactArray($record->extra);
    return $record;
});

<?php
// redact-processor.php — процессор Monolog: режем секреты до записи на диск
const SENSITIVE_KEYS = [
    'password', 'passwd', 'token', 'access_token', 'refresh_token',
    'authorization', 'cookie', 'set-cookie', 'secret', 'api_key', 'apikey',
    'cvv', 'cvc', 'card_number', 'pan', 'email', 'phone', 'ip',
];

function maskValue(string $key, mixed $value): string
{
    // Для идентифицирующих данных сохраняем форму, но убираем содержание
    if (in_array($key, ['email', 'phone', 'ip'], true) && $value !== null) {
        return substr(md5((string) $value), 0, 12) . '…';   // необратимый отпечаток
    }
    return '[redacted]';
}

function redactArray(array $data): array
{
    foreach ($data as $key => $value) {
        if (is_string($key) && in_array(strtolower($key), SENSITIVE_KEYS, true)) {
            $data[$key] = maskValue($key, $value);
        } elseif (is_array($value)) {
            $data[$key] = redactArray($value);            // идем вглубь структур
        } elseif (is_object($value)) {
            $data[$key] = redactArray(get_object_vars($value));
        }
    }
    return $data;
}

$log->pushProcessor(function ($record) {
    $record->context = redactArray($record->context);
    $record->extra   = redactArray($record->extra);
    return $record;
});

Три замечания к такому фильтру:

1. Белый список надёжнее чёрного. Чёрный список («срежем эти имена») всегда отстаёт от фантазии коллег: секрет можно назвать authkey2. Если запись строится из заранее известного набора полей — лишнее просто не попадёт в формат.
2. Хеширование не спасает полностью. Отпечаток e-mail позволяет связывать записи между собой (это нужно для аудита), но при утечке частично обратим перебором по частым адресам. Для строгой защиты — соль и отдельный ключ, то есть необратимая псевдонимизация.
3. Маскируйте в URL тоже. ?token=abc в поле route — та же утечка. Не забывайте резать строки запроса и заголовки в атрибутах span: трассировка попадает в то же хранилище, что и логи.

Полезная привычка: раз в квартал запускать по своим логам простой поиск (grep -Ei 'password|token|secret|bearer') и смотреть, что нашлось. Найденное почти всегда объясняется одним «временным» дампом на уровне debug, который зажил. Как устроен этот grep-паттерн (альтернатива |, регистронезависимый флаг, границы слова, чтобы token не ловил tokens_count) — разбираем в Регулярные выражения на практике.

Часть VII. Практика: как добавить трассировку в существующее приложение

19. Порядок работ: от одного дня до одной недели

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

• Шаг 0. Замерьте текущее состояние. Достаточно двух чисел: времени разбора последнего инцидента («4 часа») и объёма логов в сутки. Метрики к этому моменту уже должны быть — см. Метрики и мониторинг.
• Шаг 1. Единый формат записей (один день). JSON-логгер во всех сервисах с шестью обязательными полями из Части II. Код меняется минимально: одна обёртка logger() и замена самого шумного текста на структурированные записи.
• Шаг 2. Сквозной номер (один-два дня). request_id/traceparent в приём (одна функция в общем бутстрэпе), в исходящие вызовы (одна обёртка над HTTP-клиентом) и в метаданные очереди. Это самый дешёвый и самый полезный шаг — его стоит сделать, даже если Jaeger вы не поставите никогда.
• Шаг 3. Хранилище (два-три дня). Loki + Promtail (или ELK), срок хранения, один дашборд с поиском по trace-ID.
• Шаг 4. Трейс (несколько дней). OpenTelemetry SDK, коллектор, Jaeger, семплирование «ошибки и долгие — 100%, остальное 1–5%».
• Шаг 5. Связка (полдня). В Grafana переходы: из метрики — к логам того же времени и сервиса, из span — в Loki по trace_id. Это превращает набор инструментов в процесс разбора.

20. Простая настройка Jaeger-трейсера

Ниже — компактный пример на Python, чтобы показать механику: создаётся трейсер, каждый шаг оборачивается в span, атрибуты пишутся. В PHP и Node.js структура та же, отличаются имена классов и автоматические интеграции.

# tracer.py — простая настройка Jaeger через OpenTelemetry
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.resources import Resource
from opentelemetry.sdk.trace.sampling import TraceIdRatioBased
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter

def init_tracer(service_name: str, collector: str = "localhost:4317") -> trace.Tracer:
    # Выборка: обычный трафик пишем редко, ошибки и долгие отберем позже
    sampler = TraceIdRatioBased(0.05)

    provider = TracerProvider(
        resource=Resource.create({
            "service.name": service_name,
            "deployment.environment": "prod",
        }),
        sampler=sampler,
    )
    provider.add_span_processor(BatchSpanProcessor(OTLPSpanExporter(endpoint=collector)))
    trace.set_tracer_provider(provider)
    return trace.get_tracer(service_name)

tracer = init_tracer("payment-service")

def charge_order(order_id: int, amount: int) -> bool:
    # Один span = один шаг работы. Имя отражает операцию, а не свободный текст.
    with tracer.start_as_current_span("payment.charge") as span:
        span.set_attribute("order.id", order_id)
        span.set_attribute("app.currency", "RUB")

        current = trace.get_current_span().get_span_context()
        # Тот же trace_id, что попадает в логи: связка "след -> строки"
        print(f"trace_id={format(current.trace_id, '032x')}")

        try:
            ok = call_gateway(order_id, amount)
        except TimeoutError as exc:
            span.record_exception(exc)
            span.set_attribute("error", True)
            span.set_status(trace.Status(trace.StatusCode.ERROR, "gateway timeout"))
            raise
        return ok

def call_gateway(order_id: int, amount: int) -> bool:
    # Вложенный span = внешний вызов; propagator сам подставит traceparent
    with tracer.start_as_current_span("gateway.request", kind=trace.SpanKind.CLIENT):
        return True  # здесь реальный HTTP-клиент

# tracer.py — простая настройка Jaeger через OpenTelemetry
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.resources import Resource
from opentelemetry.sdk.trace.sampling import TraceIdRatioBased
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter

def init_tracer(service_name: str, collector: str = "localhost:4317") -> trace.Tracer:
    # Выборка: обычный трафик пишем редко, ошибки и долгие отберем позже
    sampler = TraceIdRatioBased(0.05)

    provider = TracerProvider(
        resource=Resource.create({
            "service.name": service_name,
            "deployment.environment": "prod",
        }),
        sampler=sampler,
    )
    provider.add_span_processor(BatchSpanProcessor(OTLPSpanExporter(endpoint=collector)))
    trace.set_tracer_provider(provider)
    return trace.get_tracer(service_name)

tracer = init_tracer("payment-service")

def charge_order(order_id: int, amount: int) -> bool:
    # Один span = один шаг работы. Имя отражает операцию, а не свободный текст.
    with tracer.start_as_current_span("payment.charge") as span:
        span.set_attribute("order.id", order_id)
        span.set_attribute("app.currency", "RUB")

        current = trace.get_current_span().get_span_context()
        # Тот же trace_id, что попадает в логи: связка "след -> строки"
        print(f"trace_id={format(current.trace_id, '032x')}")

        try:
            ok = call_gateway(order_id, amount)
        except TimeoutError as exc:
            span.record_exception(exc)
            span.set_attribute("error", True)
            span.set_status(trace.Status(trace.StatusCode.ERROR, "gateway timeout"))
            raise
        return ok

def call_gateway(order_id: int, amount: int) -> bool:
    # Вложенный span = внешний вызов; propagator сам подставит traceparent
    with tracer.start_as_current_span("gateway.request", kind=trace.SpanKind.CLIENT):
        return True  # здесь реальный HTTP-клиент

Что важно в этом коде с точки зрения здравого смысла: имя span — машинное (payment.charge), атрибуты — короткие и конечные по числу значений; error и Status ставятся явно, иначе правило выборки «всё с ошибкой — 100%» не сможет их отобрать; trace_id печатается в том же виде, что и в JSON-логе (32 hex-символа), и это единственный мостик между двумя системами; BatchSpanProcessor отправляет пакетами — никогда не ждите сети трейсера внутри пользовательского запроса.

21. Как проверить, что всё действительно работает

Трассировка коварна тем, что «почти настроенная» выглядит как работающая: trace есть, но рваный. Мини-проверка на пять минут:

1. Отправьте запрос и найдите его trace-ID в логе фронтенда.
2. По этому номеру отфильтруйте логи всех остальных сервисов — записи должны найтись по всей цепочке, а не в одном месте.
3. Откройте trace в Jaeger: полос должно быть столько же, сколько реальных вызовов. Один span без детей означает, что propagation не сработал — контекст теряется на исходящем HTTP-вызове или при передаче в очередь.
4. Сделайте запрос с ошибкой и убедитесь, что он попал в выборку, несмотря на 5% семплирование.
5. Проверьте маскирование: напишите в лог пароль и посмотрите, что сохранилось в Loki. Должно быть [redacted], а не пароль.
6. Замерьте, как сильно выросла задержка: трассировка и логирование стоят процентов, а не десятков процентов. Сравнение «до/после» — прямой сценарий из Нагрузочное тестирование.

Типовые находки на этом шаге: забытый заголовок в одном из шести сервисов, логгер, пишущий «на всякий случай» в старый текстовый файл, Authorization в атрибутах span и коллектор, принимающий 100% traces при диске, рассчитанном на 5%.

22. Чек-лист внедрения

• Формат. Все сервисы пишут JSON по одному контракту полей; время — ISO 8601 с таймзоной.
• Уровни. debug в проде выключен, warning = «справились сами», error = «задача не выполнена».
• Объём. Приложение не логирует каждый успешный запрос, дампы debug отсечены, включены ротация и срок хранения.
• Связность. У каждой записи есть trace_id; заголовок передаётся во всех исходящих вызовах и в метаданных очереди.
• Безопасность. Фильтр маскирования включён на уровне логгера; пароли, токены, ключи, карты и ПДн в логах отсутствуют.
• Хранилище. Loki для одного-нескольких VPS (дёшево, рядом с Grafana) или ELK, когда нужен полнотекстовый поиск по архиву.
• Трейс. OpenTelemetry SDK → коллектор → Jaeger; выборка: ошибки и долгие запросы 100%, остальное 1–5%.
• Процесс. Из дашборда метрик есть переход к логам этого времени и сервиса, из span — к строкам по trace_id.
• Экономика. Стоимость хранения логов и traces посчитана как метрика и не растёт бесконтрольно.
• Регулярность. Раз в квартал — проверка логов на секреты через grep и ретроспектива одного реального инцидента: за сколько минут нашли причину.

Инструмент под задачу

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

Итог. Три инструмента одной цели

Логи, метрики и трассировка — не три конкурирующих моды, а один механизм в трёх ипостасях. Метрики замечают. Логи объясняют. Трассировка показывает место. Если работает только одно из трёх, вы либо узнаёте поздно, либо узнаёте долго, либо узнаёте не то.

• Пишите объекты, а не предложения. JSON-запись с шестью обязательными полями (ts, level, service, trace_id, event, message) превращает журнал в базу данных, которую можно фильтровать и считать.
• Уровни — это регулятор объёма, а не украшение. debug по умолчанию выключен, error = невыполненная задача, шкала одинакова во всех сервисах.
• ELK против Loki — выбор по бюджету и по типу поиска. Для нескольких VPS и небольшой команды Loki почти всегда выигрывает; полнотекстовый поиск по годовому архиву — территория Elasticsearch.
• Сквозной номер — самая дешёвая и самая сильная мера. Один trace_id во всех записях и всех вызовах, включая сообщения очереди, сокращает разбор инцидента с часов до минут.
• Трассировка без семплирования разорит вас. Держите 100% для ошибок и медленных запросов и проценты — для остального.
• Лог — канал утечки. Маскируйте секреты на уровне логгера, а не на честном слове, и не логируйте содержимое запросов целиком.

Материал написан простым языком без излишней терминологии. Термины расшифрованы при первом упоминании (structured logging, distributed tracing, span, trace, propagation, sampling, ELK, ПДн), названия инструментов оставлены как в документации (Elasticsearch, Logstash, Kibana, Loki, Promtail, Jaeger, Zipkin, Tempo, OpenTelemetry, Grafana, Monolog, OTLP), аббревиатуры приведены в общепринятом виде (JSON, HTTP, API, JWT, TTL, NDJSON). Примеры конфигураций и кода приведены сокращённо: конкретные версии библиотек и имена полей сверяйте по официальной документации OpenTelemetry, Grafana Loki и Jaeger. Практические советы учитывают специфику WordPress -проектов и самостоятельного хостинга на VPS.