tracing-actix-web

tracing-actix-web copied to clipboard

The root span request doesn't recorded in actix-web built-in middleware::Logger + LogTracer

use actix_web::{dev::Service as _, web, App, HttpRequest, HttpServer, Responder};
use actix_web::{middleware::Logger, HttpMessage};
use futures_util::future::FutureExt;
use tracing::info;
use tracing::subscriber::set_global_default;
use tracing_actix_web::{RootSpan, TracingLogger};
use tracing_log::LogTracer;
use tracing_subscriber::prelude::*;

async fn index(_req: HttpRequest) -> impl Responder {
    info!("hello world");
    log::info!("yaya");
    // req.extensions().get::<Level>().unwrap().clone();
    "Hello world!"
}

#[actix_web::main]
async fn main() -> std::io::Result<()> {
    LogTracer::init_with_filter(log::LevelFilter::Trace).expect("Failed to set logger");

    let fmt_layer = tracing_subscriber::fmt::layer()
        .with_file(true)
        .with_line_number(true);
    let filter_layer = tracing_subscriber::EnvFilter::try_from_default_env()
        .or_else(|_| tracing_subscriber::EnvFilter::try_new("debug"))
        .unwrap();

    let subscriber = tracing_subscriber::registry()
        .with(filter_layer)
        .with(fmt_layer);
    // `set_global_default` can be used by applications to specify
    // what subscriber should be used to process spans.
    set_global_default(subscriber).expect("Failed to set subscriber");

    HttpServer::new(|| {
        App::new()
            .wrap_fn(|req, srv| {
                info!("Hi from start. You requested: {}", req.path());
                let root_span = req.extensions().get::<RootSpan>().unwrap().clone();
                // root_span.
                root_span.in_scope(|| {
                    info!("hello you");
                });

                srv.call(req).map(|res| {
                    if res.is_ok() {
                        let req = res.as_ref().expect("error").request();
                        let root_span = req.extensions().get::<RootSpan>().unwrap().clone();
                        root_span.in_scope(|| {
                            info!("Request ends.");
                        });
                    }
                    res
                })
            })
            .wrap(Logger::default())
            .wrap(TracingLogger::default())
            .service(
                // prefixes all resources and routes attached to it...
                web::scope("/app")
                    // ...so this handles requests for `GET /app/index.html`
                    .route("/index.html", web::get().to(index)),
            )
    })
    .bind(("127.0.0.1", 8080))?
    .run()
    .await
}

2024-06-11T17:55:49.661103Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: log: Hi from start. You requested: /app/index.html    
2024-06-11T17:55:49.661140Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: rust_tracing: src/main.rs:39: Hi from start. You requested: /app/index.html
2024-06-11T17:55:49.661157Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: rust_tracing: src/main.rs:43: hello you
2024-06-11T17:55:49.661196Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: rust_tracing: src/main.rs:12: hello world
2024-06-11T17:55:49.661210Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: log: yaya    
2024-06-11T17:55:49.661238Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: rust_tracing: src/main.rs:51: Request ends.
2024-06-11T17:55:49.661253Z  INFO HTTP request{http.method=GET http.route=/app/index.html http.flavor=1.1 http.scheme=http http.host=localhost:8080 http.client_ip=127.0.0.1 http.user_agent=Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0 http.target=/app/index.html otel.name=HTTP GET /app/index.html otel.kind="server" request_id=42f53529-c770-48fe-8e2c-76b68948b0ad}: log: Hi from response    
2024-06-11T17:55:49.661303Z  INFO log: 127.0.0.1 "GET /app/index.html HTTP/1.1" 200 12 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:127.0) Gecko/20100101 Firefox/127.0" 0.000235

The last line is from middleware::Logger.