nginx-datadogで分散トレーシング

Posted on Jul 16, 2023 | 639 words | ~3 mins

nginxのトレース情報を収集できるDatadog nginxモジュールのv1.0.0が最近リリースされていたので試した

ref. https://docs.datadoghq.com/tracing/trace_collection/proxy_setup/?tab=nginx#nginx-with-datadog-module

docker-compose.yml

version: "3.7"

services:
  api:
    build:
      context: ./api
      dockerfile: Dockerfile
      args:
        DD_API_KEY: ${DD_API_KEY}
    container_name: sample-api
    ports:
      - 8080:8080
    environment:
      - DD_ENV=dev
      - DD_HOSTNAME=local

  nginx:
    build:
      context: ./nginx
      dockerfile: Dockerfile
    container_name: sample-nginx
    image: sample-nginx
    labels:
      com.datadoghq.tags.env: 'dev'
      com.datadoghq.tags.service: 'sample-nginx'
      com.datadoghq.tags.version: '0.1.0'
      com.datadoghq.ad.check_names: '["nginx"]'
      com.datadoghq.ad.init_configs: '[{}]'
      com.datadoghq.ad.instances: '[{"nginx_status_url": "http://%%host%%:81/nginx_status/"}]'
      com.datadoghq.ad.logs: '[{"source": "nginx", "service": "sample-nginx"}]'
    volumes:
      - './nginx/nginx.conf:/etc/nginx/nginx.conf:ro'
    ports:
      - "8888:80"
    environment:
      DD_AGENT_HOST: datadog
      DD_TRACE_AGENT_PORT: 8126

  datadog: 
    image: datadog/agent:7
    container_name: sample-ddagent
    environment:
      - DD_API_KEY
      - DD_SITE=datadoghq.com
      - DD_ENV=dev
      - DD_HOSTNAME=local
      - DD_LOGS_ENABLED=true
      - DD_LOGS_CONFIG_CONTAINER_COLLET_ALL=true
      - DD_APM_NON_LOCAL_TRAFFIC=true
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock:ro
      - /proc/:/host/proc/:ro
      - /sys/fs/cgroup/:/host/sys/fs/cgroup:ro
    ports:
      - "8126:8126/tcp"

構成
- nginx、バックエンドapi、Datadog Agent用コンテナの3つからなる構成
nginx
- nginxコンテナにはDatadogのAutodiscovery機能を有効にするために、Dockerオブジェクトラベルを付与することでdd-agentとの疎通エンドポイントやDatadog Logsに関する設定を施している
- ラベルを付与することで単なるメタデータとしてでなく、一種の設定値として意味をもたせる扱い方はなるほど..となった(こうした活用方法をみたことがなかった)
- (上記設定自体はDatadog Logsに関するもので、nginx-datadogモジュールによるトレーシングとは無関係)

nginx/Dockerfile

FROM nginx:1.24.0

RUN apt-get update && \
  apt-get install -y \
    wget \
    jq

# https://docs.datadoghq.com/tracing/trace_collection/proxy_setup/?tab=nginx#module-installation
RUN get_latest_release() { \
      curl --silent "https://api.github.com/repos/$1/releases/latest" | jq --raw-output .tag_name; \
    } && \
    BASE_IMAGE=nginx:1.24.0 && \
    BASE_IMAGE_WITHOUT_COLONS=$(echo "$BASE_IMAGE" | tr ':' '_') && \
    RELEASE_TAG=$(get_latest_release DataDog/nginx-datadog) && \
    tarball="$BASE_IMAGE_WITHOUT_COLONS-ngx_http_datadog_module.so.tgz" && \
    wget "https://github.com/DataDog/nginx-datadog/releases/download/$RELEASE_TAG/$tarball" && \
    tar -xzf "$tarball" -C /usr/lib/nginx/modules && \
    rm "$tarball"

nginxコンテナ用Dockerfile
nginxベースイメージに、nginxバージョンに対応するDatadog nginxモジュールをDLしてくる
- 公式ドキュメントままのスクリプト
BASE_IMAGEでnginxバージョン指定しているが、Datadog nginxモジュールは各種nginxバージョン毎にバイナリがホストされている

nginx.conf

# Load nginx-datadog module for enabling Datadog APM Traces for proxy
load_module /usr/lib/nginx/modules/ngx_http_datadog_module.so;


error_log  /var/log/nginx/error.log notice;
pid        /var/run/nginx.pid;

events {
    worker_connections  1024;
}

http {
    include       /etc/nginx/mime.types;
    default_type  application/octet-stream;
    # ref. https://docs.datadoghq.com/integrations/nginx/?tab=host#log-collection
    log_format main '$remote_addr - $remote_user [$time_local] '
                  '"$request" $status $body_bytes_sent $request_time '
                  '"$http_referer" "$http_user_agent" "$http_x_forwarded_for"';
    access_log  /var/log/nginx/access.log main;
    sendfile        on;
    keepalive_timeout  65;

    # Reverse proxy of `app` container
    server {
        listen       80;
        server_name  localhost;

        location / {
            proxy_set_header Host $host;
            proxy_set_header X-Real-IP $remote_addr;
            proxy_pass http://api:8080;
        }
    }

    # Enabling http_stub_status_module
    # so that dd-agent can collect nginx info
    # ref. https://docs.datadoghq.com/integrations/nginx/?tab=host#prepare-nginx
    server {
        listen 81;
        server_name _;
        access_log off;

        location /nginx_status {
            stub_status;
            server_tokens on;
        }
    }
}

load_module /usr/lib/nginx/modules/ngx_http_datadog_module.so; 部分でDatadog nginxモジュールをload
APIドキュメントにあるように、datadog_ prefixで始まる各種ディレクティブをカスタマイズすることもできる(eg. datadog_service_name my_nginx;)

トレース概観

単位リクエストに相当するトレースでは以下のようなフレームグラフになる

ちゃんとバックエンドサービスに紐づくカタチでスパンが生成されている

バックエンドアプリケーション実装

Goで書かれたAPIサーバ

package main

import (
	"math/rand"
	"net/http"
	"time"

	"github.com/sirupsen/logrus"
	muxtrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/gorilla/mux"
	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
)

var log = NewLogger("/app/prod.log")

func randomStatusHandler(w http.ResponseWriter, r *http.Request) {
	rctx := r.Context()
	span, sctx := tracer.StartSpanFromContext(rctx, "testSpan")
	defer span.Finish()

	loge := log.
		WithContext(sctx).
		WithFields(logrus.Fields{"url": r.URL, "method": r.Method, "remote_addr": r.RemoteAddr})

	statusCodes := []int{http.StatusOK, http.StatusBadRequest, http.StatusInternalServerError}
	rand.Seed(time.Now().UnixNano())
	randomStatusCode := statusCodes[rand.Intn(len(statusCodes))]

	w.WriteHeader(randomStatusCode)
	switch randomStatusCode {
	case http.StatusOK:
		loge.Info("ok")
		w.Write([]byte("Status OK"))
	case http.StatusBadRequest:
		loge.Info("client error")
		w.Write([]byte("Bad Request"))
	case http.StatusInternalServerError:
		loge.Info("server error")
		w.Write([]byte("Internal Server Error"))
	}
}

func main() {
	tracer.Start()
	defer tracer.Stop()

	r := muxtrace.NewRouter()
	r.HandleFunc("/", randomStatusHandler)

	log.Println("Started")
	log.Fatal(http.ListenAndServe(":8080", r))
}

gorilla/muxベースのシンプルなAPIサーバ
- GET /のダミーエンドポイントのみをもち、ランダムに200/400/500ステータスコードを返却する
Datadogからは、GoアプリケーションへのAPMインテグレーションのためのトレーシングライブラリが提供されている
- dd-trace-go OSSとして、GitHubで公開されている
上記サンプルコードでは、dd-trace-goのgorilla/mux wrapper実装を使用し、リクエストハンドラでのトレース/スパン生成処理をライブラリに寄せている
アプリケーション側では、リクエストハンドラのトレースについて、nginx側で生成されたものと同一トレースとなることを保証するためのケアは特に要らない
- どうやってサービス間でトレース情報が紐付けされているのか
  - サービス間の通信でHTTPヘッダにx-datadog-trace-idを付与することで、クロスプロダクト相関を作成できるしくみがある
- Datadog nginxでは、nginx-datadog側のデフォルトのpropagation設定で、X-Datadog-Trace-Idなどのヘッダが自動付与され、同一トレースの紐付けが解決される

以上がnginx-datadogの動作検証で、以降はdd-trace-goに関するtips的なメモ

dd-trace-goライブラリで生成されたスパンに紐づく子スパンを生成したい

とは

リクエストハンドラ内でログ出力する際に、該当リクエストに対応するトレースに紐づくカタチでログ出力を行いたい、ということ

import (
	"net/http"

	muxtrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/gorilla/mux"
	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
)

var log = NewLogger("/app/prod.log")

func handler(w http.ResponseWriter, r *http.Request) {
	span := tracer.StartSpan("http.request", tracer.ResourceName("GET /")) // 👈 muxtrace側で生成されたスパンとは独立(紐付かない)
	defer span.Finish()
}

func main() {
	tracer.Start()
	defer tracer.Stop()

	r := muxtrace.NewRouter()
	r.HandleFunc("/", handler)

	log.Fatal(http.ListenAndServe(":8080", r))
}

上記コードのように、handler関数内で単にスパンを生成しても、dd-trace-go内部で生成されたトレース情報とは紐付かない(独立したトレース/スパンとして生成される)
- ステータスコードとも紐づいていない

結論からいうと、以下のようにすることで、dd-trace-goで生成されたトレース情報と紐付ける形で子スパンを生成できる

func randomStatusHandler(w http.ResponseWriter, r *http.Request) {
	rctx := r.Context()
	span, sctx := tracer.StartSpanFromContext(rctx, "testSpan")
	defer span.Finish()
    ...
}

ハンドラに渡されるhttp.Requestのcontextを取得した上で、StartSpanFromContextに与えることで、リクエストに対応するアクティブなスパンとそのcontextを得られる
(ライブラリ実装から機序をみていくと..)
- dd-traceのgorilla/mux RouterのServeHTTPハンドラのラップ実装の上で、
- ServeHTTP時に、http.Request生成する際に、トレースに関するContextとともに生成されていることがわかる
結果、以下のように同一トレースの下で任意で生成したスパン(ie. testSpan)が紐づけられる

dd-trace-goライブラリで生成されたスパンに紐づくログを出力したい

スパン内処理の中で出力されたログを紐付けたい

Datadog公式ドキュメントにもログとトレースの接続で方法が記載されている
manual injectionの方法として以下のようなサンプルコードが提供されている

func handler(w http.ResponseWriter, r *http.Request) {
    // Create a span for a web request at the /posts URL.
    span := tracer.StartSpan("web.request", tracer.ResourceName("/posts"))
    defer span.Finish()

    // Append span info to log messages:
    log.Printf("my log message %v", span)
}

この方法でもトレースとログの関連をつくれるが、ログ本体にもtrace_idやspan_idが出力され、若干ノイズとなってしまう
構造化ログにdd.trace_id, dd.span_idを埋め込むことで、ログとトレースの紐付が行えるので、このアプローチをとるとよい
dd-trace-goには、logrusのインテグレーションなども組み込まれているので、専用のHookを仕込むことで、容易にログとトレースの接続が行える
サンプル実装ではこれを使用している

logger.go

package main

import (
	"io"
	"os"

	"github.com/sirupsen/logrus"
	ddtracelogrus "gopkg.in/DataDog/dd-trace-go.v1/contrib/sirupsen/logrus"
)

type Logger struct {
	*logrus.Logger
}

func NewLogger(fpath string) *Logger {
	log := logrus.New()

	file, err := os.OpenFile(fpath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
	if err == nil {
		mw := io.MultiWriter(os.Stdout, file)
		log.SetOutput(mw)
	} else {
		log.Info("Failed to log to file, using default stderr")
	}

	log.SetFormatter(&logrus.JSONFormatter{})
	log.SetLevel(logrus.InfoLevel)
	log.AddHook(&ddtracelogrus.DDContextLogHook{}) // 👈👈👈
	return &Logger{log}
}

log.AddHook(&ddtracelogrus.DDContextLogHook{}) でdd-trace-goで提供されるHookを追加

main.go

var log = NewLogger("/app/prod.log")

func handler(w http.ResponseWriter, r *http.Request) {
	rctx := r.Context()
	span, sctx := tracer.StartSpanFromContext(rctx, "testSpan")
	defer span.Finish()

	loge := log.
		WithContext(sctx). // 👈👈👈
		WithFields(logrus.Fields{"url": r.URL, "method": r.Method, "remote_addr": r.RemoteAddr})
	...
}

loggerインスタンスに、WithContext でスパンcontextを与え、DDContextLogHook側でtrace_id, span_idを参照できるように

こうすることで、loggerで出力されたログエントリがトレースと紐づく

備考

開発機がApple Silicon Mac(arm64)であった為、ローカルではDatadog nginxモジュールはloadできず検証できなかった
- ので、実際の動作検証はAWS Cloud9のAmazon Linux(linux/amd64)上で行った次第
- M1 Mac持ちにとって、amd64環境でイメージビルドしたり実行したりするようなユースケースにCloud9は本当に便利だった(download/upload 1GB/s超えの通信速度の福利厚生など)
今回検証を行ったGitHub repo: https://github.com/hrfmmr/nginx-datadog-sandbox

参考

nginxのメトリクス・ログ・トレースをDatadogでモニターする方法 - Qiita