Where's the most basic example for HTTP request logging?

[gd87429]

Feature Request

Motivation

It'd be nice to have a simple example that I can throw into axum/tower so the server log requests show up like this:

127.0.0.1 "GET /v1/example HTTP/1.1" 200 826 "-" "user-agent" 0.177071

Currently, while checking out the example folder for axum:

1. It logs too much to the point where it's not useful / easy to understand what requests occurred.
2. I have to use RUST_LOG just to see requests (and I'm not even sure which to use).

Isn't there a one-liner I can use just to have some reasonably pretty request logging so I can see what endpoints have been called?

[davidpdrsn]

All the things on TraceLayer are configurable so it should be possible to get that kind of output. You're welcome to contribute an example.

tracing-subscriber requires setting RUST_LOG at least for some subscribers. Nothing tower-http can do about that.

[gd87429]

Thank you for your time.

[davidalger]

@gd87429 Doesn't get quite the same concise output that you'd see with axtic-web (as shown in your desired log format above) but the following will log requests in a fairly simple way without requiring RUST_LOG to be set:

use axum::{http::StatusCode, routing::get, Router};
use tokio;
use tower_http::trace::{self, TraceLayer};
use tracing::Level;

#[tokio::main]
async fn main() {
    tracing_subscriber::fmt::init();

    let app = Router::new()
        .route("/health", get(health))
        .route("/error", get(error))
        .layer(
            TraceLayer::new_for_http()
                .make_span_with(trace::DefaultMakeSpan::new().level(Level::INFO))
                .on_response(trace::DefaultOnResponse::new().level(Level::INFO)),
        );

    axum::Server::bind(&"127.0.0.1:8080".parse().unwrap())
        .serve(app.into_make_service())
        .await
        .unwrap();
}

async fn health() -> Result<&'static str, StatusCode> {
    Ok("UP")
}

async fn error() -> Result<&'static str, StatusCode> {
    Err(StatusCode::SERVICE_UNAVAILABLE)
}

[dependencies]
tokio = { version = "1", features = ["macros", "rt-multi-thread"] }
axum = { version = "0.5" }
tower-http = { version = "0.3", features = ["trace"] }
tracing = { version = "0.1" }
tracing-subscriber = { version = "0.3" }

The resulting logs:

2022-11-02T19:15:23.983657Z  INFO request{method=GET uri=/health version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200
2022-11-02T19:15:29.155543Z  INFO request{method=GET uri=/error version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=503
2022-11-02T19:15:29.155925Z ERROR request{method=GET uri=/error version=HTTP/1.1}: tower_http::trace::on_failure: response failed classification=Status code: 503 Service Unavailable latency=0 ms

Changing the first line in main to this will shorten things up a bit more:

    tracing_subscriber::fmt()
        .with_target(false)
        .compact()
        .init();

2022-11-02T19:19:03.742465Z  INFO request: finished processing request latency=1 ms status=200 method=GET uri=/health version=HTTP/1.1
2022-11-02T19:19:05.220886Z  INFO request: finished processing request latency=0 ms status=503 method=GET uri=/error version=HTTP/1.1
2022-11-02T19:19:05.221247Z ERROR request: response failed classification=Status code: 503 Service Unavailable latency=0 ms method=GET uri=/error version=HTTP/1.1

Not quite what you're wanting, but HTH!

[gd87429]

@davidalger It does help, thank you for the detailed response.