trace_id и корреляция запросов

Строка лога без связи со своим запросом — обрывок: факт есть, истории нет. Под нагрузкой в секунду проходят сотни запросов, их записи перемешиваются в ленте, и без общего идентификатора восстановить цепочку «запрос, сервис, база, ответ» — археология по таймстампам с точностью до миллисекунд, которая ломается на первом же соседнем запросе из того же момента. Идентификатор решает это структурно: каждая запись несёт одно поле, и фильтр по нему собирает полную хронологию во всех сервисах, куда запрос дошёл. Дисциплина вокруг поля простая, но строгая: ключ один во всей системе, значение не меняется до конца запроса, поле пишут все сервисы цепочки. Терминология урока: request_id из урока про HTTP-логи размечает запрос внутри одного контура, trace_id — сквозной идентификатор, который проезжает границы сервисов; на практике это часто одно и то же значение, и разница — в договорённости, кто его ставит.

Откуда берётся trace_id: заголовки и генерация#

Приоритетный источник — входящий заголовок: кто-то до вас уже пометил запрос, и задача сервиса не потерять значение. В ходу два формата. X-Request-Id — простой непрозрачный токен, его ставят ingress, балансировщик или шлюз; формат свободный, договоритесь о длине и алфавите. W3C traceparent — стандарт трейсинга: строка вида 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01, где поля разделены дефисами — версия, trace-id из 32 шестнадцатеричных символов, parent-id из 16 и флаги из 2. Парсится он своей функцией в десять строк: библиотека для этого не нужна, и в ядре zerolog её нет. Если заголовков нет — идентификатор генерируете вы: crypto/rand даёт шестнадцать случайных байт, hex.EncodeToString превращает их в строку тех же 32 символов. Приоритет прозрачен: traceparent — стандарт, затем X-Request-Id от прокси, затем генерация; любое из значений годится для поля лога.

Парсер traceparent и генерация идентификатора

func traceID(r *http.Request) string {
        if tp := r.Header.Get("traceparent"); tp != "" {
                if id, ok := parseTraceparent(tp); ok {
                        return id
                }
        }
        if id := r.Header.Get("X-Request-Id"); id != "" {
                return id
        }
        var b [16]byte
        if _, err := rand.Read(b[:]); err != nil {
                return strconv.FormatInt(time.Now().UnixNano(), 16)
        }
        return hex.EncodeToString(b[:])
}

func parseTraceparent(tp string) (string, bool) {
        parts := strings.Split(tp, "-")
        if len(parts) != 4 || parts[0] != "00" {
                return "", false
        }
        if len(parts[1]) != 32 || len(parts[2]) != 16 || len(parts[3]) != 2 {
                return "", false
        }
        if _, err := hex.DecodeString(parts[1]); err != nil {
                return "", false
        }
        return parts[1], true
}

Приоритет источников — от стандарта к фолбэку: traceparent, X-Request-Id, генерация crypto/rand. Парсер проверяет структуру по частям: четыре поля, версия 00, длины 32-16-2 и честный hex в trace-id — битая строка молча проваливается к следующему источнику. Генератор возвращает 32 hex-символа — тот же вид, что у стандарта, поэтому поле trace_id выглядит одинаково при любом источнике.

Живое место: UpdateContext на общем логгере

Идея «дописать trace_id в общий пакетный логгер на каждый запрос» ломается на первой параллельной нагрузке: UpdateContext меняет внутренний слайс контекста на месте и прямо помечен не потокобезопасным — два запроса гоняются за одним буфером, и в записях оказываются чужие идентификаторы. Случай уже разбирался в уроке про горутины; здесь он возвращается, потому что middleware — самое соблазнительное место для такого кода. Если trace_id должен жить у каждой записи запроса, то собирайте копию через With и кладите её в request-контекст: hlog.NewHandler из поставки zerolog делает ровно это и по той же причине создаёт копию до записи в контекст. Проверка за минуту: два конкурентных запроса и go run -race — детектор покажет гонку на UpdateContext, а копии через With дадут чистый прогон.

Логгер запроса: With и request-контекст#

Механика та же, что у request_id из урока про HTTP-логи, меняются значение и название поля. В middleware собирается копия: l := log.With().Str("trace_id", id).Logger() — With копирует контекстные байты базового логгера и дописывает поле, и каждая запись этой копии несёт trace_id без единого дополнительного вызова в хендлерах. Контекстные поля из урока про Logger.With копируются один раз при сборке, дальше копия только читается — поэтому параллельные запросы не мешают друг другу. Копия уезжает вниз по стеку через request-контекст: l.WithContext(r.Context()) и next.ServeHTTP(w, r.WithContext(ctx)); в глубине — сервисный слой, репозиторий, фоновая горутина — логгер достаётся zerolog.Ctx, который никогда не возвращает nil. Нюанс из той же связки: отключённые логгеры в контекст не кладутся — копия с порогом Disabled вернёт дефолт, и записи запроса молча пропадут. Полезный жест — вернуть идентификатор клиенту тем же заголовком: поддержка назовёт его из UI, и фильтр по trace_id найдёт весь путь запроса за секунды.

Middleware корреляции целиком

func traceMiddleware(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
                id := traceID(r)
                w.Header().Set("X-Request-Id", id)

                l := log.With().Str("trace_id", id).Logger()
                ctx := l.WithContext(r.Context())

                next.ServeHTTP(w, r.WithContext(ctx))
        })
}

func handle(w http.ResponseWriter, r *http.Request) {
        l := zerolog.Ctx(r.Context())
        l.Info().Str("route", "/orders").Msg("order received")
        // запись несёт поле trace_id без единого вызова в хендлере
}

Middleware делает три вещи: выбирает идентификатор по приоритету источников, возвращает его клиенту заголовком и собирает размеченную копию логгера. With дописывает trace_id в контекст копии, WithContext кладёт её в request-контекст — хендлер достаёт логгер zerolog.Ctx и пишет обычное Info-событие, а поле trace_id в записи появляется само.

Hook: дозапись поля в событие#

Когда логгер параметром не передаётся — чужой код пишет в глобальный log.Logger, а контекст запроса в глубине стека недоступен, — поле доставляет хук. Хук zerolog.Hook с методом Run(e *Event, level Level, message string) срабатывает в момент Msg до записи в writer: событие ещё открыто, и e.Str() из хука попадает в JSON — это факт механики msg(), а не трюк. Контекст до хука доезжает цепочкой .Ctx(ctx) на событии и методом e.GetCtx() внутри Run: док-комментарий Event.Ctx в исходниках называет извлечение трассировочной информации основным сценарием. Схема честная: каждый вызов должен приложить контекст .Ctx(ctx); без него хук увидит пустой context.Background, и в записи не появится ничего. Поэтому Hook — инструмент точечных дозаписей, а разметку целого запроса надёжнее делать With-копией в middleware: она приклеивает поле ко всем событиям разом и не зависит от дисциплины вызовов. Выбор простой: контролируете точки входа — With; событие идёт из чужого кода — хук.

Хук, достающий trace_id из контекста

type traceKey struct{}

type traceHook struct{}

func (traceHook) Run(e *zerolog.Event, level zerolog.Level, msg string) {
        if id, ok := e.GetCtx().Value(traceKey{}).(string); ok {
                e.Str("trace_id", id)
        }
}

var base = zerolog.New(os.Stderr).Hook(traceHook{}).With().Timestamp().Logger()

func doWork(ctx context.Context) {
        base.Info().Ctx(ctx).Str("step", "charge").Msg("working")
        // поле появится, если trace_id лежит в ctx под traceKey
}

Хук срабатывает в msg() до записи: e.Str дописывает поле в ещё открытый буфер события, и оно уезжает в JSON. Контекст прикладывается к событию методом Ctx и достаётся в Run через GetCtx — только так хук видит значения запроса. Утверждение с проверкой типа отсекает события без контекста: поле просто не появится в записи.

Поле живёт своей жизнью только до сборщика, дальше начинается склейка. Фильтр по trace_id в хранилище логов возвращает все записи запроса из всех сервисов, где поле писалось одинаковым ключом, — поэтому ключ trace_id фиксируется стандартом команды, а не вкусом каждого репозитория. Для дежурного это главный выигрыш: инцидент не разбирается по одной машине, а восстанавливается как цепочка событий от входа до отказа, и каждый прыжок между сервисами виден в одном списке. Дисциплина из урока про HTTP-логи действует без изменений: идентификатор не меняется до конца запроса, не путается с идентификатором пользователя и пишется во всех записях одним ключом. Отдельный вопрос — фоновые горутины, которые переживают запрос: если работа уходит в очередь, идентификатор проезжает внутри задачи, и воркер подписывает свои записи тем же trace_id — иначе хвост цепочки потеряется. Проверка корреляции дешёвая: одна тестовая цепочка из двух вызовов, в ленте фильтр по идентификатору — и вы должны увидеть записи обоих сервисов. Порядок строк внутри одного процесса по-прежнему не гарантирован: планировщик прав, как говорил урок про горутины, а фильтр восстанавливает хронологию по таймстампам.

Кто ставит идентификатор#

Источник	Что ставит	Формат	Место в приоритете
Инструментированный клиент	traceparent	00-trace-id(32 hex)-parent(16)-flags(2)	первый: стандарт W3C
Ingress или балансировщик	X-Request-Id	непрозрачный токен	второй
Ваш middleware	генерация crypto/rand	16 байт в hex: 32 символа	фолбэк без заголовков
hlog.CustomHeaderHandler	поле из заголовка	любое значение	готовый хендлер пакета zerolog
Парсер из урока	trace_id	32 hex-символа	единый вид поля при любом источнике

X-Request-Id против traceparent#

Два заголовка конкурируют за одну роль, и оставлять выбор на каждый сервис — путь к ленте, где половина записей подписана req_id, половина trace_id, а фильтр работает через раз. Решение — одна запись в стандарте команды: приоритет у traceparent, если строка распарсилась, затем X-Request-Id, затем генерация; схема ровно та, что в коде урока. Тонкость traceparent: второе поле — идентификатор трейса, третье — идентификатор спана, текущего отрезка работы. В логи уезжает trace-id; span_id тоже полезен — он различает два сервиса одной цепочки, — но это отдельное поле, а не замена trace_id. Флаги из двух символов говорят о сэмплинге трейса и в логе не нужны. Если трейсера в системе нет, а клиенты присылают traceparent, парсить и использовать trace-id всё равно стоит: поле останется совместимым с будущим внедрением, и лента не заметит подмены источника. Проверка стандарта — один тест на middleware: битый traceparent, пустой X-Request-Id и генерация дают предсказуемые значения поля.

Чек-лист корреляции#

идентификатор берётся по приоритету: traceparent, затем X-Request-Id, затем crypto/rand
поле пишется одним ключом trace_id во всех сервисах цепочки
копия логгера собирается через With в middleware и едет в request-контексте
UpdateContext на общем логгере запрещён: не потокобезопасен, гонка под нагрузкой
хук с GetCtx дозаписывает поле, когда логгер-параметр недоступен; событию нужен .Ctx(ctx)
идентификатор возвращается клиенту заголовком — поддержка найдёт запрос по нему
фоновые задачи уносят trace_id в очередь: воркер подписывает хвост цепочки
тест: битый traceparent, чужой заголовок и генерация дают предсказуемое поле

Про песочницу

Сетевой middleware в песочнице сайта не собрать: она исполняет программы без внешних библиотек, и zerolog туда не входит. Тематическая программа покажет распарсенный traceparent: строка стандарта на входе, четыре поля и извлечённый trace-id на выходе — вся логика урока без HTTP. Если хочется увидеть размеченную ленту целиком, то полный сценарий запускается локально: curl с заголовком X-Request-Id и поток stderr, где каждая запись запроса несёт ваше значение.

Проверка: приоритет источников

Заголовки traceparent (валидный) и X-Request-Id пришли вместе. Что попадёт в поле trace_id?

Проверка: UpdateContext в middleware

Почему middleware не дописывает trace_id через UpdateContext на общем логгере?

Что вернёт парсер на битой строке?

Прочитайте код и выберите, что он выведет:

tp := "00-4bf92f3577b34da6a3ce929d0e0e4736-zzz-01"

id, ok := parseTraceparent(tp)
if !ok {
        id = "fallback"
}
fmt.Println(id)

Соберите middleware корреляции

Восстановите разметку запроса: копия логгера, поле, request-контекст.

func traceMiddleware(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { id := traceID(r) l := log.With().Str("trace_id", ).Logger() ctx := l.(r.()) next.ServeHTTP(w, r.WithContext(ctx)) }) }

Тело хука с GetCtx

Расставьте строки хука в правильном порядке: от объявления типа до дозаписи поля.

Строки

Ваша программа

Нажимайте на строки слева, чтобы собрать программу

Карточки: корреляция

Термин

trace_id и request_id

нажмите, чтобы перевернуть

Определение

request_id размечает запрос в одном контуре, trace_id — сквозной через сервисы. На практике часто одно значение; разница — в договорённости.

1 / 6

Что дальше по курсу#

Корреляция склеила строки — дальше курс чистит ленту: антипаттерны покажут, как записи теряют смысл ещё до сборщика, а урок про прод — что происходит с ними после writer-а. Справочное закрепление: прогоните тестовую цепочку из двух вызовов и найдите обе записи фильтром по trace_id, затем уберите поле из второго сервиса и увидьте, как история распадается; сам тест разметки собирается по рецепту из урока про тесты логов — буфер и разбор карты покажут поле в каждой записи. Проверьте хук: событие без .Ctx(ctx) не должно нести поле. Если стандарта на заголовки в вашей команде нет, напишите его по таблице выше и приложите тест middleware — договорённость, зафиксированная кодом, переживает смену команды.

Песочница урока

Редактируйте код и запускайте его прямо здесь — интерпретатор работает в браузере, ничего устанавливать не нужно. За каждый запуск — +2 XP.

Вывод

Запустите код, чтобы увидеть вывод.

Коротко: что запомнить

trace_id — сквозной идентификатор: рождается у входа, проезжает сервисы в заголовке, пишется полем события.
Приоритет источников: валидный traceparent, затем X-Request-Id, затем crypto/rand — 32 hex-символа.
traceparent: версия 00, trace-id из 32 hex, parent-id из 16, флаги из 2; в лог уезжает trace-id.
Поле приклеивается With-копией на запрос: log.With().Str("trace_id", id).Logger() и WithContext.
UpdateContext на общем логгере не потокобезопасен: под нагрузкой в записях чужие идентификаторы.
Хук срабатывает в Msg до записи: e.GetCtx() достаёт контекст, e.Str дописывает поле.
Ключ trace_id один во всех сервисах; фоновые задачи уносят его в очередь.
Идентификатор возвращается клиенту заголовком — поддержка находит запрос по нему.

Домашнее задание

Соберите middleware корреляции на http.ServeMux: приоритет заголовков, генерация crypto/rand, With-копия в request-контексте, возврат X-Request-Id клиенту. Прогоните curl с готовым traceparent и убедитесь, что в записи уехал именно trace-id, а не вся строка. Пришлите битый traceparent с коротким parent и проверьте фолбэк на X-Request-Id; затем уберите оба заголовка и убедитесь, что поле содержит 32 hex-символа из crypto/rand. Достаньте логгер zerolog.Ctx из вложенной функции и из фоновой горутины — поле обязано быть в обеих записях. Напишите traceHook с GetCtx и добавьте событие без .Ctx(ctx): поле должно исчезнуть, и этот случай стоит увидеть своими глазами. Запустите два конкурентных запроса под go run -race — чистый прогон подтвердит отсутствие UpdateContext. Зафиксируйте приоритет заголовков в README сервиса.

Вопросы и ответы по уроку

Чем trace_id отличается от request_id из урока про HTTP-логи?

Механически — почти ничем: и то и другое строковое поле, приклеенное With-копией на запрос. Разница в масштабе договорённости: request_id обычно живёт в контуре одного сервиса или шлюза, trace_id проезжает границы сервисов в заголовке и рассчитан на сквозную цепочку. Если трейсера нет, одно значение часто выполняет обе роли — важен не термин, а один и тот же ключ поля во всех сервисах цепочки.

Нужна ли библиотека, чтобы распарсить traceparent?

Нет: заголовок — строка фиксированной структуры, и парсера из урока в десять строк достаточно: Split по дефису, проверка четырёх частей, версия 00, длины 32-16-2 и честный hex в trace-id. В ядре zerolog парсера нет — и для поля в логах он не нужен. Полноценная трассировка со спанами и экспортом — уже тема opentelemetry, но это отдельная библиотека, а не часть zerolog.

Как прокидывать trace_id в фоновые задачи?

Идентификатор уезжает вместе с задачей: в аргументе, в структуре задания или в context.Context рядом с логгером из урока про горутины. Воркер собирает свою With-копию с тем же значением и подписывает записи тем же ключом — иначе хвост цепочки потеряется из фильтра. UpdateContext для этого не подходит: он не потокобезопасен и испортит контекст общего логгера.

Термины урока

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