Распределенная трассировка в Go при помощи Jaeger
20 февраля 2019
Типичная проблема, возникающая при разработке распределенных систем, состоит в следующем. Допустим, пользователь посылает системе запрос, и запрос этот обрабатывался очень долго. При этом внутри системы запрос распался на запросы к нескольким внутренним микросервисам, которые в свою очередь могли также превратиться в несколько подзапросов, возможно, даже выполняемых параллельно. Как в такой ситуации выяснить, где тормозит система? Метрики не дают ответа на данный вопрос, поскольку в целом вся система работает нормально, затупил только отдельный запрос конкретного пользователя. Логи могут дать ответ, но они разбросаны по множеству машин, время на которых не синхронизировано. На помощь приходит Jaeger.
Jaeger (читается «егерь») представляет собой сервис для сбора и отображения трейсов в распределенных системах. В рамках этого поста мы не будем рассматривать установку и настройку Jaeger. Во-первых, потому что получится пересказ документации, а во-вторых, потому что вариантов настройки несколько. Например, в качестве бэкенда для хранения данных может быть использована Cassandra или ElasticSearch.
Вместо этого мы запустим Jaeger в Docker-контейнере:
-p 6831:6831/udp -p 16686:16686 jaegertracing/all-in-one:1.8
При этом Jaeger будет хранить данные в памяти. После остановки контейнера они будут утеряны. В принципе, если вас такой вариант устраивает, данный контейнер можно запустить и в бою:
-p 6831:6831/udp -p 16686:16686 jaegertracing/all-in-one:1.8
Теперь напишем небольшое приложение на языке Go, отправляющее трейсы в Jaeger. В качестве клиентской библиотеки воспользуемся OpenCensus. Начнем с небольшой вспомогательной процедуры:
import (
"go.opencensus.io/exporter/jaeger"
"go.opencensus.io/trace"
)
func InitJaeger(serviceName string) {
exporter, err := jaeger.NewExporter(jaeger.Options{
AgentEndpoint: "localhost:6831",
Process: jaeger.Process{
ServiceName: serviceName,
Tags: []jaeger.Tag{
jaeger.StringTag("hostname", "localhost"),
},
},
})
if err != nil {
return
}
trace.RegisterExporter(exporter)
trace.ApplyConfig(trace.Config{
DefaultSampler: trace.AlwaysSample(),
})
}
Здесь мы указываем имя нашего приложения, где искать Jaeger, кое-какие дополнительные тэги, и говорим слать трейсы вообще всегда (trace.AlwaysSample()). Кстати, трейсы отправляются по UDP.
Демонстрационное приложение будет состоять из двух частей — HTTP-клиента и HTTP-сервера. При этом клиент как-то должен сообщить серверу, в каком контексте происходит обращение к нему. В общем, чтобы в итоге Jaeger увидел один трейс, несмотря на то, что выполнение кода происходит в двух совершенно независимых программах.
Код клиента:
import (
"context"
"encoding/json"
"fmt"
"io/ioutil"
"log"
"net/http"
"time"
"go.opencensus.io/trace"
"github.com/afiskon/golang-jaeger-example"
)
func main() {
utils.InitJaeger("client")
for {
ctx, span := trace.StartSpan(context.Background(), "main")
span.AddAttributes(
trace.StringAttribute("method", "POST"),
)
log.Printf("TraceId: %s\n", span.SpanContext().TraceID.String())
resp, err := sendPostRequest(ctx,
"http://localhost:8080/api/v1/ping")
if err != nil {
log.Printf("sendPostRequest: %v\n", err)
}
fmt.Printf("Response: %s\n", resp)
span.End()
time.Sleep(5 * time.Second)
}
}
func sendPostRequest(ctx context.Context, url string) (string, error) {
_ /* ctx2 */, span := trace.StartSpan(ctx, "sendPostRequest")
defer span.End()
spanContextJson, err := json.Marshal(span.SpanContext())
if err != nil {
return "", err
}
req, err := http.NewRequest("POST", url, nil)
if err != nil {
return "", err
}
req.Header.Add("X-Span-Context", string(spanContextJson))
client := http.Client{}
resp, err := client.Do(req)
if err != nil {
return "", err
}
defer resp.Body.Close()
bytes, err := ioutil.ReadAll(resp.Body)
if err != nil {
return "", err
}
return string(bytes), nil
}
Код сервера:
import (
"context"
"encoding/json"
"flag"
"net/http"
"go.opencensus.io/trace"
"github.com/gorilla/mux"
"github.com/sirupsen/logrus"
"github.com/afiskon/golang-jaeger-example"
)
func PostHandler(w http.ResponseWriter, r *http.Request) {
spanContextJson := r.Header.Get("X-Span-Context")
var spanContext trace.SpanContext
err := json.Unmarshal([]byte(spanContextJson), &spanContext)
if err != nil {
logrus.Errorf("PostHandler, json.Unmarshal: %v\n", err)
return
}
_ /* ctx2 */, span := trace.StartSpanWithRemoteParent(
context.Background(), "PostHandler", spanContext)
defer span.End()
logrus.Debugf("PostHandler called, traceId = %s\n",
span.SpanContext().TraceID.String())
h := w.Header()
h.Set("Content-Type", "text/html")
w.WriteHeader(200)
_, err = w.Write([]byte("<h1>PONG</h1>\n"))
if err != nil {
logrus.Errorf("PostHandler, w.Write: %v\n", err)
}
}
var listenAddr string
func main() {
flag.StringVar(&listenAddr, "listen", ":8080",
"Listen address")
flag.Parse()
logrus.SetLevel(logrus.DebugLevel)
utils.InitJaeger("serer")
logrus.Infof("Starting HTTP server at %s...",
listenAddr)
r := mux.NewRouter().
PathPrefix("/api/v1").
Path("/ping").
Subrouter()
r.Methods("POST").
HandlerFunc(PostHandler)
http.Handle("/", r)
err := http.ListenAndServe(listenAddr, nil)
if err != nil {
logrus.Fatalf("http.ListenAndServe: %v\n", err)
}
logrus.Info("HTTP server terminated\n")
}
В принципе, все сводится к созданию span’ов и своевременному вызову span.End():
defer span.End()
Тут главное не запутаться в Context’ах. Когда StartSpan возвращает вам новый контекст (ctx2), вложенные span’ы должны использовать этот контекст, а не родительский (ctx1). Иначе нарушится вложенность span’ов и в Jaeger мы увидим ерунду.
К span’у можно прикрепить дополнительную информацию:
span.AddAttributes(
trace.StringAttribute("method", "POST"),
)
Она также будет видна в Jaeger. TraceId можно как-то передать пользователю или записать в лог:
По TraceId в Jaeger можно найти полную трассировку запроса.
Наконец, чтобы обращения к разным сервисам объединялись в один трейс, используются SpanContext’ы:
spanContextJson, err := json.Marshal(span.SpanContext())
// на сервере:
err := json.Unmarshal(spanContextJson, &spanContext)
if err != nil {
// ололо...
}
ctx2, span := trace.StartSpanWithRemoteParent(
context.Background(), "PostHandler", spanContext)
В приведенном примере SpanContext сериализуется в JSON и передается через HTTP-заголовок. Само собой разумеется, передавать его можно любым другим способом.
Трейсы в Jaeger выглядят приблизительно так:
Получается очень наглядно. Сразу видно, где и сколько времени проводил запрос, какие его куски и где выполнялись в параллель, и так далее. Воспринимать информацию в таком виде на порядок проще, чем грепать логи.
Полную версию исходников к посту вы найдете здесь. Как всегда, буду рад вашим вопросам и дополнениям.
Дополнение: Агрегация логов в распределенных системах с Go и Loki
Метки: Go, Оптимизация.
Вы можете прислать свой комментарий мне на почту, или воспользоваться комментариями в Telegram-группе.