Cloud Run上のActix Webで構造化ロギングを行い、さらにCloud Traceと連携させる

はじめに

Cloud Run 上で動かしている Actix Web で構造化ロギングを行い、さらに、ログを Cloud Trace と連携させる方法を紹介します。
まず、Cloud Run 上で動かしている Actix Web で構造化ロギングを行う方法を紹介します。
その後、Cloud Trace と連携させる方法を紹介します。

Actix Web から Cloud Logging に構造化ログを出力する

使用するクレート

Cargo.toml

[dependencies]
actix-web = "4.3.1"
# ...
tracing = "0.1.37"
tracing-actix-web = "0.7.4"
tracing-subscriber = { version = "0.3.16", features = ["env-filter", "registry"] }
tracing-stackdriver = "0.6.2"

実装

main.rs

#[get("/")]
async fn handler(req: HttpRequest, session: Session) -> HttpResponse {
  tracing::info!("Hello, world!");
  // ...
}

#[actix_web::main]
async fn main() -> Result<()> {
  let subscriber = tracing_subscriber::Registry::default()
      .with(
          tracing_subscriber::EnvFilter::try_from_default_env()
              .unwrap_or(tracing_subscriber::EnvFilter::new("info")),
      )
      .with(tracing_stackdriver::layer());
  tracing::subscriber::set_global_default(subscriber).expect("Failed to set tracing subscriber");

  let server = HttpServer::new(move || {
      App::new()
          .wrap(tracing_actix_web::default())
          .service(handler)
  });
  server.bind("0.0.0.0:8080")?.run().await?;

  opentelemetry::global::shutdown_tracer_provider();
  Ok(())
}

実装の説明

handler 関数内の tracing::info! マクロで、出力するメッセージを指定します。
そして、main 関数内で初期化した、subscriber がログを受け取ります。

まず、EnvFilter で RUST_LOG 環境変数を使用して、ログレベル以下のログが出ないようにフィルタリングされます。
次に、tracing_stackdriver::layer() で返される Layer がログを以下のドキュメントで指定された形式に変換します。
(ちなみに、Stackdriver は Cloud Logging の旧称です。)

https://cloud.google.com/logging/docs/structured-logging?hl=ja

以下のように構造化されたログが、標準出力されます。

{
  "time": "2023-04-14T04:48:14.506246274Z",
  "severity": "INFO",
  "httpRequest": {
    "requestMethod": "GET",
    "requestUrl": "/some/url/from/request"
   },
  "message": "Hello, world!"
}

Cloud Loggingに出力

Cloud Run 上で動いているアプリケーションは、標準出力されたログを Cloud Logging に自動的に送信します。
また、Cloud Logging は以下のドキュメントで指定された形式のログを受け取ると自動的にパースして取り込んでくれます。

Cloud Trace と連携させる

Cloud Run は以下のドキュメントの通り、自動的に Cloud Trace にトレースを送信します。

https://cloud.google.com/run/docs/trace?hl=ja

Cloud Run サービスへの受信リクエストが発生すると、Cloud Trace に表示可能なトレースが自動生成されます。これらのトレースを使用すると、Cloud Trace でさらに計測手法を追加する必要なく、実装のレイテンシの問題の原因を特定できます。標準の W3C トレース コンテキスト伝搬ヘッダー traceparent は、Cloud Run リクエストに対して自動的に入力されます。

Cloud Run にデプロイしているアプリ側で、traceparent ヘッダに指定されている trace_id を取得し、伝搬させることで、Cloud Trace とログを紐付けることができます。

ただし、全てのリクエストに対してトレースがサンプリングされるわけではないので注意が必要です。
X-Cloud-Trace-Context ヘッダを使用することで、強制的にトレースを送信できます。

Cloud Run では、すべてのリクエストに対してトレースがサンプリングされるわけではありません。Cloud Run で使用する場合、リクエストは各コンテナ インスタンスにつき 1 秒あたり最大 0.1 リクエストのレートでサンプリングされます。特定のリクエストを強制的にトレースすることもできます。

Cloud Run は、Cloud Run のサンプルレートの構成をサポートしていません。

使用するクレート

features フラグも追加で指定します。

Cargo.toml

tracing-actix-web = { version = "0.7.4", features = ["opentelemetry_0_18"] }
tracing-subscriber = { version = "0.3.16", features = ["env-filter", "registry"] }
tracing-stackdriver = { version = "0.6.2", features = ["opentelemetry"] }
tracing-opentelemetry = "0.18.0"
opentelemetry = "0.18.0"

記事執筆時点で、3 週間ほど前に opentelemetry 0.19.0 がリリースされています。
しかし、tracing 関連のクレートが opentelemetry 0.18.0 に依存しているため、opentelemetry 0.19.0 を使用すると、以下のエラーが発生します。

error[E0277]: the trait bound `opentelemetry::sdk::trace::Tracer: tracing_opentelemetry::OpenTelemetryTracer` is not satisfied

実装

main.rs

#[get("/")]
async fn handler(req: HttpRequest, session: Session) -> HttpResponse {
  tracing::info!("Hello, world!");
  // ...
}

pub struct CustomRootSpanBuilder;

impl tracing_actix_web::RootSpanBuilder for CustomRootSpanBuilder {
    fn on_request_start(request: &actix_web::dev::ServiceRequest) -> tracing::Span {
        // Create a span with the standard fields when the request starts.
        tracing_actix_web::root_span!(request)
    }

    fn on_request_end<B: actix_web::body::MessageBody>(
        span: tracing::Span,
        outcome: &Result<actix_web::dev::ServiceResponse<B>, Error>,
    ) {
        // Capture the standard fields when the request finishes.
        tracing_actix_web::DefaultRootSpanBuilder::on_request_end(span, outcome);
    }
}

#[actix_web::main]
async fn main() -> Result<()> {
  // set up the propagator to propagate the trace context
  opentelemetry::global::set_text_map_propagator(
      opentelemetry::sdk::propagation::TraceContextPropagator::new(),
  );
  let tracer = opentelemetry::sdk::export::trace::stdout::new_pipeline()
      .with_trace_config(
          opentelemetry::sdk::trace::config()
              .with_sampler(opentelemetry::sdk::trace::Sampler::AlwaysOff),
      )
      .install_simple();

  let project_id = std::env::var("GOOGLE_PROJECT_ID").expect("GOOGLE_PROJECT_ID is not set");
  let subscriber = tracing_subscriber::Registry::default()
      .with(
          tracing_subscriber::EnvFilter::try_from_default_env()
              .unwrap_or(tracing_subscriber::EnvFilter::new("info")),
      )
      .with(tracing_opentelemetry::layer().with_tracer(tracer))
      .with(tracing_stackdriver::layer().enable_cloud_trace(
          tracing_stackdriver::CloudTraceConfiguration {
              project_id: project_id.clone(),
          },
      ));
  tracing::subscriber::set_global_default(subscriber).expect("Failed to set tracing subscriber");

  let server = HttpServer::new(move || {
      App::new()
          .wrap(tracing_actix_web::TracingLogger::<CustomRootSpanBuilder>::new()) // ここも変更
          .service(handler)
  });
  server.bind("0.0.0.0:8080")?.run().await?;

  opentelemetry::global::shutdown_tracer_provider();
  Ok(())
}

実装の説明

set_text_map_propagator で指定している TraceContextPropagator が traceparent ヘッダを解釈する機能を提供します。
CustomRootSpanBuilder 内の、tracing_actix_web::root_span!(request) で、内部的にこれが使用されます。
これで、traceparent ヘッダで指定された trace_id が次の Layer に伝搬されます。

また、tracing_opentelemetry::layer().with_tracer(tracer) で、opentelemetry と tracing を連携する Layer を追加しました。
tracer は、opentelemetry が提供する Tracer の実装です。
opentelemetry::sdk::trace::Sampler::AlwaysOff を使用しているため、これ自体ではトレースは送信されません。
後の tracing_stackdriver::layer() の内部で、必要な span_id をランダムに生成するために使用します。

また、tracing_stackdriver::layer() で、enable_cloud_trace の指定を追加しています。
こうすることで、traceparent ヘッダが指定された場合に以下のような出力となります。

traceparent に 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01 が指定されている場合、以下のフィールドがログに追加されます。

{
  "logging.googleapis.com/spanId": "d13bed66fe312dc2",
  "logging.googleapis.com/trace": "projects/<GOOGLE_PROJECT_ID>/traces/0af7651916cd43dd8448eb211c80319c",
  "logging.googleapis.com/trace_sampled": true
}

ただし、traceparent ヘッダが指定されていない場合、ランダムで trace_id が生成されますが、trace_sampled は指定されません。

{
  "logging.googleapis.com/spanId": "d8d3970c3fe0d99d",
  "logging.googleapis.com/trace": "projects/<GOOGLE_PROJECT_ID>/traces/b636ea33d7df9dd78dbd6ef220dcb166"
}