ambiorix icon indicating copy to clipboard operation
ambiorix copied to clipboard

use RFC 3339 for logging

Open JosiahParry opened this issue 1 year ago • 2 comments

Using the json web api example the output for logging is non-standard.

✔ 03-01-2025 13:53:53 Listening on http://0.0.0.0:3000
✖ 03-01-2025 13:53:58 GET on / - Not found
✖ 03-01-2025 13:53:58 GET on /favicon.ico - Not found
✖ 03-01-2025 13:54:13 GET on /members/1 - Not found
✖ 03-01-2025 13:54:15 GET on /members/2 - Not found
ℹ 03-01-2025 13:54:28 GET on /api/members/2

It would be awesome if this followed the rfc 3339 (subset of iso 8601 for formatting) this would make it compatible with other tracing / logging format.

I would ideally like something like:

yyyy-mm-dd hh:mm:ss [log level] GET on / - Not found

So translating this:

2025-01-03 13:53:53 INFO ✔ Listening on http://0.0.0.0:3000
2025-01-03 13:53:58 ERROR ✖ GET on / - Not found
2025-01-03 13:53:58 ERROR ✖ GET on /favicon.ico - Not found
2025-01-03 13:54:13 ERROR ✖ GET on /members/1 - Not found
2025-01-03 13:54:15 ERROR ✖ GET on /members/2 - Not found
2025-01-03 13:54:28 INFO ℹ  GET on /api/members/2

JosiahParry avatar Jan 03 '25 22:01 JosiahParry

@JosiahParry do you know of an existing package that would do structured logging with formatted printing as you have suggest here? (thinking two birds with one stone)

JohnCoene avatar Jan 03 '25 23:01 JohnCoene

I am most familiar with this via tracing in the rust ecosystem which has a number of formatters for logging based on the use case https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/index.html.

The idea behind the provided formatters is actually quite nice and i wonder if there could be a global setting here for ambiorix as well—could lean on logger for this. tracing has 4 provided formatters:

  • Full: human readable
  • Compact: short line lengths
  • Pretty: human readable not sensitive to storage
  • Json: for integration into OpenTelemetry systems like prometheus and jaeger etc.

Here is the output from logging a hello world application in rust using the axum web framework and the default formatter (Full)

2025-01-04T19:15:24.576721Z DEBUG my_hands: listening on 127.0.0.1:3000
2025-01-04T19:15:27.654242Z TRACE axum::serve: connection 127.0.0.1:61377 accepted
2025-01-04T19:15:27.656231Z DEBUG request{method=GET uri=/ version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2025-01-04T19:15:27.656380Z DEBUG request{method=GET uri=/ version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200

Code to recreate

src/main.rs

use axum::{response::Html, routing::get, Router};
use tokio::net::TcpListener;
use tower_http::trace::TraceLayer;
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};

#[tokio::main]
async fn main() {
    // add basic tracing information
    let tracing_layer = tracing_subscriber::fmt::layer();
    tracing_subscriber::registry().with(tracing_layer).init();

    // add hello world route
    let app = Router::new()
        .route("/", get(handler))
        .layer(TraceLayer::new_for_http());

    // run web server
    let listener = TcpListener::bind("127.0.0.1:3000").await.unwrap();
    tracing::debug!("listening on {}", listener.local_addr().unwrap());
    axum::serve(listener, app).await.unwrap();
}

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

Cargo.toml

[package]
name = "my-hands"
version = "0.1.0"
edition = "2021"

[dependencies]
axum = { version = "0.8.1", features = ["tracing"] }
tokio = { version = "1.41.1", features = ["rt-multi-thread"] }
tower-http = { version = "0.6.2", features = ["trace"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.19", features = ["env-filter"] }

JosiahParry avatar Jan 04 '25 19:01 JosiahParry