rocketからopentelemetry-rustでトレースログを取得する

# 環境
* rustc 1.72.1 (d5c2e9c34 2023-09-13)
* macOS Ventura 13.6.1

```toml:Cargo.toml
[dependencies]
log = "0.4.20"
opentelemetry = { version = "0.20.0", features = ["trace"]  }
opentelemetry-otlp = { version = "0.13.0", features = ["trace"] }
opentelemetry-semantic-conventions = "0.13.0"
rocket = "0.5.0"
```

# 計装
```rust
#[get("/")]
fn index() -> &'static str {
    "Hello world"
}

// rocketの起動
#[rocket::main]
async fn main() -> Result<(), rocket::Error> {
    init_tracer();
    let _rocket = rocket::build()
        .register("/", catchers![not_found])
        .attach(TraceMiddleware {})
        .mount("/", routes![index, jobs])
        .launch()
        .await?;

    Ok(())
}

// opentelemetryのトレーサーライブラリの初期化
fn init_tracer() {
    let mut config = ExportConfig::default();
    config.endpoint = String::from("http://localhost:4317");
    match SpanExporter::new_tonic(config, TonicConfig::default()) {
        Ok(exporter) => {
            global::set_text_map_propagator(TraceContextPropagator::new());
            let provider = TracerProvider::builder()
                .with_simple_exporter(exporter)
                .with_config(trace::config().with_resource(Resource::new(vec![
                    KeyValue::new("service.name", "builder-api"),
                    KeyValue::new("span.kind", "server"),
                ])))
                .build();
            global::set_tracer_provider(provider);
        }
        Err(why) => panic!("{:?}", why),
    }
}

struct SpanContainer(Arc<Mutex<BoxedSpan>>);
impl SpanContainer {
    pub(crate) fn generate(request: &Request) -> Self {
        let tracer = global::tracer("builder-api");
        let headers: HashMap<String, String> = request
            .headers()
            .iter()
            .map(|header| {
                (
                    header.name().to_owned().to_string(),
                    header.value().to_owned().to_string(),
                )
            })
            .collect();
        let parent_cx = global::get_text_map_propagator(|propagater| propagater.extract(&headers));
        let span = tracer.start_with_context(
            format!(
                "{} {}",
                request.method().to_string(),
                request.uri().path().to_string()
            ),
            &parent_cx,
        );
        SpanContainer(Arc::new(Mutex::new(span)))
    }
}

#[rocket::async_trait]
impl Fairing for TraceFairing {
    fn info(&self) -> Info {
        Info {
            name: "trace",
            kind: Kind::Request | Kind::Response,
        }
    }

    async fn on_response<'r>(&self, request: &'r Request<'_>, response: &mut Response<'r>) {
        let mut span = request
            .local_cache(|| SpanContainer::generate(request))
            .0
            .lock()
            .unwrap();
        span.set_attribute(KeyValue::new(
            opentelemetry_semantic_conventions::trace::HTTP_RESPONSE_STATUS_CODE.to_string(),
            response.status().code as i64,
        ));
        span.end();
    }
    
    async fn on_request(&self, request: &mut Request<'_>, _: &mut Data<'_>) {
        let mut span = request
            .local_cache(|| SpanContainer::generate(request))
            .0
            .lock()
            .unwrap();
        span.set_attribute(KeyValue::new(
            opentelemetry_semantic_conventions::trace::HTTP_REQUEST_METHOD.to_string(),
            request.method().to_string(),
        ));
    }
}
```

# 解説
## まずはotelと関係のない部分
#[rocket::main]でrocketのエントリーポイントを指定しています。また、`#[get("/")]`でパス`/`へGETリクエストが来た場合の処理を記述しています。
init_tracer()呼び出し以外はotelと関係ありません。

```rust
#[get("/")]
fn index() -> &'static str {
    "Hello world"
}

// rocketの起動
#[rocket::main]
async fn main() -> Result<(), rocket::Error> {
    init_tracer();
    let _rocket = rocket::build()
        .register("/", catchers![not_found])
        .attach(TraceMiddleware {})
        .mount("/", routes![index, jobs])
        .launch()
        .await?;

    Ok(())
}
```

## Tracerの初期化
今回Open Telemetry Protocol(以下OTLP)でOpentelemetry Collector(以下OtelCol)へ送信しているので、[こちら](https://opentelemetry.io/docs/instrumentation/rust/exporters/)を参考にしています。
Railsの計装も試したことがありますが、Rustで書くと分量すごく増えますね。Goも同様だったイメージですが、静的型付け言語を扱うならそういうものなのかもしれません。

Tonicが現れるのは通信にGRPCが使われているからでしょうきっと。

```rust
// opentelemetryのトレーサーライブラリの初期化
fn init_tracer() {
    let mut config = ExportConfig::default();
    config.endpoint = String::from("http://localhost:4317");
    match SpanExporter::new_tonic(config, TonicConfig::default()) {
        Ok(exporter) => {
            global::set_text_map_propagator(TraceContextPropagator::new());
            let provider = TracerProvider::builder()
                .with_simple_exporter(exporter)
                .with_config(trace::config().with_resource(Resource::new(vec![
                    KeyValue::new("service.name", "builder-api"),
                    KeyValue::new("span.kind", "server"),
                ])))
                .build();
            global::set_tracer_provider(provider);
        }
        Err(why) => panic!("{:?}", why),
    }
}
```

## Spanを扱うstructの作成
なぜこんなものをわざわざ作るのか、なぜArcやMutexを使っているのか、ツッコミどころが多いですが次のFairingで説明します。
ここではリクエストヘッダーから呼び出し元のスパン情報を取得して、新しいスパンを作成しています。スパンのコンテキスト（おやすぱんの情報などなど）を受渡するのに`Propagater`を使用します。[こちら](https://opentelemetry.io/docs/specs/otel/context/api-propagators/)に仕様が定義されており、extractメソッドで、HashMapからコンテキスト情報を受け取ります。HTTPではヘッダにスパンの情報を載せるため、ヘッダからHashMapを作っています。

今回全てのヘッダーをプロぱゲーターに渡していますが、どの様なヘッダで情報が受け渡されているかは、W3Cの[Trace Context](https://www.w3.org/TR/trace-context/)として定義されている様です。親のSpanIDとかは`traceparent`ヘッダーに含まれています。

```rust
struct SpanContainer(Arc<Mutex<BoxedSpan>>);
impl SpanContainer {
    pub(crate) fn generate(request: &Request) -> Self {
        let tracer = global::tracer("builder-api");
        let headers: HashMap<String, String> = request
            .headers()
            .iter()
            .map(|header| {
                (
                    header.name().to_string(),
                    header.value().to_string(),
                )
            })
            .collect();
        let parent_cx = global::get_text_map_propagator(|propagater| propagater.extract(&headers));
        let span = tracer.start_with_context(
            // 第一引数はスパン名ですが、仮にGET / のようなMethod + Pathにしています。
            format!(
                "{} {}",
                request.method().to_string(),
                request.uri().path().to_string()
            ),
            &parent_cx,
        );
        SpanContainer(Arc::new(Mutex::new(span)))
    }
}
```

## Fairing
FairingはrocketのMiddlewareの様なものです。on_requestは各リクエストの最初、on_responseは最後に実行されます。spanの生成を行うにはちょうどいいのでFairing内でspan生成を行います。

リクエスト内でのスパンインスタンスの受け渡しには、リクエスト内での値の受け渡しに使用できる、`request.local_cache`を使用しています([ドキュメントはこちら](https://api.rocket.rs/v0.5/rocket/request/macro.local_cache.html))。local_cacheは渡したクロージャの戻り値の型が同じ時、前回呼び出しと同じ値を取得できる様です。

SpanをSpanコンテナーでラップしていますが、local_cacheはSendやSyncを必要としており、opentelemetryのspanストラクトはそれらを実装していないからです。SendやSyncを実装しているということは、複数のスレッドからアクセスされる、という意味なのでArcとMutexを使って参照可能にしたりlockを取得して変更可能にしたりしています。

on_requestとon_responseが一つのリクエスト内で同時に呼ばれることはないと思われるので、これで問題ないかもしれませんがrocketの[RequestGuard](https://rocket.rs/v0.5-rc/guide/requests/#request-guards)を使った場合は同時アクセスが起こってもおかしくないのでデッドロックなど気をつけないと行けなさそうですね。

今回RequestMethodとResponse Codeだけ`set_attribute`を使って記録していますが、こちらの[Semantic Conventions](https://opentelemetry.io/docs/specs/semconv/http/http-spans/)に従って各種情報を載せるとより良いです(MUSTって書いてあるので載せなければならない、が正しいでしょうが、ね！)。

```rust
#[rocket::async_trait]
impl Fairing for TraceFairing {
    fn info(&self) -> Info {
        Info {
            name: "trace",
            kind: Kind::Request | Kind::Response,
        }
    }

    async fn on_response<'r>(&self, request: &'r Request<'_>, response: &mut Response<'r>) {
        let mut span = request
            .local_cache(|| SpanContainer::generate(request))
            .0
            .lock()
            .unwrap();
        span.set_attribute(KeyValue::new(
            opentelemetry_semantic_conventions::trace::HTTP_RESPONSE_STATUS_CODE.to_string(),
            response.status().code as i64,
        ));
        span.end();
    }
    async fn on_request(&self, request: &mut Request<'_>, _: &mut Data<'_>) {
        let mut span = request
            .local_cache(|| SpanContainer::generate(request))
            .0
            .lock()
            .unwrap();
        span.set_attribute(KeyValue::new(
            opentelemetry_semantic_conventions::trace::HTTP_REQUEST_METHOD.to_string(),
            request.method().to_string(),
        ));
    }
}
```

# JAEGERでトレースデータを見てみる
![スクリーンショット 2023-12-18 14.16.19.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/223111/8626efdd-546f-8f95-55d4-ddffebd02723.png)

`builder-api`と書かれているところが今回rocketで実装した部分ですね。そのほかはrocketを呼び出しているRailsのトレースです。この様に、呼び出しものと情報を関連づけて実装することができました。

※builder-apiのスパンの位置が本来ありそうな場所とすごくずれていますが、railsはdocker上、rustはホストマシン上で実行しているため時間がズレるみたいですね([参考](https://qiita.com/mittun/items/09f2d61dda9181bac65e))。

# 最後に
現在SREとして働かせていただいていますが、サービス内で起きたことを把握するためにトレースデータの様なものはますます重要になってきていると思います。
ですが言語やフレームワークは様々で、それぞれどう軽装したらいのか、、と悩むことが多くありそうなのでこう言ったサンプルをこれからも作っていければと思います。