Распределённая трассировка с помощью Jaeger

Частая проблема при разработке распределённых систем состоит в следующем. Предположим, вы отправили системе запрос, и этот запрос обрабатывается очень долго. При этом внутри системы он распадается на запросы к нескольким внутренним микросервисам, которые могут превратиться в несколько подзапросов и выполняться параллельно. Как в этом случае определить, что тормозит систему? На помощь приходит Jaeger — сервис для сбора и отображения трейсов в распределённых системах.

Что такое распределённая трассировка и зачем она нужна

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

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

Кажется, что достаточно создать отдельный лог-сервис, который будет записывать запросы для каждой службы. Но когда API обрабатывает сотни запросов в секунду, откуда вы знаете, что один запрос лога в сервисе A соответствует логу в сервисе B и так далее?

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

Как работает трассировка

Разберём на примере Даши-путешественница, которой дали задание добраться до замка из песка из дома на дереве. Вот карта:

Чтобы добраться до замка из песка, нужно пройти через лес, пересечь озеро и преодолеть пирамиду. Только после этого Даша окажется в замке. Каждое препятствие, встречающееся на пути, занимает время. Вы хотите знать, сколько всего времени требуется, чтобы преодолеть дистанцию от домика на дереве до замка из песка. Это просто — нужно зафиксировать время перед отъездом и по прибытию.

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

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

Let’s coding!

Перенесём путешествие Даши в код и проанализируем, что она делает на каждом препятствии. Для начала нам нужно создать 4 функции:

func startTheJourneyFromTreeHouse(parent context.Context, param int64) (out int64, err error) { span, ctx := opentracing.StartSpanFromContext(parent, "startTheJourneyFromTreeHouse") defer func() { ctx.Done() span.Finish() }()  time.Sleep(2 * time.Millisecond) span.SetTag("message", "prepare some food")  out = param + 2 return }  func passTheForest(parent context.Context, param int64) (out int64, err error) { span, ctx := opentracing.StartSpanFromContext(parent, "passTheForest") defer func() { ctx.Done() span.Finish() }()  time.Sleep(5 * time.Millisecond) span.SetTag("message", "oh it's a long forest and I'm getting tired now!")  out = param + 5 return }  func crossTheLake(parent context.Context, param int64, isRainyDay bool) (out int64, err error) { span, ctx := opentracing.StartSpanFromContext(parent, "crossTheLake") defer func() { ctx.Done() span.Finish() }()  time.Sleep(10 * time.Millisecond) out = param + 10  if isRainyDay { time.Sleep(20 * time.Millisecond) span.SetTag("message", "It's a rainy day and "+ "I must extra careful since I don't want my boat drowned with me") } else { span.SetTag("message", "Clear weather and I enjoy the view from the lake!") }  span.SetTag("isRainyDay", isRainyDay)  return }  func enterThePyramid(parent context.Context, param int64) (out int64, err error) { span, ctx := opentracing.StartSpanFromContext(parent, "enterThePyramid") defer func() { ctx.Done() span.Finish() }()  time.Sleep(10 * time.Millisecond) out = param + 10  span.SetTag("message", "Whoa, everywhere's dark!") return }

startTheJourneyFromTreeHouse — Даша готовит еду своего путешествия;
passTheForest — Даша гуляет с обезьяной Бутом по лесу;
crossTheLake — Даша пересекает озеро. Здесь мы добавим условие: если день дождливый, то процесс будет медленнее. Это условие также показывает, что трассировка позволяет точно определить, где произошло замедление процесса;
enterThePyramid — Даша входит в пирамиду и выходит из темной комнаты внутри пирамиды.

В первом аргументе каждой функции всегда есть параметр context. На его основе вы создаёте интервал, используя opentracing.StartSpanFromContext. Каждый интервал представляет собой функциональный процесс и должен завершаться с использованием отложенной функции. В context есть информация о трассировке, поэтому при вызове функции passTheForest он будет содержать информацию из предыдущего вызова функции startTheJourneyFromTreeHouse.

Вызов функции будет выполнен следующим образом:

serverSpan := eCtx.Get("serverSpan").(opentracing.Span) ctx := opentracing.ContextWithSpan(    context.Background(),    serverSpan, ) defer ctx.Done() ... out, _ = startTheJourneyFromTreeHouse(ctx, in) out, _ = passTheForest(ctx, out) out, _ = crossTheLake(ctx, out, isRainyDay) out, _ = enterThePyramid(ctx, out)

Переменная serverSpan — значение, которое уже задано в traceMiddleware. Оно содержит родительский интервал, который обертывает весь интервал вызовов функций:

spanCtx, _ := opentracing.GlobalTracer().Extract(    opentracing.HTTPHeaders,    opentracing.HTTPHeadersCarrier(req.Header), ) serverSpan := opentracing.StartSpan(    c.Request().URL.Path,    ext.RPCServerOption(spanCtx), )  c.Set("serverSpan", serverSpan)

Каждый раз, когда вы вызываете функцию, она несет информацию из предыдущего вызова функции. И вы получаете трассировку стека (которая визуализируется с помощью интервала), которая выглядит следующим образом:

В каждом интервале вы записываете информацию и можете увидеть подробности, развернув его:

Самый длинный процесс — функция crossTheLake с параметром is_rainy_day true. Чтобы убедиться, что это не аномалия, вы можете попробовать найти другую трассировку в той же конечной точке. С помощью этой подсказки вы можете попытаться оптимизировать функцию, не угадывая, как провидец, а опираясь на данные.

Заключительные слова

При высоком трафике довольно сложно определить точную проблему в серверной части. Свести к минимуму трудности, связанные с поиском узких мест, помогает трассировка. Она работает путём конвейерной передачи информации с использованием context и отправки этой информации с использованием UDP в Jaeger.