New Relicを使ったRust・Axumアプリのログとトレース

概要

本記事では、Rust・Axumアプリケーションの監視にNew Relicを導入し、ログとトレースを取得する方法を紹介します。
その過程で、ログとトレースを紐づけるために、crateに簡単なPatchを当てたことも紹介します。

今回使うコードは、以下のリポジトリにあります。

前提条件

Rustの開発環境が整っていること
New Relicのアカウントがあること

New Relicについて

New Relicでアプリケーションの監視を行う場合、言語が対応していればAPM（Application Performance Monitoring）を利用することが一般的です。

しかし残念ながら、RustのAPMは提供されていません（ぜひ提供してほしいですね）。

ですが、New RelicはOpenTelemetryをサポートしており、OpenTelemetryを利用することで、Rustアプリケーションのトレースを取得することができます。

RustにOpenTelemetryを導入する

今回使用するcrateをCargo.tomlに追加します。

Cargo.toml

[dependencies]
# 1. axum関連
axum = { version = "0.7.9" }
tokio = { version = "1.42.0", features = ["rt-multi-thread"] }
tower = "0.5.2"
tower-http = { version = "0.6.2", features = ["trace"] }

# 2. トレース関連
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.19", features = [
    "env-filter",
    "fmt",
    "std",
    "time",
] }

# 3. opentelemetry関連
opentelemetry = { version = "0.27.1", features = ["metrics", "logs"] }
opentelemetry-http = "0.27.0"
opentelemetry-otlp = { version = "0.27.0", features = [
    "tonic",
    "metrics",
    "logs",
    "tracing",
    "http-proto",
    "reqwest-client",
    "reqwest-rustls",
    "tls",
    "tls-roots",
    "opentelemetry-http",
] }
opentelemetry-semantic-conventions = { version = "0.27.0", features = [
    "semconv_experimental",
] }
opentelemetry-stdout = { version = "0.27.0", features = ["logs"] }
opentelemetry_sdk = { version = "0.27.1", features = [
    "rt-tokio",
    "logs",
    "metrics",
] }
tracing-opentelemetry = { version = "0.28.0", features = [] }
opentelemetry-appender-tracing = "0.27.0"

# 4. その他
time = { version = "0.3.37", features = ["macros", "formatting"] }
anyhow = "1.0.94"

数が多いですが、追加しているcrateは大きく分けて３つです。

axum関連
トレース関連
opentelemetry関連

次に、New Relicにログ・トレースを送信するためのProviderを作成します。

今回はメトリクスには触れません（上手く取得できてないので…）。

fn resource(new_relic_service_name: &str, host_name: &str) -> Resource {
    Resource::new(vec![
        KeyValue::new(
            opentelemetry_semantic_conventions::resource::SERVICE_NAME,
            new_relic_service_name.to_string(),
        ),
        KeyValue::new(
            opentelemetry_semantic_conventions::resource::HOST_NAME,
            host_name.to_string(),
        ),
    ])
}

fn init_logger_provider(
    new_relic_otlp_endpoint: &str,
    new_relic_license_key: &str,
    new_relic_service_name: &str,
    host_name: &str,
) -> Result<LoggerProvider, opentelemetry_sdk::logs::LogError> {
    let exporter = LogExporter::builder()
        .with_http()
        .with_endpoint(format!("{}/v1/logs", new_relic_otlp_endpoint))
        .with_headers(HashMap::from([(
            "api-key".into(),
            new_relic_license_key.into(),
        )]))
        .with_protocol(Protocol::HttpJson)
        .build()?;

    Ok(LoggerProvider::builder()
        .with_resource(resource(new_relic_service_name, host_name))
        .with_batch_exporter(exporter, runtime::Tokio)
        .build())
}

fn init_tracer_provider(
    new_relic_otlp_endpoint: &str,
    new_relic_license_key: &str,
    new_relic_service_name: &str,
    host_name: &str,
) -> Result<SdkTracerProvider, TraceError> {
    let exporter = SpanExporter::builder()
        .with_http()
        .with_endpoint(format!("{}/v1/traces", new_relic_otlp_endpoint))
        .with_headers(HashMap::from([(
            "api-key".into(),
            new_relic_license_key.into(),
        )]))
        .with_protocol(Protocol::HttpJson)
        .build()?;

    Ok(SdkTracerProvider::builder()
        .with_resource(resource(new_relic_service_name, host_name))
        .with_batch_exporter(exporter, runtime::Tokio)
        .build())
}

fn init_metrics(
    new_relic_otlp_endpoint: &str,
    new_relic_license_key: &str,
    new_relic_service_name: &str,
    host_name: &str,
) -> Result<opentelemetry_sdk::metrics::SdkMeterProvider, MetricError> {
    let exporter = MetricExporter::builder()
        .with_http()
        .with_endpoint(format!("{}/v1/metrics", new_relic_otlp_endpoint))
        .with_headers(HashMap::from([(
            "api-key".into(),
            new_relic_license_key.into(),
        )]))
        .with_protocol(Protocol::HttpJson)
        .build()?;

    let reader =
        opentelemetry_sdk::metrics::PeriodicReader::builder(exporter, runtime::Tokio).build();

    Ok(opentelemetry_sdk::metrics::SdkMeterProvider::builder()
        .with_reader(reader)
        .with_resource(resource(new_relic_service_name, host_name))
        .build())
}

今回はhttpプロトコルを使用していますが、gRPCも利用可能です。

また、ログ・トレース・メトリクスの各エンドポイントは$BASE_URL/v1/logs、$BASE_URL/v1/traces、$BASE_URL/v1/metricsになるようです。

参考

New Relicに送信するときにアプリケーション情報も同時に送信することで、New Relic上でアプリケーションを識別することができます。

今回はSERVICE_NAMEとHOST_NAMEを送信していますが、他にも様々な情報を送信することができます。

Rustでは、opentelemetry_semantic_conventionsでリソースのセマンティック規則が提供されています。

Resource::new(vec![
        KeyValue::new(
            opentelemetry_semantic_conventions::resource::SERVICE_NAME,
            new_relic_service_name.to_string(),
        ),
        KeyValue::new(
            opentelemetry_semantic_conventions::resource::HOST_NAME,
            host_name.to_string(),
        ),
    ])

次に、これらのProviderを組み立てて、tracingとopentelemetryを連携させます。

tracingとopentelemetryを連携させることで、tracingで記録したログやスパンをopentelemetryのトレースに紐づけることができます。

pub fn init_opentelemetry(
    new_relic_otlp_endpoint: &str,
    new_relic_license_key: &str,
    new_relic_service_name: &str,
    host_name: &str,
) -> anyhow::Result<()> {
    let tracer_provider = init_tracer_provider(
        &new_relic_otlp_endpoint,
        &new_relic_license_key,
        &new_relic_service_name,
        &host_name,
    )?;
    opentelemetry::global::set_tracer_provider(tracer_provider.clone());
    let tracer = tracer_provider.tracer(new_relic_service_name.to_string());

    let fmt_layer = tracing_subscriber::fmt::layer()
        .with_ansi(true)
        .with_file(true)
        .with_line_number(true)
        .with_target(true);
    let env_filter =
        tracing_subscriber::EnvFilter::try_from_default_env().unwrap_or_else(|_| "info".into());
    let otel_trace_layer = tracing_opentelemetry::OpenTelemetryLayer::new(tracer)
        .with_error_records_to_exceptions(true)
        .with_error_fields_to_exceptions(true)
        .with_error_events_to_status(true)
        .with_error_events_to_exceptions(true)
        .with_location(true);
    let otel_metrics_layer = tracing_opentelemetry::MetricsLayer::new(init_metrics(
        new_relic_otlp_endpoint,
        new_relic_license_key,
        new_relic_service_name,
        host_name,
    )?);
    let logger_provider = init_logger_provider(
        new_relic_otlp_endpoint,
        new_relic_license_key,
        new_relic_service_name,
        host_name,
    )?;
    let otel_logs_layer =
        opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge::new(&logger_provider);

    tracing_subscriber::registry()
        .with(fmt_layer)
        .with(env_filter)
        .with(otel_trace_layer)
        .with(otel_metrics_layer)
        .with(otel_logs_layer)
        .init();

    Ok(())
}

tracingのフォーマットとログレベルを設定した後、opentelemetryのtrace, metrics, logsの各レイヤーをtracing_subscriberに追加しています。

New Relicにログを送信してみる

ここまでで、ログとトレースを取得するための準備が整いました。

次に、ログを送信してみます。

pub fn init_opentelemetry(
    new_relic_otlp_endpoint: &str,
    new_relic_license_key: &str,
    new_relic_service_name: &str,
    host_name: &str,
) -> anyhow::Result<()> {
    # ...省略

    tracing_subscriber::registry()
        .with(fmt_layer)
        .with(env_filter)
        .with(otel_trace_layer)
        .with(otel_metrics_layer)
        .with(otel_logs_layer)
        .init();

    tracing::info!("OpenTelemetry initialized");

    logger_provider.force_flush();

    Ok(())
}

#[tokio::main]
async fn main() {
    let newrelic_license_key =
        std::env::var("NEWRELIC_LICENSE_KEY").expect("NEWRELIC_LICENSE_KEY env var is required");

    init_opentelemetry(
        "https://otlp.nr-data.net",
        &newrelic_license_key,
        "axum-newrelic-example",
        "localhost",
    )
    .expect("Failed to initialize OpenTelemetry");
}

今回は確認のために、init_opentelemetry関数を呼び出すと同時にtracing::info!でログを出力しています。

またログは非同期で送信されるため、logger_provider.force_flush()で強制的に送信しています。

new relicのOTLPエンドポイントはhttps://otlp.nr-data.netです。

参考

NEWRELIC_LICENSE_KEYを環境変数に設定して、アプリケーションを起動します。

NEWRELIC_LICENSE_KEY=YOUR_LICENSE_KEY cargo run

OpenTelemetry initializedというログを出力して終了するだけのアプリケーションです。
実行後にNew RelicのAPM & Servicesを確認するとaxum-newrelic-exampleというサービスが追加されているはずです。

Logsを確認すると、先ほど出力したログが送信されていることが確認できます。

AxumアプリにNew Relicを導入する

ログを送信できることが確認できたので、次にAxumアプリにNew Relicを導入します。

Hello, World!を返すだけのAxumアプリを作成します。

#[tokio::main]
async fn main() {
    let newrelic_license_key =
        std::env::var("NEWRELIC_LICENSE_KEY").expect("NEWRELIC_LICENSE_KEY env var is required");

    init_opentelemetry(
        "https://otlp.nr-data.net",
        &newrelic_license_key,
        "axum-newrelic-example",
        "localhost",
    )
    .expect("Failed to initialize OpenTelemetry");

    // build our application with a route
    let app = Router::new()
        .route("/", get(handler))
        .layer(MakeSpanForHttp.into_tracing_service());

    // run it
    let listener = tokio::net::TcpListener::bind("127.0.0.1:3000")
        .await
        .unwrap();
    println!("listening on {}", listener.local_addr().unwrap());
    axum::serve(listener, app).await.unwrap();
}

pub async fn handler() -> Html<&'static str> {
    Html("<h1>Hello, World!</h1>")
}

localhost:3000にアクセスするとHello, World!が表示されるはずです。

トレースを送信してみる

次に、トレースを送信してみます。

handler関数を以下のように修正し、handlerから呼び出されるsub1関数とsub2関数を追加します。

#[tracing::instrument]
pub async fn handler() -> Html<&'static str> {
    tracing::info!("request received");
    Html("<h1>Hello, World!</h1>")
}

#[tracing::instrument]
pub fn sub1(call_fn: &str) {
    tracing::info!(name: "sub1", call_fn = call_fn, "info log");
    sub2("sub1");
}

#[instrument]
pub fn sub2(call_fn: &str) {
    tracing::error!(name: "sub2" ,"error log");
}

instrumentアトリビュートを使用することで、関数の開始時に自動的にスパンを生成してくれるようになります。

axum serverを起動して、localhost:3000にアクセスします。

2024-12-14T13:55:43.787141Z  INFO handler: rust_axum_newrelic_example::handler: src/handler.rs:6: request received
2024-12-14T13:55:43.787278Z  INFO handler:sub1{call_fn="handler"}: rust_axum_newrelic_example::handler: src/handler.rs:15: info log call_fn="handler"
2024-12-14T13:55:43.787374Z ERROR handler:sub1{call_fn="handler"}:sub2{call_fn="sub1"}: rust_axum_newrelic_example::handler: src/handler.rs:21: error log

最後のログを見ると、まずhandler関数が呼び出され、その中でsub1関数が引数call_fn="handler"で呼び出され、さらにsub2関数が引数call_fn="sub1"で呼び出されていることがわかります。

New RelicのDistributed tracingを確認すると、トレースが送信されていることが確認できます。

各リクエストのトレースを、ハンドラー単位でトランザクションとしてまとめてパフォーマンスモニタリングを可能にする

ここまでで、Distributed tracingでトレースを取得することができました。

しかし、今の状態では１リクエストごとのトレースを見ることができるだけで、全体のパフォーマンスやボトルネックを把握するのは難しいです。

New Relicには、トランザクションという概念があり、複数のリクエストをまとめてパフォーマンスをモニタリングすることができます。

各ハンドラー単位（エンドポイントごとに）でトランザクションを作成し、トランザクションごとにパフォーマンスをモニタリングできるようにします。

axumがリクエストを受けたとき、ハンドラーが呼び出される前にスパンを作成するようにします。

#[derive(Clone)]
pub(crate) struct MakeSpanForHttp;

impl<B> MakeSpan<B> for MakeSpanForHttp {
    fn make_span(&mut self, request: &Request<B>) -> Span {
        let matched_path = request
            .extensions()
            .get::<MatchedPath>()
            .map_or(request.uri().to_string(), |m| m.as_str().to_string());
        tracing::info_span!(
            "request",
            http.method = %request.method(),
            http.uri = %request.uri(),
            http.version = ?request.version(),
            otel.name = format!("{} {}", request.method(), matched_path),
            otel.kind = "server",
        )
    }
}

impl MakeSpanForHttp {
    pub(crate) fn into_tracing_service(
        self,
    ) -> ServiceBuilder<Stack<TraceLayer<SharedClassifier<ServerErrorsAsFailures>, Self>, Identity>>
    {
        ServiceBuilder::new().layer(TraceLayer::new_for_http().make_span_with(self))
    }
}

注目すべきは、otel.kind = "server"という部分です。
これにより、New RelicのトランザクションにOpenTelemetryのスパンがマッピングされます。

その他、トランザクション名をrequest.method() + matched_path、リクエスト情報（メソッド、URI、バージョン）をスパンの属性として追加しています。

Axumアプリを起動して数回アクセスし、New RelicのTransactionsを確認すると、GET /という名前でトランザクションとしてまとめられていることが確認できます。

トランザクションから各トレースも確認できます。

これで、Axumアプリのパフォーマンスをトランザクション単位でモニタリングすることができるようになりました。

トレースとログを紐づける

さて、ここまででおおよそいい感じにアプリケーションの監視ができるようになりましたが、実はまだ問題があります。

それは、トレースとログが紐づいていないことです。

GET /のトレースを確認すると、ログが出力されているはずなのに表示されていません。

これは、ログのアトリビュートにtrace.idやspan.idが含まれていないためです。

解決策の一つとして、ログを出力する際に毎回trace.idやspan.idをログに含める方法があります。

tracing::info!(
    trace.id = trace_id,
    span_id = span_id,
    "request received",
);

しかし、これを毎回書くのは面倒ですし、漏れがあるとログとトレースを紐づけることができません（いい感じに自動的に属性を付与してくれるカスタムレイヤーなどを実装する方法があれば教えていただきたいです）。

そこで今回は、tracingとOpenTelemetryを連携させているopentelemetry-appender-tracingにパッチを当てて、otelログ送信時にtrace.idやspan.idを自動的に付与するようにします。

以下がパッチを当てたPRです。
とにかくtrace.idやspan.idをアトリビュートに追加したかっただけなので、割と愚直な実装です。

パッチを当てたcrateをcrates.ioに公開しています。

cargo add opentelemetry-appender-tracing2

opentelemetry-appender-tracingをopentelemetry-appender-tracing2に置き換えることで、ログとトレースが紐づくようになるはずです。

tracingとOpenTelemetryのセットアップをサクッとやってくれるcrate

今回は、tracingとOpenTelemetryを連携させるために、いくつかのcrateを使用しました。

しかし、アプリケーションを作成する際に、毎回これらのcrateをセットアップするのは面倒です（なにより忘れるので毎回exampleを見に行っている）

そこで、tracingとOpenTelemetryのセットアップをサクッとやってくれるcrateがあると便利だと思い、easy_init_newrelic_opentelemetryというcrateを公開しました。

easy_init_newrelic_opentelemetryを使用することで、以下のように、簡単にtracingとOpenTelemetryをセットアップすることができます。

easy_init_newrelic_opentelemetry::NewRelicSubscriberInitializer::default()
    .newrelic_license_key(&newrelic_license_key)
    .newrelic_service_name("axum-newrelic-example")
    .host_name("localhost")
    .init()
    .expect("Failed to initialize OpenTelemetry");

自分用に作成したものなので拡張性に乏しくフォーマットや設定事項が決め打ちですが、簡単にセットアップできるので、興味があれば使ってみてください。

まとめ

本記事では、Rust・Axumアプリケーションの監視にNew Relicを導入し、ログとトレースを取得する方法を紹介しました。

New Relicを使うことで、ログとトレースを取得することができ、アプリケーションのパフォーマンスをモニタリングすることができます。

メトリクスについてはうまく取得できていないので、今後の取得できるようにしたいです。