BatSchool · История одного письма: трассы

Журнал из урока 98 отвечает на вопрос «что случилось». Записи хорошие: уровень, текст, пометки. Но каждая запись это точка во времени. Письмо же это путь: окошко, проверка адреса, книга башен, книги Почтамта, выдача. Чтобы понять, где письмо застряло, нужны не точки, а отрезки, вложенные друг в друга. Это и есть трасса.

Путевой лист письма

На старой почте к посылке привязывали путевой лист. Каждая станция писала в нём две вещи: когда посылка пришла и когда ушла. Если посылка пропала, по листу видно последнюю станцию, которая её видела, и сколько посылка там пролежала.

В Effect одна строчка такого листа называется спан. У спана есть имя (TowerBook.lookup), время начала и конца, атрибуты (tower: 'T-5') и родитель: спан, внутри которого он начался. Все спаны одного письма складываются в дерево, и это дерево называется трасса.

import { Effect } from 'effect';

const askBook = (code: string) =>
  Effect.sleep('2 seconds').pipe(Effect.withSpan('TowerBook.lookup', { attributes: { tower: code } }));

const sendLetter = (letter: number, to: string) =>
  Effect.gen(function* () {
    yield* askBook(to);
    yield* Effect.sleep('10 millis');
  }).pipe(Effect.withSpan('letters.send', { attributes: { letter } }));

Effect.withSpan(имя, { attributes }) оборачивает эффект в спан: спан начинается, когда эффект запустили, и кончается, когда эффект закончился, успехом или провалом. Родителя указывать не нужно. Спан TowerBook.lookup начался внутри letters.send, и Effect сам запишет letters.send ему в родители: текущий спан лежит в контексте файбера, как сервисы из урока 47.

Трасса этого письма выглядит так:

letters.send       letter=7         ████████████████████  2.01 s
  TowerBook.lookup tower=T-5        ███████████████████   2.00 s

Две секунды из двух с лишним письмо ждало книгу. Журнал этого не показывал, трасса показывает с первого взгляда.

Имя функции это имя спана

В уроке 38 Effect.fn('имя') давал функции имя для стека ошибок. Оно же становится именем спана: каждый вызов такой функции открывает свой спан.

import { Effect, Result } from 'effect';

export const checkTowers = Effect.fn('checkTowers')(function* (
  book: TowerBook['Service'],
  codes: ReadonlyArray<string>,
): Effect.fn.Return<ReadonlyArray<Result.Result<TowerInfo, TowerBookError>>> {
  yield* Effect.annotateCurrentSpan('towers', codes.length);
  return yield* Effect.forEach(codes, (code) => Effect.result(book.lookup(code)), { concurrency: 3 });
});

Это утренняя сверка Почтамта: спросить книгу про список башен, по три разом. Effect.annotateCurrentSpan(ключ, значение) пишет атрибут в текущий спан, здесь в спан checkTowers: сколько башен сверяли. Атрибут из withSpan известен до начала, а annotateCurrentSpan пишут по ходу, когда значение стало известно.

Effect.result из урока 42 превращает беду одной башни в значение, и сверка не падает из-за T-9, которой нет. В трассе беда всё равно видна: спан книги про T-9 кончится провалом.

Покрути трассу сам. В виджете две готовые трассы: письмо номер семь и утренняя сверка пяти башен, где T-9 отказывает сразу. Переключатель меняет у checkTowers concurrency с 1 на 3, и полосы вопросов к книге из лесенки становятся параллельными.

Книга в трассе

Как и журнал, трасса книги башен делается обёрткой, без правки сервиса из урока 90:

export const tracedBook = (book: TowerBook['Service']): TowerBook['Service'] => ({
  lookup: (code) =>
    book.lookup(code).pipe(
      Effect.tap((tower) => Effect.annotateCurrentSpan('tower.open', tower.open)),
      Effect.withSpan('TowerBook.lookup', { attributes: { tower: code } }),
    ),
});

Порядок важен: annotateCurrentSpan стоит внутри withSpan, поэтому пишет в спан книги. Если поставить Effect.tap после withSpan, атрибут уйдёт в спан выше, в окошко или в сверку. Ответ книги ложится атрибутом tower.open, беда закрывает спан провалом: у спана, который кончился ошибкой, атрибута ответа нет, есть причина.

Трасса в тесте

Кто собирает спаны? Сервис Tracer.Tracer. По умолчанию он ничего не хранит. В проде его заменяют слоем, который отправляет спаны в сборщик, а в тесте трассировщиком в памяти:

import { Tracer } from 'effect';

const spans: Tracer.NativeSpan[] = [];
const memoryTracer = Tracer.make({
  span(options) {
    const span = new Tracer.NativeSpan(options);
    spans.push(span);
    return span;
  },
});

const traced = Effect.provideService(checkTowers(book, ['T-2', 'T-9']), Tracer.Tracer, memoryTracer);

Tracer.make просит одну функцию: сделать спан по описанию. Tracer.NativeSpan это готовый спан Effect, который запоминает имя, атрибуты в Map, родителя в Option и статус. После запуска в массиве лежат все спаны сверки: у checkTowers атрибут towers: 2 и родителя нет, у двух TowerBook.lookup родитель checkTowers, и у спана T-9 статус Ended с exit провала.

В проде спаны уходят по протоколу OTLP в сборщик, где их рисуют такими же лентами, как в виджете. Для этого в Effect есть модуль effect/observability со слоем Otlp.layer: код Почтамта не меняется, меняется только слой трассировщика. Модуль в 4.1 помечен @stability unstable, поэтому в этом курсе трассы проверяются в памяти.

Под капотом

Пондер Стиб · единственный, кто понимает Гекс

Спан это запись с родителем. Текущий спан лежит в контексте файбера по ключу Tracer.ParentSpan. withSpan создаёт новый спан, указывает ему родителем текущий и запускает эффект с новым спаном в контексте. Дочерние файберы получают контекст родителя, поэтому три вопроса к книге из forEach с concurrency: 3 все повиснут под checkTowers, хотя бегут в разных файберах. Для трассы файберы не важны: важно, внутри чего запустили.

Где тут дыра

const night = (letters: ReadonlyArray<NewLetter>) =>
  Effect.forEach(letters, (letter) => send(letter), { concurrency: 10 }).pipe(Effect.withSpan('ночь'));

На его примере трасса есть: один спан ночь, двенадцать часов. Ночь тихая, писем двадцать, и всё дошло. Теперь соседний пример, ночь открытия: три тысячи писем, и письмо номер семь застряло. Где? В трассе одна полоса на двенадцать часов, внутри пусто: у отправки письма своего спана нет, у книги тоже. Длительность ночи это не история письма. Спан ставят на ту единицу работы, о которой потом спросят: на письмо, на вопрос к книге, на запрос к базе. Тогда под спаном ночи лягут три тысячи писем, и письмо номер семь найдётся по атрибуту letter.

Почтамт, этап 9

Почтамт учится рассказывать историю письма. Новый модуль src/trace.ts: книга башен в трассе и утренняя сверка. Тесты собирают спаны трассировщиком в памяти, сверяют имена, атрибуты, родителей и статус, а время двигают TestClock: четыре башни по три разом сверяются за две секунды, а не за четыре.

EF-99-1★

Нарисуй трассу checkTowers(tracedBook(book), ['T-2', 'T-9', 'T-3', 'T-4']), если каждая башня отвечает через секунду, а T-9 сразу отказом. Сколько спанов, у кого какой родитель, какой атрибут у каждого и сколько длится checkTowers? Сначала ответь, потом проверь в виджете и на тестах этапа.

EF-99-2★★

В tracedBook поменяй местами Effect.tap и Effect.withSpan. Что станет с атрибутом tower.open в трассе сверки? Почему тип функции при этом не изменится и компилятор промолчит?

Практика

Глубже в архиве

Как трассы и метрики снимают с приложения на Node без Effect, через OpenTelemetry, разобрано в уроке про производительность и телеметрию раздела про Node.

Дальше

Лента письма номер семь лежит на столе Патриция. Ветрин читает её молча, до конца, и откладывает.

Ответ в числах ждёт в следующем уроке.