httpd: Change format of tracing messages

Signed-off-by: xphoniex <dj.2dixx@gmail.com>
This commit is contained in:
xphoniex 2023-03-02 16:59:42 +00:00 committed by Alexis Sellier
parent dd7e3923b5
commit 077c040c08
No known key found for this signature in database
4 changed files with 108 additions and 18 deletions

View File

@ -24,8 +24,8 @@ fastrand = { version = "1.7.0" }
flate2 = { version = "1" } flate2 = { version = "1" }
hyper = { version = "0.14.17", default-features = false } hyper = { version = "0.14.17", default-features = false }
lexopt = { version = "0.2.1" } lexopt = { version = "0.2.1" }
radicle-surf = { version = "0.9.0", default-features = false, features = ["serde"] }
nonempty = { version = "0.8.1", features = ["serialize"] } nonempty = { version = "0.8.1", features = ["serialize"] }
radicle-surf = { version = "0.9.0", default-features = false, features = ["serde"] }
serde = { version = "1", features = ["derive"] } serde = { version = "1", features = ["derive"] }
serde_json = { version = "1", features = ["preserve_order"] } serde_json = { version = "1", features = ["preserve_order"] }
thiserror = { version = "1" } thiserror = { version = "1" }
@ -40,10 +40,12 @@ tracing-subscriber = { version = "0.3", default-features = false, features = ["s
path = "../radicle" path = "../radicle"
version = "0.2.0" version = "0.2.0"
[dependencies.radicle-cli]
path = "../radicle-cli"
[dev-dependencies] [dev-dependencies]
hyper = { version = "0.14.17", default-features = false, features = ["client"] } hyper = { version = "0.14.17", default-features = false, features = ["client"] }
pretty_assertions = { version = "1.3.0" } pretty_assertions = { version = "1.3.0" }
radicle-cli = { path = "../radicle-cli" }
radicle-crypto = { path = "../radicle-crypto" } radicle-crypto = { path = "../radicle-crypto" }
tempfile = { version = "3.3.0" } tempfile = { version = "3.3.0" }
tower = { version = "0.4", features = ["util"] } tower = { version = "0.4", features = ["util"] }

View File

@ -8,12 +8,15 @@ use std::str;
use std::sync::Arc; use std::sync::Arc;
use std::time::Duration; use std::time::Duration;
use ::tracing::Span;
use anyhow::Context as _; use anyhow::Context as _;
use axum::body::{Body, BoxBody}; use axum::body::{Body, BoxBody, HttpBody};
use axum::http::{Request, Response}; use axum::http::{Request, Response};
use axum::middleware;
use axum::Router; use axum::Router;
use tower_http::trace::TraceLayer; use tower_http::trace::TraceLayer;
use tracing::Span;
use tracing_extra::{tracing_middleware, ColoredStatus, Paint, RequestId, TracingInfo};
mod api; mod api;
mod axum_extra; mod axum_extra;
@ -21,6 +24,7 @@ mod git;
mod raw; mod raw;
#[cfg(test)] #[cfg(test)]
mod test; mod test;
mod tracing_extra;
#[derive(Debug, Clone)] #[derive(Debug, Clone)]
pub struct Options { pub struct Options {
@ -38,6 +42,7 @@ pub async fn run(options: Options) -> anyhow::Result<()> {
tracing::info!("{}", str::from_utf8(&git_version)?.trim()); tracing::info!("{}", str::from_utf8(&git_version)?.trim());
let profile = Arc::new(radicle::Profile::load()?); let profile = Arc::new(radicle::Profile::load()?);
let request_id = RequestId::new();
tracing::info!("using radicle home at {}", profile.home().display()); tracing::info!("using radicle home at {}", profile.home().display());
@ -52,23 +57,36 @@ pub async fn run(options: Options) -> anyhow::Result<()> {
.merge(git_router) .merge(git_router)
.nest("/api", api_router) .nest("/api", api_router)
.nest("/raw", raw_router) .nest("/raw", raw_router)
.layer(middleware::from_fn(tracing_middleware))
.layer( .layer(
TraceLayer::new_for_http() TraceLayer::new_for_http()
.make_span_with(|request: &Request<Body>| { .make_span_with(move |_request: &Request<Body>| {
tracing::info_span!( tracing::info_span!("request", id = %request_id.clone().next())
"request",
method = %request.method(),
uri = %request.uri(),
status = tracing::field::Empty,
latency = tracing::field::Empty,
)
}) })
.on_response( .on_response(
|response: &Response<BoxBody>, latency: Duration, span: &Span| { |response: &Response<BoxBody>, latency: Duration, _span: &Span| {
span.record("status", &tracing::field::debug(response.status())); if let Some(info) = response.extensions().get::<TracingInfo>() {
span.record("latency", &tracing::field::debug(latency)); tracing::info!(
"{} \"{} {} {:?}\" {} {:?} {}",
tracing::info!("Processed"); info.connect_info.0,
info.method,
info.uri,
info.version,
ColoredStatus(response.status()),
latency,
Paint::dim(
response
.body()
.size_hint()
.exact()
.map(|n| n.to_string())
.unwrap_or("0".to_string())
.into()
),
);
} else {
tracing::info!("Processed");
}
}, },
), ),
) )

View File

@ -18,7 +18,9 @@ mod logger {
#[cfg(not(feature = "logfmt"))] #[cfg(not(feature = "logfmt"))]
mod logger { mod logger {
pub fn subscriber() -> impl tracing::Subscriber { pub fn subscriber() -> impl tracing::Subscriber {
tracing_subscriber::FmtSubscriber::new() tracing_subscriber::FmtSubscriber::builder()
.with_target(false)
.finish()
} }
} }

View File

@ -0,0 +1,68 @@
use std::fmt;
use std::net::SocketAddr;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::Arc;
use axum::extract::ConnectInfo;
use axum::http::Request;
use axum::middleware::Next;
use axum::response::IntoResponse;
use axum::Extension;
use hyper::{Method, StatusCode, Uri, Version};
pub use radicle_cli::terminal::ansi::Paint;
#[derive(Clone)]
pub struct RequestId(Arc<AtomicU64>);
impl RequestId {
pub fn new() -> RequestId {
RequestId(Arc::new(0.into()))
}
pub fn next(&mut self) -> u64 {
self.0.fetch_add(1, Ordering::SeqCst)
}
}
pub struct TracingInfo {
pub connect_info: ConnectInfo<SocketAddr>,
pub method: Method,
pub version: Version,
pub uri: Uri,
}
pub struct ColoredStatus(pub StatusCode);
impl fmt::Display for ColoredStatus {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
match self.0.as_u16() {
200..=299 => write!(f, "{}", Paint::green(self.0)),
300..=399 => write!(f, "{}", Paint::blue(self.0)),
400..=499 => write!(f, "{}", Paint::red(self.0)),
_ => write!(f, "{}", Paint::yellow(self.0)),
}
}
}
pub async fn tracing_middleware<B>(request: Request<B>, next: Next<B>) -> impl IntoResponse {
let connect_info = *request
.extensions()
.get::<ConnectInfo<std::net::SocketAddr>>()
.unwrap();
let method = request.method().clone();
let version = request.version();
let uri = request.uri().clone();
let tracing_info = TracingInfo {
connect_info,
method,
version,
uri,
};
let response = next.run(request).await;
(Extension(tracing_info), response)
}