以下の内容はhttps://kmuto.hatenablog.com/entry/2025/04/14/093000より取得しました。


分散トレーシングにおけるサービス間のトレースのつながりの仕組みを試していた

分散型サービスにおいて、別物である呼び出し側と呼び出され側でどう1つのOpenTelemetryトレースとしてまとめているんだろう、と調べると、Traceparentヘッダなるものを渡しているらしい。実際ヘッダくらいしかやりとりできるものはないので、それ自体は理解できる。

OpenTelemetry SDKを使ってコンテキストを受け渡し処理するようにしていればだいたい気にしなくてよいっぽいのだが、実際生データとしてはどういう感じなのか、Goで試してみた。Goを選んだために無駄につまずいた気がしなくもないが、まぁこれも経験である。

サービスの呼び出し側としてhello-client、呼び出され側としてhello-server、生データヘッダを見るためのproxyの3つのGoコードを用意した(ChatGPTがおおむね用意してくれた)。

hello-serverはポート8082、proxyはポート8081で動き、proxyはリクエストを8082に転送する。hello-clientからhttp://localhost:8081/helloにリクエストすることで、proxyを経由してhello-serverからレスポンスを受け取る。hello-server・hello-clientにトレース計装する。

まずcmd/hello-server/main.go。

package main

import (
    "context"
    "encoding/json"
    "log"
    "net/http"

    "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp"
    "go.opentelemetry.io/otel/propagation"
    "go.opentelemetry.io/otel/sdk/resource"
    sdktrace "go.opentelemetry.io/otel/sdk/trace"
    semconv "go.opentelemetry.io/otel/semconv/v1.24.0"
)

func initTracer() func() {
    otel.SetTextMapPropagator(propagation.TraceContext{})
    ctx := context.Background()
    exporter, err := otlptracehttp.New(ctx)
    if err != nil {
        log.Fatal(err)
    }

    tp := sdktrace.NewTracerProvider(
        sdktrace.WithBatcher(exporter),
        sdktrace.WithResource(resource.NewWithAttributes(
            semconv.SchemaURL,
            semconv.ServiceName("hello-server"),
        )),
    )

    otel.SetTracerProvider(tp)

    // シャットダウン関数
    return func() {
        if err := tp.Shutdown(context.Background()); err != nil {
            log.Fatalf("error shutting down tracer provider: %v", err)
        }
    }
}

func helloHandler(w http.ResponseWriter, r *http.Request) {
    w.Header().Set("Content-Type", "application/json")
    w.WriteHeader(http.StatusOK)

    resp := map[string]string{"message": "Hello"}
    if err := json.NewEncoder(w).Encode(resp); err != nil {
        log.Printf("Failed to write response: %v", err)
    }
}

func main() {
    shutdown := initTracer()
    defer shutdown()

    // ミドルウェアで OpenTelemetry を組み込んだハンドラ
    helloWithTracing := otelhttp.NewHandler(http.HandlerFunc(helloHandler), "GET /hello")

    http.Handle("/hello", helloWithTracing)

    log.Println("Listening on :8082")
    log.Fatal(http.ListenAndServe(":8082", nil))
}

次にcmd/hello-client/main.go。

package main

import (
    "context"
    "fmt"
    "io"
    "log"
    "net/http"

    "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp"
    "go.opentelemetry.io/otel/propagation"
    "go.opentelemetry.io/otel/sdk/resource"
    sdktrace "go.opentelemetry.io/otel/sdk/trace"
    semconv "go.opentelemetry.io/otel/semconv/v1.24.0"
)

func initTracer() func() {
    otel.SetTextMapPropagator(propagation.TraceContext{})
    ctx := context.Background()
    exporter, err := otlptracehttp.New(ctx)
    if err != nil {
        log.Fatal(err)
    }

    tp := sdktrace.NewTracerProvider(
        sdktrace.WithBatcher(exporter),
        sdktrace.WithResource(resource.NewWithAttributes(
            semconv.SchemaURL,
            semconv.ServiceName("hello-client"),
        )),
    )

    otel.SetTracerProvider(tp)

    // 終了処理用
    return func() {
        if err := tp.Shutdown(context.Background()); err != nil {
            log.Fatalf("Error shutting down tracer provider: %v", err)
        }
    }
}

func hello(ctx context.Context) error {
    tr := otel.Tracer("example/hello")
    ctx, span := tr.Start(ctx, "hello")
    defer span.End()

    client := http.Client{
        Transport: otelhttp.NewTransport(http.DefaultTransport),
    }
    req, err := http.NewRequestWithContext(ctx, http.MethodGet, "http://localhost:8081/hello", nil)
    if err != nil {
        return err
    }
    resp, err := client.Do(req)
    if err != nil {
        return err
    }
    defer resp.Body.Close()

    body, _ := io.ReadAll(resp.Body)
    fmt.Printf("Response: %s\n", body)

    return nil
}

func main() {
    shutdown := initTracer()
    defer shutdown()

    ctx := context.Background()
    if err := hello(ctx); err != nil {
        log.Fatalf("error in hello(): %v", err)
    }
}

最後にcmd/proxy/main.go。

package main

import (
    "io"
    "log"
    "net/http"
)

func main() {
    handler := func(w http.ResponseWriter, req *http.Request) {
        // 転送先URLを作成
        targetURL := "http://localhost:8082" + req.RequestURI

        // 新しいリクエストを作成(コンテキスト付きで)
        proxyReq, err := http.NewRequestWithContext(req.Context(), req.Method, targetURL, req.Body)
        if err != nil {
            http.Error(w, "Failed to create request", http.StatusInternalServerError)
            return
        }

        // リクエストヘッダを転送
        proxyReq.Header = req.Header.Clone()

        // ログにヘッダ出力
        log.Println("=== Request Headers ===")
        for k, v := range req.Header {
            log.Printf("%s: %v\n", k, v)
        }

        // リクエスト送信
        client := http.DefaultClient
        resp, err := client.Do(proxyReq)
        if err != nil {
            http.Error(w, "Request failed", http.StatusBadGateway)
            return
        }
        defer resp.Body.Close()

        // レスポンスヘッダを転送
        for k, vv := range resp.Header {
            for _, v := range vv {
                w.Header().Add(k, v)
            }
        }
        w.WriteHeader(resp.StatusCode)

        // レスポンスボディをコピー
        io.Copy(w, resp.Body)

        // ログにレスポンスヘッダ出力
        log.Println("=== Response Headers ===")
        for k, v := range resp.Header {
            log.Printf("%s: %v\n", k, v)
        }
    }

    log.Println("Proxy listening on :8081")
    http.HandleFunc("/", handler)
    log.Fatal(http.ListenAndServe(":8081", nil))
}

3つ別々のシェルで起動する。

go run cmd/hello-server/main.go
go run cmd/proxy/main.go
go run cmd/hello-client/main.go

プロキシを見ると、いかにもなTraceparentヘッダが入っている。

2025/04/13 18:38:28 Proxy listening on :8081
2025/04/13 18:38:48 === Request Headers ===
2025/04/13 18:38:48 Traceparent: [00-4c6df8f7447f495da12ba543c268b60c-b2b5e5479b9395ab-01]
2025/04/13 18:38:48 Accept-Encoding: [gzip]
2025/04/13 18:38:48 User-Agent: [Go-http-client/1.1]
2025/04/13 18:38:48 === Response Headers ===
2025/04/13 18:38:48 Content-Type: [application/json]
2025/04/13 18:38:48 Date: [Sun, 13 Apr 2025 09:38:48 GMT]
2025/04/13 18:38:48 Content-Length: [20]

OpenTelemetry Collector debugログを見てみる。

ScopeSpans #0
ScopeSpans SchemaURL: 
InstrumentationScope go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp 0.60.0
Span #0
    Trace ID       : f9d525847eb9a03b71e4f140a3901662
    Parent ID      : 528cb7b748d60148
    ID             : 6dbac0a5bd6765d2
    Name           : HTTP GET
    Kind           : Client
    Start time     : 2025-04-13 09:41:28.632662218 +0000 UTC
    End time       : 2025-04-13 09:41:28.633930651 +0000 UTC
    Status code    : Unset
    Status message : 
Attributes:
     -> http.method: Str(GET)
     -> http.url: Str(http://localhost:8081/hello)
     -> net.peer.name: Str(localhost)
     -> net.peer.port: Int(8081)
     -> http.status_code: Int(200)
     -> http.response_content_length: Int(20)
ScopeSpans #1
ScopeSpans SchemaURL: 
InstrumentationScope example/hello 
Span #0
    Trace ID       : f9d525847eb9a03b71e4f140a3901662
    Parent ID      : 
    ID             : 528cb7b748d60148
    Name           : hello
    Kind           : Internal
    Start time     : 2025-04-13 09:41:28.632648354 +0000 UTC
    End time       : 2025-04-13 09:41:28.633938238 +0000 UTC
    Status code    : Unset
    Status message : 
    {"kind": "exporter", "data_type": "traces", "name": "debug"}
2025-04-13T18:41:30.098+0900    info    Traces  {"kind": "exporter", "data_type": "traces", "name": "debug", "resource spans": 1, "spans": 1}
2025-04-13T18:41:30.098+0900    info    ResourceSpans #0
Resource SchemaURL: https://opentelemetry.io/schemas/1.24.0
Resource attributes:
     -> service.name: Str(hello-server)
     -> service.namespace: Str(kmuto/trace-test)
ScopeSpans #0
ScopeSpans SchemaURL: 
InstrumentationScope go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp 0.60.0
Span #0
    Trace ID       : f9d525847eb9a03b71e4f140a3901662
    Parent ID      : 6dbac0a5bd6765d2
    ID             : 662b17dcac6fe2fc
    Name           : GET /hello
    Kind           : Server
    Start time     : 2025-04-13 09:41:28.633705134 +0000 UTC
    End time       : 2025-04-13 09:41:28.633738659 +0000 UTC
    Status code    : Unset
    Status message : 
Attributes:
     -> http.method: Str(GET)
     -> http.scheme: Str(http)
     -> net.host.name: Str(localhost)
     -> net.host.port: Int(8082)
     -> net.sock.peer.addr: Str(::1)
     -> net.sock.peer.port: Int(36344)
     -> user_agent.original: Str(Go-http-client/1.1)
     -> http.target: Str(/hello)
     -> net.protocol.version: Str(1.1)
     -> http.response_content_length: Int(20)
     -> http.status_code: Int(200)
    {"kind": "exporter", "data_type": "traces", "name": "debug"}

Traceparentヘッダが00-4c6df8f7447f495da12ba543c268b60c-b2b5e5479b9395ab-01なので、「00-トレースID-呼び出し元スパンID-01」というのが渡っているということか。W3C Trace Context仕様らしい。00はバージョンで現在は00固定。後ろの01はトレースフラグで現在は1ビットだけが定義(00はサンプリングされていない・01はサンプリングされているらしい。サンプリングしてないわけだが…)。

(※追記:mrasu先生から「トレースを送ることがサンプリングする だよ。GoだとAlwaysSample()とNeverSample()が用意されていてデフォルトはAlways」とご指摘いただきました。なるほど〜1つ賢くなった!)

Mackerelにも送ってみて、hello-clientのトレースにhello-serverのスパンが入っていることを確認。やったね。

実はしばらく別々のまま全然つながってくれず唸っていた。結局otel.SetTextMapPropagator(propagation.TraceContext{})を明示的に入れないと、GoのSDKの場合はTraceparentで伝播されないという罠があった(ChatGPTの初期コードでは入れてくれなくて、激詰めしていたらようやく提示された)。

ついでにOTEL_EXPORTER_OTLP_ENDPOINThttpsの罠をまた踏んでしばらく悩んでいた(過去記事の余談2)。まるで成長していない…

HTTPでない場合は別途メタデータなどで渡すことになるようだ(gRPCの場合はpropagatorで渡せる)。




以上の内容はhttps://kmuto.hatenablog.com/entry/2025/04/14/093000より取得しました。
このページはhttp://font.textar.tv/のウェブフォントを使用してます

不具合報告/要望等はこちらへお願いします。
モバイルやる夫Viewer Ver0.14