diff --git a/distribution/lambda/Makefile b/distribution/lambda/Makefile index 639b52d4a73..2bb08fa4309 100644 --- a/distribution/lambda/Makefile +++ b/distribution/lambda/Makefile @@ -111,7 +111,7 @@ bench-index: done bench-search-term: - export QW_LAMBDA_LOG_SPAN_BOUNDARIES=true + export QW_LAMBDA_ENABLE_VERBOSE_JSON_LOGS=true mem_sizes=( 1024 2048 4096 8192 ) for mem_size in "$${mem_sizes[@]}" do @@ -121,7 +121,7 @@ bench-search-term: done bench-search-histogram: - export QW_LAMBDA_LOG_SPAN_BOUNDARIES=true + export QW_LAMBDA_ENABLE_VERBOSE_JSON_LOGS=true mem_sizes=( 1024 2048 4096 8192 ) for mem_size in "$${mem_sizes[@]}" do @@ -143,3 +143,7 @@ bench-search: test-mock-data-endpoints: python -c 'from cdk import cli; cli.test_mock_data_endpoints()' + + +dl-log: + python -c 'from cdk import cli; cli.download_logs_to_file("2c880455-b6e4-497e-80b9-b168b3cd0c46", "MockDataStack-QuickwitIndexerLambda3D0AD72D-2PbWB4ocAqpf",1711618460.0016074)' diff --git a/quickwit/quickwit-lambda/src/environment.rs b/quickwit/quickwit-lambda/src/environment.rs index 57f339d351d..ea916eacde4 100644 --- a/quickwit/quickwit-lambda/src/environment.rs +++ b/quickwit/quickwit-lambda/src/environment.rs @@ -24,10 +24,11 @@ use once_cell::sync::Lazy; pub static INDEX_ID: Lazy = Lazy::new(|| var("QW_LAMBDA_INDEX_ID").expect("QW_LAMBDA_INDEX_ID must be set")); -/// Configure the fmt tracing subscriber to log span boundaries. This is very verbose and is -/// only used to generate advanced KPIs from Lambda runs (e.g for blogpost benchmarks) -pub static LOG_SPAN_BOUNDARIES: Lazy = - Lazy::new(|| var("QW_LAMBDA_LOG_SPAN_BOUNDARIES").is_ok_and(|v| v.as_str() == "true")); +/// Configure the fmt tracing subscriber to log as json and include span +/// boundaries. This is very verbose and is only used to generate advanced KPIs +/// from Lambda runs (e.g for blog post benchmarks) +pub static ENABLE_VERBOSE_JSON_LOGS: Lazy = + Lazy::new(|| var("QW_LAMBDA_ENABLE_VERBOSE_JSON_LOGS").is_ok_and(|v| v.as_str() == "true")); pub static OPENTELEMETRY_URL: Lazy> = Lazy::new(|| var("QW_LAMBDA_OPENTELEMETRY_URL").ok()); diff --git a/quickwit/quickwit-lambda/src/logger.rs b/quickwit/quickwit-lambda/src/logger.rs index 632c0abc817..11e4d32ffd4 100644 --- a/quickwit/quickwit-lambda/src/logger.rs +++ b/quickwit/quickwit-lambda/src/logger.rs @@ -32,46 +32,76 @@ use tracing_subscriber::prelude::*; use tracing_subscriber::registry::LookupSpan; use tracing_subscriber::{EnvFilter, Layer}; -use crate::environment::{LOG_SPAN_BOUNDARIES, OPENTELEMETRY_AUTHORIZATION, OPENTELEMETRY_URL}; +use crate::environment::{ + ENABLE_VERBOSE_JSON_LOGS, OPENTELEMETRY_AUTHORIZATION, OPENTELEMETRY_URL, +}; static TRACER_PROVIDER: OnceCell> = OnceCell::new(); pub(crate) const RUNTIME_CONTEXT_SPAN: &str = "runtime_context"; -fn fmt_layer(level: Level) -> impl Layer -where - S: for<'a> LookupSpan<'a>, - S: tracing::Subscriber, -{ +fn fmt_env_filter(level: Level) -> EnvFilter { let default_filter = format!("quickwit={level}") .parse() .expect("Invalid default filter"); - let env_filter = EnvFilter::builder() + EnvFilter::builder() .with_default_directive(default_filter) - .from_env_lossy(); + .from_env_lossy() +} + +fn fmt_time_format() -> UtcTime>> { + // We do not rely on the Rfc3339 implementation, because it has a nanosecond precision. + // See discussion here: https://github.com/time-rs/time/discussions/418 + UtcTime::new( + time::format_description::parse( + "[year]-[month]-[day]T[hour]:[minute]:[second].[subsecond digits:3]Z", + ) + .expect("Time format invalid."), + ) +} + +fn compact_fmt_layer(level: Level) -> impl Layer +where + S: for<'a> LookupSpan<'a>, + S: tracing::Subscriber, +{ let event_format = tracing_subscriber::fmt::format() .with_target(true) - .with_timer( - // We do not rely on the Rfc3339 implementation, because it has a nanosecond precision. - // See discussion here: https://github.com/time-rs/time/discussions/418 - UtcTime::new( - time::format_description::parse( - "[year]-[month]-[day]T[hour]:[minute]:[second].[subsecond digits:3]Z", - ) - .expect("Time format invalid."), - ), - ) + .with_timer(fmt_time_format()) + .compact(); + + tracing_subscriber::fmt::layer::() + .event_format(event_format) + .with_ansi(false) + .with_filter(fmt_env_filter(level)) +} + +fn json_fmt_layer(level: Level) -> impl Layer +where + S: for<'a> LookupSpan<'a>, + S: tracing::Subscriber, +{ + let event_format = tracing_subscriber::fmt::format() + .with_target(true) + .with_timer(fmt_time_format()) .json(); - let fmt_span = if *LOG_SPAN_BOUNDARIES { - FmtSpan::NEW | FmtSpan::CLOSE - } else { - FmtSpan::NONE - }; tracing_subscriber::fmt::layer::() - .with_span_events(fmt_span) + .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) .event_format(event_format) .fmt_fields(JsonFields::default()) .with_ansi(false) - .with_filter(env_filter) + .with_filter(fmt_env_filter(level)) +} + +fn fmt_layer(level: Level) -> Box + Send + Sync + 'static> +where + S: for<'a> LookupSpan<'a>, + S: tracing::Subscriber, +{ + if *ENABLE_VERBOSE_JSON_LOGS { + json_fmt_layer(level).boxed() + } else { + compact_fmt_layer(level).boxed() + } } fn otlp_layer(