From 3f0d9c102d7acac28817db865dd1218d002a62ba Mon Sep 17 00:00:00 2001 From: "E.Gavrilov" Date: Thu, 3 Sep 2026 22:05:16 +0300 Subject: [PATCH] Rewrite editorial article 264 --- editorial/agent-rewrites/264.json | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/editorial/agent-rewrites/264.json b/editorial/agent-rewrites/264.json index 96d5dbb..038b5e3 100644 --- a/editorial/agent-rewrites/264.json +++ b/editorial/agent-rewrites/264.json @@ -1,7 +1,7 @@ { "index": 264, "slug": "editorial-2020-09-practice-tracing-basics", - "title": "Трассировка запроса: как найти задержку по одному trace", - "excerpt": "Разбираем разорванный trace: как передать trace context через границу сервисов, связать parent и child span, прочитать waterfall и остановиться, если данных недостаточно.", - "contentHtml": "

Сервис отвечает успешно, но один и тот же endpoint то укладывается в 40 миллисекунд, то ждёт почти секунду. В логах есть записи gateway, catalog и inventory. Связать их с одним запросом нельзя: у строк разные идентификаторы, а время запуска не совпадает. Цена ошибки — менять timeout, retry или запрос к базе вслепую. Можно убрать один видимый симптом и оставить настоящую задержку на следующем участке.

\n

Тезис. Трассировка помогает не потому, что добавляет ещё один лог. Она связывает операции в дерево: общий trace-id описывает одну историю, span-id описывает отдельную операцию, а parent-id показывает прямую связь. На транспортной границе сервис должен передать контекст, создать свой span и передать уже его как родителя следующей операции. Если граница не передала контекст, waterfall распадается и вывод о причине задержки становится гипотезой.

\n

Как читать один trace

\n

Представим учебный запрос к каталогу. Gateway принимает HTTP-запрос и создаёт span gateway.handle. Затем он вызывает catalog. Catalog получает trace context, создаёт catalog.lookup с родителем gateway и запускает два дочерних участка: pricing.read и inventory.fetch. Inventory, в свою очередь, вызывает адаптер.

\n

В такой модели один trace содержит пять span. У всех один trace-id. Каждый span имеет собственный span-id. У дочернего span parent-span-id равен идентификатору операции, которая его вызвала. Эта связь важнее красивого имени сервиса: она показывает, кто породил ожидание.

\n
Симптом → причина → проверка → действие
СимптомПричинаПроверкаДействие
Строки лога нельзя собрать в запросКомпоненты создают разные trace-idСравнить trace-id у входящего и исходящего spanПередавать контекст через границу
Child span существует, но parent неизвестенСервис создал span без текущего контекстаПроверить parent-span-id и порядок времениСоздавать child из извлечённого context
Waterfall показывает невозможное перекрытиеСложили вложенные durationПроверить интервалы start/end и вложенностьСчитать critical path, а не сумму всех span
Trace пропал после proxy или очередиCarrier не прошёл через транспортСравнить header до отправки и после полученияПроверить конкретный adapter или carrier
Задержка есть, но причина не виднаНужный участок не создаёт span или не попал в samplingПроверить покрытие, sampling и экспортНе объявлять виновника без следующего сигнала
\n

Контекст передаётся через границу

\n

Внутри одного процесса контекст можно передать аргументом функции или средствами SDK. После HTTP-вызова, сообщения очереди или фоновой задачи получатель сам его не угадает. Для HTTP используется carrier. Один распространённый вариант — W3C traceparent. В версии 00 он содержит version, trace-id, parent-id и trace-flags.

\n
traceparent: 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01\n\n// gateway отправляет свой span как parent:\nconst outgoing = \\`00-\\${traceId}-\\${gatewaySpanId}-01\\`;\n\n// catalog создаёт новый span, но сохраняет traceId:\nconst catalogSpan = {\n  traceId,\n  spanId: '00f067aa0ba902b7',\n  parentSpanId: gatewaySpanId,\n};
\n

Код выше — учебный пример. Он не открывает сеть, не заменяет SDK и не доказывает, что конкретный proxy сохранит заголовок. Его задача — показать два инварианта: trace-id остаётся тем же, а текущий span-id меняется на каждой участвующей границе.

\n

Получатель должен проверить формат до использования. Trace-id и parent-id имеют фиксированную длину и не могут быть нулевыми. Неверный header нельзя принимать как доверенный контекст. Если header отсутствует, сервис начинает новую историю или применяет явно заданную политику. Нельзя молча приписывать запрос к случайному trace.

\n
\"Схема
На границе меняется parent span, но trace-id остаётся общим. Схема показывает контракт передачи, а не выполнение реального запроса.
\n

Waterfall показывает путь, а не сумму строк

\n

Пусть в учебном примере gateway.handle идёт от 0 до 240 миллисекунд, catalog.lookup — от 20 до 220, pricing.read — от 30 до 70, а inventory.fetch — от 30 до 200. Внутри inventory адаптер занимает интервал от 100 до 170 миллисекунд. Эти числа придуманы для объяснения и не являются измерениями production.

\n

Pricing и inventory стартуют одновременно. Поэтому конец запроса определяется веткой inventory, а не суммой 40 и 170 миллисекунд. Время parent включает время дочерних span. Если сложить 240, 200, 40, 170 и 70, получится число, которое не описывает ни задержку запроса, ни critical path. Для анализа нужно найти цепочку зависимых операций и отдельно посмотреть участки parent, которые не закрыли child.

\n
\"Учебный
В учебном waterfall поздно завершающаяся ветка inventory определяет критический путь. Вывод применим только при общей шкале времени и корректных parent-child связях.
\n

Порядок действий

\n
  1. Зафиксируйте симптом. Запишите endpoint, примерный диапазон задержки, код ответа, входные условия и время наблюдения.
  2. Выберите одну историю. Найдите trace конкретного запроса по доступному идентификатору. Не смешивайте записи разных попыток.
  3. Проверьте корень. Убедитесь, что root span имеет начало и конец, а его trace-id не меняется внутри истории.
  4. Проверьте границы. Для каждого HTTP-вызова или сообщения сравните отправленный carrier с полученным. Отметьте место, где связь исчезает.
  5. Проверьте parent. У каждого child должен существовать ожидаемый родитель. Временной интервал child не должен выходить за границу parent без отдельного объяснения.
  6. Постройте критический путь. Отделите последовательные операции от параллельных. Не складывайте вложенные duration.
  7. Назовите следующий сигнал. Если самый длинный span — adapter, проверьте его запрос, очередь или внешний ответ. Один span не доказывает причину внутри себя.
  8. Проверьте отрицательную ветку. Если trace отсутствует, sampling исключил запрос или часы расходятся, остановите вывод и соберите недостающий сигнал.
  9. Сравните повтор. Повторите тот же сценарий с теми же входными условиями и убедитесь, что вывод не зависит от одной удачной истории.
\n

Что трассировка не доказывает

\n

Наличие trace-id не означает, что история полная. Sampling может отбросить запрос. Экспорт может задержаться или завершиться ошибкой. Уровень логирования может скрыть событие. Прокси может удалить заголовок. Очередь может использовать другой carrier. Для каждой границы нужна отдельная проверка.

\n

Трассировка также не показывает автоматически бизнес-причину. Длинный span базы может быть следствием блокировки, плохого плана, холодного соединения или внешнего лимита. Название inventory.fetch не различает эти случаи. Следующий шаг должен читать собственный сигнал участка: план запроса, размер очереди, код внешнего ответа или время подключения.

\n

Не помещайте в trace context пароль, токен, email, полный URL с параметрами или тело запроса. Trace-id служит для связи операций. Доступ к trace и правила хранения должны учитывать, что span attributes часто попадают в журналы и хранилища наблюдаемости.

\n

Проверяемый критерий готовности

\n

Разбор готов, если другой инженер может по одному запросу воспроизвести четыре факта: все нужные span имеют общий trace-id; каждая транспортная граница показывает отправленный и полученный context; parent-child связи согласуются с временем; критический путь объясняет задержку без сложения перекрывающихся интервалов. Для найденного участка существует следующий проверяемый сигнал.

\n

Если хотя бы один факт неизвестен, результатом должна быть запись «причина не доказана» и конкретный следующий fetch, лог или измерение. Это не провал метода. Это правильная граница вывода: trace показывает путь запроса, но не разрешает придумывать отсутствующие данные.

\n

Проверяемые источники

\n" + "title": "Трассировка запроса: как доказать задержку по одному trace", + "excerpt": "Разбираем учебный разрыв trace: как проверить traceparent на границах сервисов, не сложить перекрывающиеся span дважды и выбрать следующий измеримый сигнал.", + "contentHtml": "

После условного выката дежурный инженер получает два одинаковых запроса: один завершился за 40 миллисекунд, другой ждал почти секунду. Gateway, catalog и inventory записали события, но их нельзя уверенно собрать в одну историю: идентификаторы различаются, а времена запуска не совпадают. Это учебный incident, поэтому числа ниже придуманы для проверки метода, а не выданы за замер production.

\n

Первое действие — взять один запрос и сравнить контекст на каждой границе: какой traceparent отправил gateway, что извлёк catalog и какой span стал родителем следующего вызова. Цена ошибки здесь практическая: если сразу увеличить timeout или retry, можно скрыть потерю контекста и перенести задержку дальше. Задача статьи — показать, какие факты trace доказывает, а где нужен следующий сигнал.

\n

Сценарий: один запрос и пять span

\n

Разберём контролируемую схему. Gateway принимает HTTP-запрос и создаёт корневой span gateway.handle. Он вызывает catalog. Catalog создаёт catalog.lookup как дочернюю операцию и параллельно запускает pricing.read и inventory.fetch. Inventory вызывает inventory.adapter. Так получается пять span в одной простой trace-истории.

\n

trace-id идентифицирует всю историю, а span-id — одну операцию. У каждого span может быть не более одного parent в обычном дереве, но дочерних span может быть несколько. Поэтому имя сервиса ещё ничего не доказывает: нужно проверить идентификаторы, parent-child связь и интервалы start/end. Ниже приведены только значения учебной модели.

\n
Симптом → возможная причина → проверка → действие
СимптомВозможная причинаПроверкаДействие
Строки нельзя собрать в один запросНа границе создан новый root или потерян contextСравнить trace-id во входящем и исходящем spanПроверить extract/inject и carrier
Child есть, но parent неизвестенSpan создан без активного ContextСверить parent-span-id и момент созданияСоздавать child из извлечённого Context
Сумма duration намного больше ответаВложенные или параллельные интервалы посчитали повторноСопоставить start/end и перекрытияИскать критический путь, а не сумму строк
Trace обрывается после proxy или очередиCarrier не прошёл через транспорт либо сработал samplingСравнить заголовок до отправки и после полученияПроверить конкретную boundary и полноту выборки
Самый длинный span не объясняет ответОн перекрывается с поздней веткой или слишком широк внутри себяНайти последний end и следующий внутренний сигналПроверить адаптер, очередь или внешний ответ
\n

Контекст на HTTP-границе

\n

Внутри процесса Context можно передать средствами SDK. После HTTP-вызова или сообщения очереди получатель не угадывает его по имени сервиса. Propagator записывает context в carrier, например в HTTP-заголовки, а принимающая сторона извлекает его обратно. Это две разные операции: inject выполняет отправитель, extract — получатель.

\n

В W3C Trace Context заголовок traceparent версии 00 имеет четыре поля: version, trace-id, parent-id и trace-flags. Для trace-id используется 32 строчных шестнадцатеричных символа, для parent-id — 16; нулевые значения недействительны. При некорректном контексте реализация должна его проигнорировать, а решение о новой root-истории принимает политика инструмента.

\n

Порядок для исходящего HTTP-вызова важен. Получив запрос, catalog сначала извлекает remote context и создаёт свой server span как child. Перед вызовом inventory он создаёт span исходящего обращения, обычно client span, делает его текущим и только потом inject-ит его context в новый carrier. Inventory извлекает carrier и создаёт свой server span. Тогда в исходящем заголовке меняется parent-id текущего вызова, а trace-id сохраняется.

\n
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01\n\n// Схема операций SDK, без сетевого вызова:\nconst incoming = propagator.extract(request.headers);\nconst serverSpan = tracer.startSpan('catalog.lookup', { parent: incoming });\nconst outgoing = tracer.startSpan('inventory.fetch', { parent: serverSpan });\npropagator.inject(outgoing.context(), requestToInventory.headers);\n\n// На стороне inventory:\nconst remote = propagator.extract(requestToInventory.headers);\nconst inventorySpan = tracer.startSpan('inventory.server', { parent: remote });
\n

Этот фрагмент показывает последовательность, но не является готовым API для конкретного языка: названия методов у SDK различаются. Он также не обещает, что proxy сохранит заголовок. Для воспроизводимой проверки нужно записать carrier непосредственно перед отправкой и сразу после extract на стороне получателя.

\n
\"Схема
На каждой границе создаётся новый span, но при корректной propagation trace-id остаётся общим. Схема показывает контракт, а не сетевой прогон.
\n

Waterfall: путь запроса, а не сумма строк

\n

В учебной модели root gateway.handle идёт от 0 до 240 мс, catalog.lookup — от 20 до 220, pricing.read — от 30 до 70, а inventory.fetch — от 30 до 200. Внутри inventory адаптер занимает интервал от 100 до 170 мс. Pricing и inventory стартуют одновременно, поэтому их duration перекрываются.

\n

Inclusive duration родителя включает работу children. Если сложить 240, 200, 40, 170 и 70, получится 720 мс, хотя root завершается за 240. Это не задержка запроса. Правильный вопрос другой: какая последовательность интервалов удерживает ответ до конца? В этой модели поздний child catalog — inventory, а pricing остаётся параллельной веткой, не входящей в критический путь после 70 мс.

\n

Для этой простой шкалы критическая цепь раскладывается так: 0–20 мс до catalog, 20–30 мс до его children, 30–100 мс до adapter, 100–170 мс работы adapter, 170–200 мс после adapter, 200–220 мс после children и 220–240 мс до ответа. Сумма этих неперекрывающихся участков равна 240 мс. Это разложение относится к выбранной модели; для асинхронных links, retry и разных часов нужен другой анализ.

\n
\"Учебный
Позднее завершение inventory определяет конец ветки catalog. Вложенный adapter уже входит в interval inventory и не должен добавляться второй раз.
\n

Воспроизводимая проверка интервалов

\n

Ниже — самодостаточный пример для Node.js без внешних пакетов. Он проверяет duration, наличие parent и то, какой child catalog завершился последним. Код не строит полноценный trace backend и не учитывает асинхронные links; его граница намеренно ограничена одной согласованной шкалой.

\n
const spans = [\n  { name: 'gateway.handle', parent: null, start: 0, end: 240 },\n  { name: 'catalog.lookup', parent: 'gateway.handle', start: 20, end: 220 },\n  { name: 'pricing.read', parent: 'catalog.lookup', start: 30, end: 70 },\n  { name: 'inventory.fetch', parent: 'catalog.lookup', start: 30, end: 200 },\n  { name: 'inventory.adapter', parent: 'inventory.fetch', start: 100, end: 170 },\n];\n\nconst byName = new Map(spans.map((span) => [span.name, span]));\nconst duration = (span) => span.end - span.start;\nconst invalid = spans.filter((span) => {\n  const parent = span.parent ? byName.get(span.parent) : null;\n  return parent && (span.start < parent.start || span.end > parent.end);\n});\nconst catalogChildren = spans.filter((span) => span.parent === 'catalog.lookup');\nconst latestChild = catalogChildren.reduce((latest, span) =>\n  span.end > latest.end ? span : latest,\n);\n\nconsole.log({\n  rootDuration: duration(byName.get('gateway.handle')),\n  latestCatalogChild: latestChild.name,\n  latestCatalogChildEnd: latestChild.end,\n  invalidParentRanges: invalid.length,\n});\n// { rootDuration: 240, latestCatalogChild: 'inventory.fetch',\n//   latestCatalogChildEnd: 200, invalidParentRanges: 0 }
\n

Результат подтверждает три локальных факта: root длится 240 мс, inventory завершается позже pricing, каждый child находится внутри parent. Одна шкала — условие входных данных, а не вывод программы. Код не подтверждает, что catalog действительно получил traceparent, что sampling сохранил все span или что задержка внутри adapter вызвана базой. Для последнего вывода нужен собственный сигнал adapter.

\n

Порядок действий

\n
  1. Зафиксируйте симптом. Запишите endpoint, диапазон задержки, код ответа, входные условия и время наблюдения.
  2. Выберите одну историю. Найдите конкретный trace по доступному идентификатору. Не смешивайте повторные попытки и записи разных часов.
  3. Проверьте root. Убедитесь, что корневой span имеет start и end, а sampling и экспорт не скрыли критическую часть.
  4. Проверьте transport boundary. Сравните исходящий carrier с тем, что реально извлёк получатель. Отметьте первую границу, где trace-id исчезает.
  5. Проверьте формат. Для W3C context проверьте version, длины полей, строчные hex-символы и запрет нулевых trace-id и parent-id.
  6. Проверьте parent-child. Сверьте ожидаемого родителя и убедитесь, что child не выходит за его интервал в выбранной модели.
  7. Постройте critical path. Отделите последовательные участки от параллельных. Inclusive duration не складывайте со временем вложенного span.
  8. Назовите следующий сигнал. Для широкого span выберите один fetch: запрос адаптера, размер очереди, внешний код ответа, профиль или источник времени.
  9. Повторите проверку. Повторите тот же сценарий после изменения и отдельно проверьте отрицательный путь: потерянный carrier, sampling или невалидный timestamp.
\n

Границы вывода и безопасность

\n

Trace показывает наблюдаемую структуру и интервалы, но не автоматически бизнес-причину. Длинный span базы может быть следствием блокировки, плохого плана, холодного соединения или внешнего лимита. Если span заканчивается после parent, сначала зафиксируйте противоречие: это может быть раннее закрытие, асинхронная работа или неверно выбранная модель связи.

\n

Обычное дерево плохо описывает fan-out, очередь, retry и работу после ответа. Для операций с несколькими причинными источниками могут понадобиться links, а для разнесённых часов — проверка источника времени и допустимой погрешности. Отсутствие span не доказывает отсутствие работы: запись могла не попасть в sampling, экспорт мог задержаться или instrumentation могла не охватить участок.

\n

Не передавайте в trace context пароль, токен, email, тело запроса или полный URL с параметрами. Trace-id нужен для корреляции, а не для хранения полезной нагрузки. Если следующий сигнал содержит персональные данные, применяйте правила доступа и маскирования вашей системы наблюдаемости.

\n

Критерий готовности

\n

Разбор готов, когда для одного проверочного запроса выполнены четыре условия: записи связаны с root и имеют объяснимые parent-child отношения; на каждой транспортной границе указан фактически отправленный и полученный context; критический путь рассчитан без двойного счёта вложенных и параллельных интервалов; после изменения повторён тот же симптом и отрицательный путь. Если один факт неизвестен, честный результат — «причина пока не доказана» и конкретный следующий fetch.

\n

Проверяемые источники

\n" }