Files
packager/src/telemetry/tracing/mod.rs

248 lines
7.9 KiB
Rust
Raw Normal View History

2023-08-29 21:34:01 +02:00
use std::fmt;
2023-08-29 21:34:01 +02:00
use std::future::Future;
2023-08-29 21:34:01 +02:00
use std::io;
2023-08-29 21:34:01 +02:00
use std::pin::Pin;
2023-08-29 21:34:01 +02:00
use std::time::Duration;
use axum::Router;
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
use http::Request;
use tower_http::{classify::ServerErrorsFailureClass, trace::TraceLayer};
2023-08-29 21:34:01 +02:00
use tracing::Span;
2023-08-29 21:34:01 +02:00
use tracing_subscriber::{
filter::{LevelFilter, Targets},
2023-08-29 21:34:01 +02:00
fmt::{format::Format, Layer},
2023-08-29 21:34:01 +02:00
layer::SubscriberExt,
prelude::*,
2023-08-29 21:34:01 +02:00
registry::Registry,
2023-08-29 21:34:01 +02:00
};
2023-08-29 21:34:01 +02:00
use tracing::Instrument;
use uuid::Uuid;
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
#[cfg(feature = "jaeger")]
2023-08-29 21:34:01 +02:00
use opentelemetry::{global, runtime::Tokio};
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
pub enum OpenTelemetryConfig {
Enabled,
Disabled,
2023-08-29 21:34:01 +02:00
}
2023-08-29 21:34:01 +02:00
pub enum TokioConsoleConfig {
Enabled,
Disabled,
}
2023-08-29 21:34:01 +02:00
fn get_stdout_layer<
T: tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
>() -> impl tracing_subscriber::Layer<T> {
2023-08-29 21:34:01 +02:00
// default is the Full format, there is no way to specify this, but it can be
// overridden via builder methods
let stdout_format = Format::default()
.pretty()
.with_ansi(true)
.with_target(true)
.with_level(true)
.with_file(false);
let stdout_filter = Targets::new()
2023-08-29 21:34:01 +02:00
.with_default(LevelFilter::WARN)
2023-08-29 21:34:01 +02:00
.with_targets(vec![
2023-08-29 21:34:01 +02:00
(env!("CARGO_PKG_NAME"), LevelFilter::DEBUG),
2023-08-29 21:34:01 +02:00
("sqlx", LevelFilter::DEBUG),
2023-08-29 21:34:01 +02:00
("runtime", LevelFilter::OFF),
2023-08-29 21:34:01 +02:00
("tokio", LevelFilter::OFF),
2023-08-29 21:34:01 +02:00
]);
2023-08-29 21:34:01 +02:00
let stdout_layer = Layer::default()
.event_format(stdout_format)
.with_writer(io::stdout)
.with_filter(stdout_filter);
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
stdout_layer.boxed()
}
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
trait Forwarder {
type Config;
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
fn build(
config: Self::Config,
2023-09-11 19:47:51 +02:00
shutdown_functions: &mut Vec<ShutdownFunction>,
2023-08-29 21:34:01 +02:00
) -> Option<Box<dyn tracing_subscriber::Layer<dyn tracing::Subscriber>>>;
}
2023-08-29 21:34:01 +02:00
#[cfg(feature = "jaeger")]
2023-08-29 21:34:01 +02:00
fn get_jaeger_layer<
T: tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
>(
2023-09-11 19:47:51 +02:00
config: &OpenTelemetryConfig,
shutdown_functions: &mut Vec<ShutdownFunction>,
2023-08-29 21:34:01 +02:00
) -> Option<impl tracing_subscriber::Layer<T>> {
2023-08-29 21:34:01 +02:00
match config {
2023-08-29 21:34:01 +02:00
OpenTelemetryConfig::Enabled => {
global::set_text_map_propagator(opentelemetry_jaeger::Propagator::new());
// Sets up the machinery needed to export data to Jaeger
// There are other OTel crates that provide pipelines for the vendors
// mentioned earlier.
let tracer = opentelemetry_jaeger::new_agent_pipeline()
.with_service_name(env!("CARGO_PKG_NAME"))
.with_max_packet_size(20_000)
.with_auto_split_batch(true)
2023-08-29 21:34:01 +02:00
.install_batch(Tokio)
2023-08-29 21:34:01 +02:00
.unwrap();
let opentelemetry_filter = {
Targets::new()
.with_default(LevelFilter::DEBUG)
.with_targets(vec![
(env!("CARGO_PKG_NAME"), LevelFilter::DEBUG),
2023-08-29 21:34:01 +02:00
("sqlx", LevelFilter::DEBUG),
2023-08-29 21:34:01 +02:00
("runtime", LevelFilter::OFF),
2023-08-29 21:34:01 +02:00
("tokio", LevelFilter::OFF),
2023-08-29 21:34:01 +02:00
])
};
2023-08-29 21:34:01 +02:00
let opentelemetry_layer = tracing_opentelemetry::layer()
.with_tracer(tracer)
.with_filter(opentelemetry_filter);
2023-08-29 21:34:01 +02:00
shutdown_functions.push(Box::new(|| {
global::shutdown_tracer_provider();
Ok(())
}));
Some(opentelemetry_layer)
}
OpenTelemetryConfig::Disabled => None,
2023-08-29 21:34:01 +02:00
}
2023-08-29 21:34:01 +02:00
}
2023-09-11 19:47:51 +02:00
type ShutdownFunction = Box<dyn FnOnce() -> Result<(), Box<dyn std::error::Error>>>;
2023-08-29 21:34:01 +02:00
pub async fn init<Func, T>(
#[cfg(feature = "jaeger")] opentelemetry_config: OpenTelemetryConfig,
#[cfg(feature = "tokio-console")] tokio_console_config: TokioConsoleConfig,
args: crate::cli::Args,
2023-08-29 21:34:01 +02:00
f: Func,
) -> T
where
2023-08-29 21:34:01 +02:00
Func: FnOnce(crate::cli::Args) -> Pin<Box<dyn Future<Output = T>>>,
2023-08-29 21:34:01 +02:00
T: std::process::Termination,
{
2023-08-29 21:34:01 +02:00
// mut is dependent on features (it's only required when jaeger is set), so
// let's just disable the lint
#[cfg(feature = "jaeger")]
2023-09-11 19:47:51 +02:00
let mut shutdown_functions: Vec<ShutdownFunction> = vec![];
2023-08-29 21:34:01 +02:00
#[cfg(not(feature = "jaeger"))]
2023-09-11 19:47:51 +02:00
let shutdown_functions: Vec<ShutdownFunction> = vec![];
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
#[cfg(feature = "tokio-console")]
2023-08-29 21:34:01 +02:00
let console_layer = match tokio_console_config {
TokioConsoleConfig::Enabled => Some(console_subscriber::Builder::default().spawn()),
TokioConsoleConfig::Disabled => None,
};
let stdout_layer = get_stdout_layer();
2023-08-29 21:34:01 +02:00
#[cfg(feature = "jaeger")]
2023-09-11 19:47:51 +02:00
let jaeger_layer = get_jaeger_layer(&opentelemetry_config, &mut shutdown_functions);
2023-08-29 21:34:01 +02:00
2023-08-29 21:34:01 +02:00
let registry = Registry::default();
#[cfg(feature = "tokio-console")]
let registry = registry.with(console_layer);
#[cfg(feature = "jaeger")]
let registry = registry.with(jaeger_layer);
// just an example, you can actuall pass Options here for layers that might be
// set/unset at runtime
let registry = registry.with(stdout_layer).with(None::<Layer<_>>);
2023-08-29 21:34:01 +02:00
tracing::subscriber::set_global_default(registry).unwrap();
2023-08-29 21:34:01 +02:00
tracing_log::log_tracer::Builder::new().init().unwrap();
2023-08-29 21:34:01 +02:00
let result = f(args)
.instrument(tracing::debug_span!(target: env!("CARGO_PKG_NAME"), env!("CARGO_PKG_NAME")))
.await;
2023-08-29 21:34:01 +02:00
for shutdown_func in shutdown_functions {
shutdown_func().unwrap();
}
result
2023-08-29 21:34:01 +02:00
}
struct Latency(Duration);
impl fmt::Display for Latency {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.0.as_micros())
}
}
pub fn init_request_tracing(router: Router) -> Router {
router.layer(
TraceLayer::new_for_http()
.make_span_with(|_request: &Request<_>| {
let request_id = Uuid::new_v4();
tracing::debug_span!(
2023-08-29 21:34:01 +02:00
target: "packager::request",
2023-08-29 21:34:01 +02:00
"request",
%request_id,
)
})
.on_request(|request: &Request<_>, _span: &Span| {
let request_headers = request.headers();
let http_version = request.version();
tracing::debug!(
2023-08-29 21:34:01 +02:00
target: "packager::request",
2023-08-29 21:34:01 +02:00
method = request.method().as_str(),
path = request.uri().path(),
?http_version,
?request_headers,
"request received",
);
})
.on_response(
|response: &axum::response::Response, latency: Duration, _span: &Span| {
let response_headers = response.headers();
let latency = Latency(latency);
tracing::debug!(
2023-08-29 21:34:01 +02:00
target: "packager::request",
2023-08-29 21:34:01 +02:00
%latency,
status = response.status().as_str(),
?response_headers,
"finished processing request",
);
},
)
.on_failure(
|error: ServerErrorsFailureClass, latency: Duration, _span: &Span| {
let latency = Latency(latency);
match error {
ServerErrorsFailureClass::StatusCode(code) => {
tracing::error!(
2023-08-29 21:34:01 +02:00
target: "packager::request",
2023-08-29 21:34:01 +02:00
%latency,
"request failed with error response {}",
code,
);
}
ServerErrorsFailureClass::Error(message) => {
tracing::error!(
2023-08-29 21:34:01 +02:00
target: "packager::request",
2023-08-29 21:34:01 +02:00
%latency,
"request failed: {}",
message,
);
}
}
},
),
)
}