lenec ru

← все посты

Алексей Морозов Подписаться

Correlation ID на практике: как сшить логи в одну историю запроса

15K

Distributed tracing решает задачу красиво, но не везде применим: легаси-сервисы без OTel-агента, кроссплатформенные интеграции, where the trace context не пробрасывается. Часто проще иметь хотя бы одну вещь — correlation ID — и через неё связывать логи всех сервисов в одну историю.

Correlation ID — это уникальный идентификатор запроса, который проходит через все сервисы и записывается в каждый лог. По нему можно собрать полную картину обработки конкретного запроса grep'ом по всем логам.

За двенадцать лет я видел проекты, где correlation ID был, и проекты, где не был. Разница в скорости решения инцидентов — на порядок. Разберу, как правильно его внедрять, чтобы это работало действительно везде, а не «у нас вроде есть, но в Kafka-консьюмере не пробрасывается».

Зачем именно correlation ID

В обычной системе с десятком сервисов один пользовательский запрос превращается в десятки внутренних. Без correlation ID отладка инцидента выглядит так:

  1. Юзер пишет «у меня заказ не создался в 15:42».
  2. Открываю логи orders, ищу по user_id и времени.
  3. Нахожу ошибку в payments. Иду в payments-логи, ищу по orderId и времени.
  4. Нахожу там вызов в provider-сервис. Иду туда. И так далее.

Это полчаса с надеждой, что я нигде не путаюсь и что временные интервалы не пересекаются. С correlation ID — один grep по всем логам за 30 секунд.

Минимальная схема

На входе в систему (API gateway или первый сервис) генерируется UUID:

@Component
class CorrelationIdFilter : Filter {
    override fun doFilter(req: ServletRequest, resp: ServletResponse, chain: FilterChain) {
        val request = req as HttpServletRequest
        val correlationId = request.getHeader("X-Correlation-Id") 
            ?: UUID.randomUUID().toString()
        
        MDC.put("correlationId", correlationId)
        try {
            (resp as HttpServletResponse).setHeader("X-Correlation-Id", correlationId)
            chain.doFilter(req, resp)
        } finally {
            MDC.clear()
        }
    }
}

Логика:

  • Если в заголовке уже есть X-Correlation-Id — используем его.
  • Если нет — генерируем UUID.
  • Кладём в MDC (Mapped Diagnostic Context — thread-local-хранилище для логирования).
  • Возвращаем тот же ID в response (для клиента).

Logback/Log4j настраиваются добавлять MDC в каждую запись:

<encoder>
    <pattern>%d{HH:mm:ss.SSS} [%thread] [%X{correlationId:-}] %-5level %logger - %msg%n</pattern>
</encoder>

Теперь каждая лог-запись содержит correlation ID без участия программиста. Поиск по логам — `correlationId=xxx`.

Пробрасывание между сервисами

Главный момент. Correlation ID должен идти со всеми исходящими запросами.

HTTP-клиент

// RestTemplate interceptor
@Component
class CorrelationIdInterceptor : ClientHttpRequestInterceptor {
    override fun intercept(
        request: HttpRequest,
        body: ByteArray,
        execution: ClientHttpRequestExecution
    ): ClientHttpResponse {
        MDC.get("correlationId")?.let {
            request.headers.add("X-Correlation-Id", it)
        }
        return execution.execute(request, body)
    }
}

На стороне получателя — тот же фильтр, который на входе. Он либо подхватит ID из заголовка, либо сгенерирует.

Kafka producer/consumer

// Producer
fun publish(topic: String, key: String, payload: ByteArray) {
    val record = ProducerRecord(topic, null, key, payload)
    MDC.get("correlationId")?.let {
        record.headers().add("correlation-id", it.toByteArray())
    }
    producer.send(record)
}

// Consumer
fun handle(record: ConsumerRecord<String, ByteArray>) {
    val cid = record.headers().lastHeader("correlation-id")?.value()?.toString(Charsets.UTF_8)
        ?: UUID.randomUUID().toString()
    MDC.put("correlationId", cid)
    try {
        process(record.value())
    } finally {
        MDC.clear()
    }
}

Главная ошибка — забыть очистить MDC. На переиспользуемом потоке (worker pool) предыдущий correlation ID останется и «утечёт» в обработку следующего сообщения. finally { MDC.clear() } — обязательно.

Async и executors

MDC хранится в ThreadLocal. На executor service контекст теряется при переходе задачи в другой поток.

// Прозрачный wrapper над executor
class MdcAwareExecutor(private val delegate: Executor) : Executor {
    override fun execute(command: Runnable) {
        val context = MDC.getCopyOfContextMap()
        delegate.execute {
            val original = MDC.getCopyOfContextMap()
            try {
                if (context != null) MDC.setContextMap(context) else MDC.clear()
                command.run()
            } finally {
                if (original != null) MDC.setContextMap(original) else MDC.clear()
            }
        }
    }
}

Аналогично для CompletableFuture, Reactor (Schedulers), Kotlin Coroutines (есть готовый MDCContext). Если этого не сделать, на каждом async-переходе теряется correlation ID, и логи перестают связываться.

Correlation ID и trace_id

Если у вас уже есть OpenTelemetry, trace_id — это и есть ваш correlation ID. Он генерируется автоматически, пробрасывается через стандартные заголовки, доступен в логах через MDC.

Дублировать correlation ID отдельным полем — не нужно. Используйте trace_id как correlation_id, и не путайте две концепции.

Когда оба нужны:

  • В системах, где не везде есть OTel (legacy + new). Correlation ID — общий знаменатель.
  • Для clients, которые видят свой запрос в логах: trace_id обычно скрыт в OTel-headers, correlation ID можно вернуть в response для клиента.
  • В цепочках через внешние интеграции (партнёры, внешние API). Trace_id W3C может не пробрасываться, correlation ID можно класть в любой заголовок.

Структурированное логирование

Correlation ID работает только если логи можно искать. Текстовые логи в файлах с pattern'ом — допустимо, но grep по 50 файлам — медленно.

Структурированное логирование (JSON) с агрегатором (Loki, Elasticsearch, Datadog) — правильный путь. Каждая запись — JSON с полями, в том числе correlation_id.

{"ts":"2026-03-15T15:42:00.123Z","level":"INFO","logger":"OrderService","msg":"order created","correlation_id":"abc-123","order_id":"42","user_id":"7"}

Поиск становится: correlation_id:"abc-123" в Loki/ES, и за полсекунды видны все логи всех сервисов по этому запросу.

Передача в response

Возвращайте correlation ID клиенту в response-заголовке. Это позволяет пользователю/другому сервису сослаться на конкретный запрос:

Поддержка пишет: «у меня ошибка, X-Correlation-Id из ответа: 7f3a-2c8e».
Инженер: grep correlation_id=7f3a-2c8e — все логи перед глазами.

Клиент тоже может в свой UI выводить correlation ID при ошибках: «request id: 7f3a-2c8e». Это привычная практика у крупных API (AWS, Stripe).

Подводные камни

Несколько вещей, на которые я наступал.

Утечка между запросами через ThreadLocal. На переиспользуемом потоке (Tomcat, Netty worker) MDC не очищается между запросами. Один correlation ID «прилипает», все последующие логи в этом потоке используют его. Решение — обязательный MDC.clear() в filter'е и middleware.

Async-cancel. Запустили async-задачу с MDC-контекстом, отменили её. ThreadLocal остался установлен. Следующая задача получает чужой correlation ID. Декоратор должен очищать.

Пропуски в Kafka. Producer публикует событие с correlation ID, consumer корректно подхватывает. Между ними — outbox. Outbox-писатель сам не имеет MDC при публикации (он работает в отдельном scheduler-потоке). Решение — outbox-row хранит correlation ID, publisher читает и проставляет в headers.

Слишком короткие ID. Использовали 8-значный hex для «компактности». На 100k запросов в день — коллизии в течение дня. UUID = 122 бита энтропии — достаточно. Не экономьте.

ID в URL. Не кладите correlation ID в query string или path. Он попадёт в access-логи прокси, в browser history, в bookmark. Заголовок — единственное правильное место.

ID без обязательного формата. Принимаете любую строку из заголовка X-Correlation-Id. Клиент шлёт <script> или 50 МБ. Сервис логирует. Лекарство — валидация формата (regex для UUID или alphanumeric, длина не больше 64).

Использование в инцидентах

Несколько практик, которые ускоряют расследование.

Correlation ID в алертах. Алерт «5xx errors на endpoint X» содержит примеры correlation_id. Инженер сразу копирует и идёт в логи.

В письмах об ошибках. Если ваш сервис шлёт error-emails в Sentry или Slack, correlation_id должен быть в каждом сообщении.

В метриках. Метрики — агрегированные данные, без correlation_id. Но в exemplars (если бэкенд поддерживает Prometheus exemplars) можно прикрепить trace_id/correlation_id к примеру значения. Тогда от пика на графике переходим в конкретные трассы.

В клиентских ошибках. Браузер логирует ошибки с window.onerror — он видит correlation_id из last-response-header. Складываем в Sentry браузерный + correlation_id, по нему достаём логи бэкенда.

Что запомнить

Correlation ID — самая дешёвая обвязка, которая радикально ускоряет отладку. Один UUID, проброшенный через все хопы, запись в каждом логе через MDC, поиск через структурированный лог-агрегатор.

Если у вас нет OpenTelemetry — correlation ID обязателен. Если есть — используйте trace_id, он закрывает ту же задачу. Дублировать ради «дополнительного канала» обычно не нужно.

Главное — пробрасывание везде: HTTP, Kafka, async-executors, scheduled jobs, outbox-publishers. Если хоть один хоп не пробрасывает, цепочка ломается, и в этом месте логи перестают связываться. Один пропуск делает correlation ID бесполезным для половины случаев.

Внедрение занимает день-два, окупается на первом серьёзном инциденте.

Комментарии 0

  • Будьте первым, кто оставит комментарий.

Войдите, чтобы оставить комментарий.