Трассировка OpenTelemetry в 200 строк кода

Разработчики часто воспринимают трассировку как нечто загадочное, и OpenTelemetry — не исключение. Она может казаться еще более сложной из‑за множества новых концепций, с которыми сталкиваешься в базовых примерах.

Ситуация усугубляется тем, что по мере создания стабильной и надежной библиотеки для трассировки сам код усложняется, чтобы учитывать редкие случаи, поддерживать работу в разных окружениях и оптимизировать производительность, минимизируя влияние на приложения. Это особенно заметно при использовании автоматической инструментации, которая может «волшебным образом» оборачивать или изменять код, который изначально для этого не предназначен.

Неудивительно, что многие разработчики воспринимают библиотеки трассировки как «черные ящики». Мы добавляем их в приложения, надеемся на лучшее и полагаемся на них в критические моменты, например, во время инцидентов ночью.

На самом деле, трассировка гораздо проще, чем кажется. Если разобрать её на части, можно представить её как комбинацию «необычного логирования» и «распространения контекста».

Логи

Разработчикам обычно очень комфортно работать с логами. Мы начинаем с «Hello World!» и они остаются с нами на протяжении всей работы. Когда возникает проблема, мы часто прибегаем к логам, добавляя что‑то вроде console.log("potato"), чтобы проверить, выполняется ли код (даже когда отладчик прямо под рукой).

Логи действительно полезны! Однако надеюсь, что кто‑то однажды убедит вас хранить их в формате ключ‑значение для более структурированного и удобного анализа.

If you make one New Year’s resolution related to modernizing your infrastructure and preparing for the brave new world of distributed systems, I suggest this:

Structure your logs.

You won’t be sorry. You will eventually be so, so glad you did.

Just do it.

Неплохо иметь хотя бы какую‑то консистентность в логах: важно убедиться, что у каждого лога одинаковым образом формируется временная метка или присутствует поле «имя» для удобного поиска. Скорее всего, вы уже писали подобные функции в своих проектах:

log("user-authenticated", { userId, remaingingRateLimit });  // ...  function log(name, attributes = {}) {   console.log(     JSON.format({       name,       timestamp: new Date().getTime(),       ...attributes,     })   ); }

{ "timestamp": 1725845013447, "name": "user-authenticated", "userId": "1234", "remaingingRateLimit": 100 }

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

logTiming("query-user-info", () => {   db.fetchUserInfo(); });  // ....  function logTiming(name, attributes = {}, lambda) {   let startTime = new Date().getTime();    // run some subtask   lambda();    let durationMs = new Date().getTime() - startTime;   log(name, { durationMs, ...attributes }); }

{ "timestamp": 1725845013447, "name": "query-user-info", "durationMs": 12 }

Если это так, поздравляю! Вы на полпути к переизобретению trace span.

Span’ы это ✨причудливые✨ логи

Трассировка — это набор span’ов. Пример ниже показывает трассировку с четырьмя различными span:

Span действительно можно рассматривать как набор пар ключ/значение, аналогично строкам в логе, с обязательными полями:

• Имя: Определяет действие или событие, которое span описывает.

• Временная метка: Указывает момент начала span.

• Длительность: Показывает, как долго span длился.

• Набор ID: Сюда входят:

  • Trace ID: Идентификатор всей трассировки, объединяющий все span’ы.

  • Span ID: Уникальный идентификатор конкретного span.

  • Parent Span ID: Идентификатор родительского span (если есть), позволяющий организовать иерархию.

Дополнительно можно добавлять любые атрибуты в виде пар ключ/значение, например:

let span = new Span("api-req"); let resp = await api("get-user-limits"); span.setAttributes({ responseCode: resp.code }); span.End(); console.log(span);  // ...  class Span {   constructor(name, context = {}, attributes = new Map()) {     this.startTime = new Date().getTime();     this.traceID = context.traceID ?? crypto.randomBytes(16).toString("hex");     this.parentSpanID = context.spanID ?? undefined;     this.spanID = crypto.randomBytes(8).toString("hex");     this.name = name;     this.attributes = attributes;   }    setAttributes(keyValues) {     for (let [key, value] of Object.entries(keyValues)) {       this.attributes.set(key, value);     }   }    end() {     this.durationMs = new Date().getTime() - this.startTime;   } }

Вывод span в таком формате мог бы выглядеть следующим образом:

Span {   startTime: 1722436476271,   traceID: 'cfd3fd1ad40f008fea72e06901ff722b',   parentSpanID: undefined,   spanID: '6b65f0c5db08556d',   name: 'api-req',   attributes: Map(0) {     "responseCode": 200   },   durationMs: 3903 }

Запись в логе, соответствующая вышеуказанному span, могла бы выглядеть следующим образом:

{   "startTime": 1722436476271,   "traceID": "cfd3fd1ad40f008fea72e06901ff722b",   "spanID": "6b65f0c5db08556d",   "name": "api-req",   "responseCode": 200,   "durationMs": 3903 }

Trace это набор span’ов

Если вы хотите видеть все логи от определенного запроса, вы, вероятно, делали что‑то похожее:

// generate a request id and inherit one from your platform let requestID = req.headers["X-REQUEST-ID"]; // ... log("api-request-start", { requestID }); let resp = await apiRequest(); log("api-request-end", { requestID });

Что позволило бы искать по ID запроса, чтобы посмотреть, что происходило при его обработке:

{ "timestamp": 1722436476271, "requestID": "1234", "name": "fetch-user-permissions" } { "timestamp": 1722436476321, "requestID": "1234", "name": "api-request-start" } { "timestamp": 1722436476345, "requestID": "1234", "name": "api-request-end" } { "timestamp": 1722436476431, "requestID": "1234", "name": "update-db-record" } { "timestamp": 1722436476462, "requestID": "1234", "name": "create-email-job" }

Выполнение трассировки таким образом может дать весьма неплохой результат! Но мы можем лучше.

У trace span есть 3 разных ID, составляющих контекст трассировки. Первые два просты:

• Span ID: случайный ID для каждого span

• Trace ID: случайный ID, который может быть общим для нескольких span

Последний чуть сложнее:

• Parent Span ID: Span ID активного span’а, когда создавался текущий span

Parent Span ID позволяет системе создать DAG каждой трассировки после получения каждого span. После отрисовки в качестве древа это дает нам отображение в виде водопада, столь знакомое и любимое нами, но также стоит помнить, что это лишь одна из возможных визуализаций данных.

Контекст

Контексту нужно всего 2 значения: trace ID и ID текущего span. При создании нового span мы можем унаследовать span ID, если таковой имеется, создать новый span ID и создать новый контекст.

let context = {   traceID: "cfd3fd1ad40f008fea72e06901ff722b",   spanID: "6b65f0c5db08556d", };

Нам нужен способ передавать контекст в нашем приложении. Мы могли бы делать это вручную:

let { span, newContext } = new Span("api-req", oldContext);

И да, в официальном Go SDK действительно так и делают, но в большинстве других языков это делается неявно и обрабатывается библиотекой автоматически. В Ruby или Python можно использовать локальную для потока переменную, но в Node использовался бы AsyncLocalStorage.

На данном этапе это помогает обернуть создание span в хелпер-функцию:

import { AsyncLocalStorage } from "node:async_hooks";  let asyncLocalStorage = new AsyncLocalStorage(); // start with an empty context asyncLocalStorage.enterWith({ traceID: undefined, spanID: undefined });  async function startSpan(name, lambda) {   let ctx = asyncLocalStorage.getStore();   let span = new Span(name, ctx, new Map());   await asyncLocalStorage.run(span.getContext(), lambda, span);   span.end();   console.log(span); }  startSpan("parent", async (parentSpan) => {   parentSpan.setAttributes({ outerSpan: true });   startSpan("child", async (childSpan) => {     childSpan.setAttributes({ outerSpan: false });   }); });

И теперь у нас есть основа нашей библиотеки трассировки! 🎉

Span {   startTime: 1725850276756,   traceID: 'b8d002c2f6ae1291e0bd29c9791c9756',   parentSpanID: '50f527cbf40230c3',   name: 'child',   attributes: Map(1) { 'outerSpan' => false },   spanID: '8037a93b6ed25c3a',   durationMs: 11.087375000000002 } Span {   startTime: 1725850276744,   traceID: 'b8d002c2f6ae1291e0bd29c9791c9756',   parentSpanID: undefined,   name: 'parent',   attributes: Map(1) { 'outerSpan' => true },   spanID: '50f527cbf40230c3',   durationMs: 26.076625 }

Наша библиотека трассировки вполне жизнеспособна, несмотря на всего 60 строк кода, но у нее есть 2 больших недостатка:

• Нам надо добавлять ее везде вручную.

• Она ограничена одной системой. У нас нет механизма передачи контекста между двумя системами в сервисе.

Давайте исправим это!

Распределяемся

Распределенная трассировка звучит пугающе, но в общем означает, что контекст трассировки может передаваться между системами для того, чтобы отследить, какие операции вызывают другие и как эти данные передаются конечному получателю.

Когда мы выполняем HTTP‑запрос другой системе, нам необходимо передать Trace ID и текущий Span ID. Мы могли бы добавить эти два поля к пэйлоаду HTTP вручную, но существует стандарт W3C для кодирования данной информации в заголовок HTTP, чтобы отправлять его как метаданные для каждого запроса. Заголовок traceparent выглядит следующим образом:

00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01

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

00-{ Trace ID}-{ Parent Span ID }-01

Он позволит нам парсить и сериализовать контекст трассировки с помощью простых функций:

let getTraceParent = (ctx) => `00-${ctx.traceID}-${ctx.spanID}-01`;  let parseTraceParent = (header) => ({   traceID: header.split("-")[1],   spanID: header.split("-")[2], });

Нам необходимо добавить эту информацию в исходящие запросы и парсить её для любого входящего запроса. В этом поможет инструментация.

Оборачиваем штуки в другие штуки

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

Вместо этого мы создадим middleware для фреймворка Hono, который может быть добавлен пользователем вручную.

async function honoMiddleware(c, next) {   // check the incoming request for the traceparent header   // if it exists parse and inherit the trace context   let context = EMPTY_CONTEXT;   if (c.req.header("traceparent")) {     context = parseTraceParent(c.req.header("traceparent"));   }    // set the context and wrap the whole req / res operation in a span   await setContext(context, async () => {     await startSpan(`${c.req.method} ${c.req.path}`, async (span) => {       // Before we let our app handle the request, let's pull some info about       // it off and add it to our trace.       span.setAttributes({         "http.request.method": c.req.method,         "http.request.path": c.req.path,       });        // let our app handle the request       await next();        // Pull information about how our app responded       span.setAttributes({         "http.response.status_code": c.res.status,       });     });   }); }

Также нам нужно обрабатывать исходящие HTTP‑запросы и убедиться, что добавляем заголовок traceparent. У встроенной команды fetch нет такого понятия, как middleware, поэтому мы обернём её вручную, как шаверму из JavaScript. Это не так страшно, особенно по сравнению с тем, как это делается на практике.

// pass the original function into our wrapping logic function patchFetch(originalFetch) {   // return a function with the same signature, but that executes our logic too   return async function patchedFetch(resource, options = {}) {     // generate and add the traceparent header     let ctx = getContext();      if (!options.headers) {       options.headers = {};     }     options.headers["traceparent"] = getTraceParent(ctx);      // run the underlying fetch function, but wrap it in a span and     // pull out some info while we're at it     let resp;     await startSpan("fetch", async (span) => {       span.setAttributes({ "http.url": resource });       resp = await originalFetch(resource, options);       span.setAttributes({ "http.response.status_code": resp.status });     });      // pass along fetch's response. It's like we were never here     return resp;   }; }

Здесь вы сможете найти пример приложения и увидеть нашу трассировку в действии.

Давайте отправим все это в Honeycomb

Мы можем выводить наши span в терминал, но это не самый удобный опыт. Прежде чем переходить к OpenTelemetry, полезно взглянуть на Honeycomb»s Events API. Ранее Honeycomb использовал более простой подход — «просто отправь нам JSON». Сейчас они не рекомендуют этот метод, но его все еще можно применить в рамках нашего проекта.

Полный код экспортера можно найти здесь, но самая интересная часть — это логика формирования пэйлоада.

// literally put all of the data together in one big json blob... like a log line! // and then POST it to their API function spanToHoneycombJSON(span) {   return {     ...Object.fromEntries(globalAttributes),     ...Object.fromEntries(span.attributes),     name: span.name,     trace_id: span.traceID,     span_id: span.spanID,     parent_span_id: span.parentSpanID,     start_time: span.startTime,     duration_ms: span.durationMs,   }; }

Поскольку мы не используем стандартный формат, нам придется вручную указать Honeycomb, какие поля будут отвечать за Trace ID, Span ID и другие ключевые значения в конфигурации датасета. Но это всё, что необходимо для построения водопада трассировки!

Так где же OpenTelemetry?

Итак, у нас есть вычурные логи трассировки, а инструментация и распространение контекста на деле оказываются достаточно простыми. Однако OpenTelemetry действительно может казаться большим и сложным стандартом, особенно если вы видели спецификацию.

Это правда, OpenTelemetry — это крупный проект. Но для наших целей нам нужна только небольшая его часть. При установке SDK OpenTelemetry для выбранного вами языка, этот SDK передает данные с использованием OpenTelemetry Protocol (OTLP). Каждый SDK OpenTelemetry для любого языка использует OTLP. OpenTelemetry Collector — это набор инструментов для получения, отправки и преобразования данных в формате OTLP. Таким образом, OTLP — важная штука.

У OTLP есть собственная спецификация protobuf, которая позволяет сжимать телеметрические данные в бинарное сообщение, совместимое с любой платформой, ОС и архитектурой CPU. Теоретически мы могли бы сгенерировать модуль JavaScript для парсинга и передачи protobuf‑сообщений из .proto‑файлов, но это выглядит как слишком сложная задача.

К счастью, в спецификации protobuf также предусмотрено отображение в формат JSON, и в репозитории спецификаций есть хороший пример, с которого можно начать. Поэтому не будем усложнять.

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

function spanToOTLP(span) {   return {     resourceSpans: [       {         resource: {           attributes: toAttributes(Object.fromEntries(globalAttributes)),         },         scopeSpans: [           {             scope: {               name: "minimal-tracer",               version: "0.0.1",               attributes: [],             },             spans: [               {                 traceId: span.traceID,                 spanId: span.spanID,                 parentSpanId: span.parentSpanID,                 name: span.name,                 startTimeUnixNano: span.startTime * Math.pow(10, 6),                 endTimeUnixNano:                   (span.startTime + span.elapsedMs) * Math.pow(10, 6),                 kind: 2,                 attributes: toAttributes(Object.fromEntries(span.attributes)),               },             ],           },         ],       },     ],   }; }

Но благодаря силе стандартов мы больше не ограничены одним поставщиком услуг. Мы можем отправлять данные любому сервису, поддерживающему OpenTelemetry!

Honeycomb все еще функционирует, разумеется.

И Baseline тоже!

Мы также можем визуализировать телеметрию локально, используя otel-desktop-viewer!

Мы даже можем отрисовывать данные в терминале с помощью otel-tui.

Это все!?

И это все. С помощью 181 строки кода мы реализовали трассировку, распространение контекста, инструментацию и экспортировали в стандартный формат, который может быть обработан любым вендором, поддерживающим его. И все благодаря магии 🌈 стандартов.

А это… вообще… законно?

Если вы пристально следили за процессом, есть большое количество спецификаций OpenTelemetry, описывающих, как OpenTelemetry SDK должен вести себя и быть построен. Наша маленькая библиотека не делает большую часть этого. Она только для обучения, но можно представить упрощенный SDK, не следующий стандарту, например, как этот для Cloudflare Workers. Он отдает OTLP, но не следует всем спецификациям. Как же нам на это смотреть?

Похожий вопрос был задан сооснователю OpenTelemetry Теду Яну во время OTel Community Day в прошлом июне. Я записал его ответ, как мог. Перефразируя:

We don”t care about the spec. We care about that the black box participates in tracing and emits OTLP and semantic conventions. The true spec is the data.

Я это вижу следующим образом: в то время как официальные SDK обязаны следовать спецификации, для других реализаций разумно отходить от стандарта до тех пор, пока внешний наблюдатель не видит разницы в поведении. Наша библиотека не совсем проходит проверку из‑за шорткатов при парсинге заголовка traceparent, но исправление не потребует большого количества кода.

Падажи… почему тогда opentelemetry-js настолько большая?

Если мы можем сделать рабочий трассировщик менее чем за 200 строк, почему в официальном JavaScript SDK настолько больше кода?

В данном случае будет полезно упомянуть часть вещей, которые JavaScript SDK обрабатывает, а наша библиотека — нет:

• Буферизация и группировка исходящей телеметрии в более эффективном формате. Не стоит отправлять по одному span за HTTP‑запрос — вендор телеметрии захочет поговорить.

• Работа и в браузере, и в окружении Node.

• Грамотная обработка ошибок, позволяющая обернуть основной функционал библиотекой.

• Возможность конфигурации. Нужно сделать что‑то, что выходит за рамки простого примера? Скорее всего возможно с использованием SDK.

• Автоматическое оборачивание часто используемых библиотек в проверенную инструментацию.

• Оптимизация производительности при использовании в tight loops.

• Следование семантическим конвенциям.

• Поддержка еще двух типов телеметрии: логирования и метрик.

И так далее! Надеюсь, эта статья помогла вам начать чуть лучше понимать, как много работы уходит на усиление и расширяемость, которые наслаиваются на подобные библиотеки, когда они используются в реальных проектах. Создание библиотеки, которая может стабильно работать во всех местах, куда мы деплоим JavaScript, и поддерживать весь функционал, требуемый широкому спектру пользователей, крайне нетривиально.

Но трассировка? Мы же знаем, что это просто ✨ причудливое логирование ✨, не так ли?

Весь код, используемый для данной статьи, вы можете найти в репозитории jmorrell/minimal‑nodejs‑otel‑tracer на GitHub.