3
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

Day 24

hooq Advent Calendar 2025

@namn1125(namnium)inゆめみ

とりあえずtracingを体感する

3
Last updated at Posted at 2025-12-24

メリークリスマス！hooqアドベントカレンダー 24日目の記事です！

hooqはメソッドを ? 演算子にフックする属性マクロです。本アドカレではhooqの使い方を始め、hooqマクロを作成するにあたり得た知識、Rustのエラーハンドリング・エラーロギング周りの話をまとめています。

Rustのエラー関連についてまとめてきたhooqアドカレもラス前ということで、今回は最近猫Rustaceanも杓子Rustaceanも触ってるtracingを自分なりに触ってみたいと思います！

エラーロギングのためだけに、オブザーバビリティ(Observability, O11y)やらOpenTelemetryやら何やらの知識が求められるため、tracingエコシステムを正面から理解することは難しいでしょう。筆者もO11yは最近学び始めたばかりで、tracingは感覚的にしかわかっていません。

とはいえ触れぬまま年越しも何かモニョる...というわけで、詳細理解は来年の自分に期待しつつ、本記事では無理せず以下3つを軽くまとめてみます。

  • とりあえず #[tracing::instrument] の恩恵を感じる
  • tracingクレートのREADMEを斜め読み
  • jaegerにOTLPでトレースを送ってみる

本記事ではあまり込み入ったO11yの話はできない1点についてご容赦ください。

#[tracing::instrument]でエラートレースもどきを得る

最近Rustのエラーハンドリング・ロギングの議論が妙に静かに感じるのですが、それは実はこの属性マクロのおかげではないかと筆者は予想しています。

というわけで、最速でこのマクロの恩恵を受けてみましょう！詳しい原理は後です。

tracingは非同期ライブラリの王道tokio-rsグループが提供していますが、利用は別に非同期関数に限定されません！一昨日の記事から使っているような単純な例にも十分適用できます。

Cargo.toml
[package]
name = "tracing_pg"
version = "0.1.0"
edition = "2024"

[dependencies]
tracing = "0.1.44"
tracing-subscriber = { version = "0.3.22", features = ["env-filter"] }
src/main.rs
use tracing_subscriber::{filter::EnvFilter, layer::SubscriberExt, util::SubscriberInitExt};

#[tracing::instrument(err)]
fn func1() -> Result<(), String> {
    Err("error!".to_string())
}

#[tracing::instrument(err)]
fn func2() -> Result<(), Box<dyn std::error::Error>> {
    func1()?;

    Ok(())
}

#[tracing::instrument(err)]
fn func3() -> Result<(), Box<dyn std::error::Error>> {
    func2()?;

    Ok(())
}

fn main() -> Result<(), Box<dyn std::error::Error>> {
    subscriber_init()?;

    tracing::info!("Starting application");

    func3()?;

    Ok(())
}

fn subscriber_init() -> Result<(), Box<dyn std::error::Error>> {
    let env_filter = EnvFilter::try_from_default_env().or_else(|_| EnvFilter::try_new("debug"))?;
    let subscriber = tracing_subscriber::fmt::layer()
        .with_file(true)
        .with_line_number(true);

    tracing_subscriber::registry()
        .with(subscriber)
        .with(env_filter)
        .try_init()?;

    Ok(())
}

subscriber_init 内部に多少のおまじないがありますが、 #[tracing::instrument(err)] を各関数につけることで、エラートレースもどきを得ることができます。

実行結果
$ cargo run -q
2025-12-24T15:24:19.550558Z  INFO tracing_pg: src/main.rs:25: Starting application
2025-12-24T15:24:19.550678Z ERROR func3:func2:func1: tracing_pg: src/main.rs:3: error=error!
2025-12-24T15:24:19.550737Z ERROR func3:func2: tracing_pg: src/main.rs:8: error=error!
2025-12-24T15:24:19.550788Z ERROR func3: tracing_pg: src/main.rs:15: error=error!
Error: "error!"

#[tracing::instrument(err)] のおかげで、「3行目定義の func1 でエラーが発生」→「8行目定義の func2 でエラーが発生」→「15行目定義の func3 でエラーが発生」というトレースが得られ、どのようにしてエラーが伝搬したかがわかりました！便利ですね！

うおぉぉtracing完全に理解したぜ！

...というとさすがに言い過ぎかもしれませんが、O11yミリ知らでも「とりあえず #[tracing::instrument(err)] を付けておく」ことで、Backtraceを採用しない場合でも、そして非同期処理でもエラートレースもどきが得られるわけです。

Webアプリケーションに限らず、中規模以上の非同期処理を含むアプリケーションはどれもこの属性マクロに頼っておけばエラーの原因究明が楽になるでしょう。

「もう全部tracingあいつ一人でいいんじゃないかな」

これが最近Rust界隈であんまりエラーハンドリング・ロギングの議論が見られなくなった(エラートレースを得る手段としてはsnafu等他にも選択肢があるはずなのにあまり聞かない)理由の一つ2なのではないかと思います。

tracingの語彙で言えばもどきでもなんでもなくまさしく処理の「トレース」を見ていると言えるでしょう。

筆者が主張したいのは、本アドカレで今日まで模索してきた「 Backtrace に類するもの」として見た場合、遜色ない(どころかより詳細な)情報が得られている点です。このバックトレースに類しているというニュアンスで「エラートレースもどき」と呼称しています。

宣伝: hooqと組み合わせるとエラーが発生した ? 演算子の場所を得られます！

#[instrument(err)] が出力する行は、 #[instrument(err)] が存在する行 であり ? 演算子の行を得る手段は用意されていないようです3。hooq属性マクロと併用することで ? 演算子の位置をピンポイントでイベント内に含められます！

詳細は次の記事を参照ください :point_right: tracing × hooq = 🔎 #Rust - Qiita

#[tracing::instrument] の挙動説明をもう少しだけ...

この属性マクロについて折角の機会なのでもう少しまとめたいと思います。

公式ドキュメントに出てくる利用方法について早見表としてまとめてみました。まとめただけなので詳細は公式の方を読んでいただけると幸いです。まただいぶ端折っています。表では use tracing::instrument; を前提とし tracing:: は省略します。

注目度 マクロの書き方 効果
☆ #[instrument] 関数に付与することで関数名の名前を持ったスパンを作成し関数のスコープに適用する。この記法だと「 スパンを作成するだけでイベントは送出しない 」点と「 self 含め全引数がログに出る 」点に注意
#[instrument(name = "...")] スパンの名前を変更。デフォルトは関数名
#[instrument(target = "...")] スパンのターゲットを変更する。デフォルトは、その場所のモジュールパス
#[instrument(level = "...")] スパンのレベル( info や warn など)を変更する。デフォルトは INFO
☆ #[instrument(skip(...))] 指定した引数をレコードから除外する。 Debug を実装していない型やログに出力したくないフィールドを指定
#[instrument(skip_all)] 引数すべてをレコードから除外
☆ #[instrument(fields(xxx = ...))] レコードに含めるフィールドを追加
☆☆ #[instrument(ret)] スパンと同じレベルで 値を返す際に返り値でイベントを送出する (つまりログが出る)
#[instrument(ret(level = ...))] 値を返す際に指定したログレベルでイベントを送出する
#[instrument(ret(Display))] 同上。デフォルトでは返り値が Debug で出力されてしまうので、これを Display にする
☆☆☆ #[instrument(err)] Result<T, E> が返り値の関数について エラー時にイベントを送出する 。ログレベルのデフォルトは ERROR
#[instrument(err(level = ...))] ret と同様、イベント送出時のログレベルを指定する
#[instrument(err(Debug))] ret と異なり err はデフォルトの表示方法が Display なので、逆に Debug で出したい時に指定
#[instrument(err, ret)] Result<T, E> が返り値の関数について Ok でも Err でもイベント送出する

一応確認のために表形式にしましたがぶっちゃけここで確認しておきたかったのは #[instrument] だけではスパンの作成しかせず、イベントを送出させたければ #[instrument(ret)] か #[instrument(err)] にする必要があるということです。

tracingクレート README斜め読み

冒頭でtracingに触れることができたので、ここからは軽く座学したいと思います！tracingクレートのREADMEを読んでO11yを知らないなりに軽くtracingエコシステムを押さえておきます。

「具体的に○○したい」みたいなのは次節のjaegerへの送信以外今回は思いつかなかったので、コード例はありません。また図解などはなくもしかしたらわかりにくい説明を含むかもしれません。「READMEにこんなことが書いてあったよ」というメモ書きだとみなしていただけると幸いです。

Overview 要約

tracing は構造化されたイベントベースの診断情報を集めるRustプログラムの 計装4フレームワーク です。

  • 従来のlogクレートなどでは、順番がおかしくなるために非同期に弱かった
  • tracingではただのログではなく「時間性」や「因果関係」等を含めた構造化された イベント を記録する。だから非同期に強い！
  • tracingクレート自体の役割はtracingエコシステムのAPIの提供
    • 役割的には(env_loggerなどに対する)logクレートに近そう

コアコンセプト

上記向けのAPIを提供しているようです。

スパン Spans

ある処理の範囲を表すのに用いられるもので、開始時刻と終了時刻を持ちます。スパン中に発生したイベントがスパンの関係と共にログに現れ、スパンはネストすることもあります。

スパンについてはこの記事様に掲載されている図が分かりやすくて好きです5！

イベント Events

従来のログに対応するもので、ある出来事の瞬間的な記録です。

  • ログと異なり構造化されている
  • スパン内で起きる

上記2つがログと異なる点でしょうか？

イベントにもスパンにもログと同様Levelの概念があります。

サブスクライバ Subscribers

スパンやイベントが発生した際の記録先がサブスクライバになります。tracingからはSubscriber トレイトとして提供されています。

  • event: イベントが発生した時に呼び出される
  • enter: スパンに入る時に呼び出される
  • exit: スパンから出る時に呼び出される

tracing-subscriberクレートが提供するtracing_subscriber::fmt::Subscriberが主な実装者でしょうか...？logクレートに対するenv_loggerみたいな感じがしますね。

以降はREADME記載の内容で気になったものをつまみ食いします！

Spanの利用方法

span.enter() を使う方法と、冒頭で紹介した #[instrument] を使う方法が紹介されています。大体は #[instrument] があれば事足りる気がします。

logクレートとの互換性

debug! や info! などほぼ同じ記法で書けるマクロで用意されているので移行は楽という記述がありますね。やはりtracingはlogの上位互換と見てしまってよさそうです。

関係するクレートについて

ここに色々記載があったり、実際に利用する際に依存がたくさん増えたりするため関係性を理解できていませんでしたが、今回まとめたことで、とりあえずlogクレートと同様に考えればよいことがわかりました！

opentelemetryクレートなど次節にて初めて必要になるクレートが色々あるのですが、これらは tracing-subscriber が必要としているクレートであり、tracingエコシステムの一部ではありそうですが直接必要なわけではなさそうです。

tracing視点で必要なのはあくまでもSubscriberトレイトを実装した何某で、そのために一例としてとりあえず tracing-subscriber が必要ということを押さえておけばよさそうです！

jaegerにログを送ってみる

本節は tracing × hooq = 🔎 #Rust - Qiita にて用意したもののあまり解説をしなかったjaegerを用いたPoCを題材に軽く解説をしたものになります。

本記事最後は折角の機会なので標準エラー出力だけではなく何かしらの監視ツールにトレースを送ってみたいと思います！

書籍「RustによるWebアプリケーション開発　設計からリリース・運用まで」や、他記事様等で皆jaeger(イェーガーと読むらしい...)を利用しているので本記事でも踏襲してjaegerを利用します。

axumサーバーを立てたPoCを用意しました！axumサーバー自体のコード詳細はここでは解説しません。以下のGitHubリポジトリを参照ください。

jaegerの立ち上げには docker compose up -d を利用しました。以下compose.yamlです。

compose.yaml
services:
  jaeger:
    image: jaegertracing/all-in-one:1.75.0
    ports:
      - "16686:16686"
      - "4318:4318"
    environment:
      - LOG_LEVEL=debug
      - COLLECTOR_OTLP_ENABLED=true

jaegerはOpenTelemetryに準拠しており、axumサーバーからOTel情報を 4318 ポートに送ることでjaeger側でトレースを受け取れます。 16686 ポートはjaegerのサイトがホストされています。

jaegerの設定についてはopentelemetry-otlpクレートのドキュメントが参考になりました！: https://docs.rs/opentelemetry-otlp/latest/opentelemetry_otlp/#using-with-jaeger

そして以下がSubscriber等の設定なのですが呪文味がさらに増しています。 :dizzy_face: opentelemetry-otlpクレート等の公式ドキュメント等を参考にしましたが、正直筆者はまだ良くわかってないです。 :innocent:

src/logger.rs (一部改変)
use opentelemetry::{KeyValue, global};
use opentelemetry_otlp::{Protocol, WithExportConfig};
use opentelemetry_sdk::Resource;
use tracing_subscriber::{EnvFilter, layer::SubscriberExt, util::SubscriberInitExt};

pub fn init() -> Result<(), Box<dyn std::error::Error>> {
    // Initialize OTLP exporter using HTTP binary protocol
    let otlp_exporter = opentelemetry_otlp::SpanExporter::builder()
        .with_http()
        .with_protocol(Protocol::HttpBinary)
        .build()?;

    // service.name などを設定
    let resource = Resource::builder()
        .with_service_name("todo_app_tracing")
        .with_attributes([
            KeyValue::new("service.version", env!("CARGO_PKG_VERSION")),
            KeyValue::new("deployment.environment", "dev"),
        ])
        .build();

    // Create a tracer provider with the exporter
    let tracer_provider = opentelemetry_sdk::trace::SdkTracerProvider::builder()
        .with_resource(resource)
        .with_batch_exporter(otlp_exporter)
        .build();

    // Set it as the global provider
    global::set_tracer_provider(tracer_provider);

    let tracer = global::tracer("todo_app_tracer");
    let opentelemetry = tracing_opentelemetry::layer().with_tracer(tracer);

    // ====================

    let env_filter = EnvFilter::try_from_default_env().or_else(|_| EnvFilter::try_new("debug"))?;
    let subscriber = tracing_subscriber::fmt::layer()
        .with_file(true)
        .with_line_number(true)
        .json();

    tracing_subscriber::registry()
        .with(subscriber)
        .with(env_filter)
        .with(opentelemetry)
        .try_init()?;

    Ok(())
}

一つ言えるのは、大部分(opentelemetry 変数の作成まで)はtracing-subscriberのための設定ということです。 opentelemetry 変数に入っているのはtracing_opentelemetry::OpenTelemetryLayerで、こちらはtracing-subscriberのLayer トレイトを実装しています。そのためtracing-subscriberにレイヤとして登録が可能、といったからくりのようです。

エラーとなるリクエストを送ると localhost:16686 にて画像のようにトレースを見れます。

jaeger.png

とにかく動いたからヨシ！

まとめ・所感

Rustのエラーハンドリング・ロギングにおいてtracingは避けては通れない存在になっており、まだまだ理解していない事項が多いですが今回自分なりにまとめられて良かったです。

tracingについては色々な方がもっとまともな入門記事を出してくださっているので、そちらの方を参照すると良いかなと思います。筆者もこれから精進します。

ここまで読んでいただきありがとうございました！メリークリスマス！

  1. 「普通のロギングではない構造化ログだからこそ素早く原因解明できる！」とか、「トレースやスパンのおかげでlogクレートとは異なり非同期処理にも強い！」といった話は確かに大切ですし役立ちますが、手を動かす機会が遠のくだけなのでこれらの話はオブザーバビリティの本でも買ってゆっくり電車内で読めばいいです。今の筆者です。 ↩

  2. その他の理由としては、本アドカレでほのめかしてきましたがthiserror + anyhowで十分Backtraceが取りまわせるようになってきたという背景もありそうです。 ↩

  3. 実は本記事の副目的にこの事実の裏取りもありました。無事にできたと思います。 ↩

  4. instrument...？楽器って何...？と最初思っていたのですが、和訳は計装で、測定器みたいな意味のようです。 ↩

  5. こういう時「自分が記事を書く必要あるんだろうか？」って気持ちになるのはあるあるですね。本記事について言えば今回は筆者にとっての学習ノートの位置づけなのでまぁ良しとします。一応本記事のオリジナリティという意味で行くとREADMEを読み解いているという点だろうか？ ↩

3
3
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
3
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?