diff --git a/.changesets/fix_bnjjj_fix_log_level.md b/.changesets/fix_bnjjj_fix_log_level.md new file mode 100644 index 0000000000..29a242dc97 --- /dev/null +++ b/.changesets/fix_bnjjj_fix_log_level.md @@ -0,0 +1,9 @@ +### Set log level to `info` by default for the entire application ([PR #4451](https://github.com/apollographql/router/pull/4451)) + +By default the log level of the application if `RUST_LOG` is not set is `info` and if you provide `--log` or `APOLLO_RUST_LOG` value then it overrides the default `info` log level with `apollo_router=...` because it only impacts the `apollo_router` crate, not external custom plugin and so one. + +By doing this fix, by default if you have a custom plugin with info logs or metrics you won't have to enforce `RUST_LOG=info` everytime, it will work as expected. + +> Note: it doesn't impact the behavior of `RUST_LOG` if you set it. + +By [@bnjjj](https://github.com/bnjjj) in https://github.com/apollographql/router/pull/4451 \ No newline at end of file diff --git a/apollo-router/src/executable.rs b/apollo-router/src/executable.rs index 75bcd2ef3b..271e55c4f4 100644 --- a/apollo-router/src/executable.rs +++ b/apollo-router/src/executable.rs @@ -158,6 +158,7 @@ pub struct Opt { value_parser = add_log_filter, env = "APOLLO_ROUTER_LOG" )] + // FIXME: when upgrading to router 2.0 we should put this value in an Option log_level: String, /// Reload locally provided configuration and supergraph files automatically. This only affects watching of local files and does not affect supergraphs and configuration provided by GraphOS through Uplink, which is always reloaded immediately. @@ -262,10 +263,11 @@ fn add_log_filter(raw: &str) -> Result { let rgx = Regex::new(r"(^|,)(off|error|warn|info|debug|trace)").expect("regex must be valid"); let res = rgx.replace_all(&lowered, |caps: &Captures| { + // The default level is info, then other ones can override the default one // If the pattern matches, we must have caps 1 and 2 format!("{}apollo_router={}", &caps[1], &caps[2]) }); - Ok(res.into_owned()) + Ok(format!("info,{res}")) } } } @@ -732,7 +734,7 @@ mod tests { for level in ["off", "error", "warn", "info", "debug", "trace"] { assert_eq!( add_log_filter(level).expect("conversion works"), - format!("apollo_router={level}") + format!("info,apollo_router={level}") ); } } @@ -743,49 +745,49 @@ mod tests { // which is a reasonably corpus of things to test. #[test] fn complex_logging_modifications() { - assert_eq!(add_log_filter("hello").unwrap(), "hello"); - assert_eq!(add_log_filter("trace").unwrap(), "apollo_router=trace"); - assert_eq!(add_log_filter("TRACE").unwrap(), "apollo_router=trace"); - assert_eq!(add_log_filter("info").unwrap(), "apollo_router=info"); - assert_eq!(add_log_filter("INFO").unwrap(), "apollo_router=info"); - assert_eq!(add_log_filter("hello=debug").unwrap(), "hello=debug"); - assert_eq!(add_log_filter("hello=DEBUG").unwrap(), "hello=debug"); + assert_eq!(add_log_filter("hello").unwrap(), "info,hello"); + assert_eq!(add_log_filter("trace").unwrap(), "info,apollo_router=trace"); + assert_eq!(add_log_filter("TRACE").unwrap(), "info,apollo_router=trace"); + assert_eq!(add_log_filter("info").unwrap(), "info,apollo_router=info"); + assert_eq!(add_log_filter("INFO").unwrap(), "info,apollo_router=info"); + assert_eq!(add_log_filter("hello=debug").unwrap(), "info,hello=debug"); + assert_eq!(add_log_filter("hello=DEBUG").unwrap(), "info,hello=debug"); assert_eq!( add_log_filter("hello,std::option").unwrap(), - "hello,std::option" + "info,hello,std::option" ); assert_eq!( add_log_filter("error,hello=warn").unwrap(), - "apollo_router=error,hello=warn" + "info,apollo_router=error,hello=warn" ); assert_eq!( add_log_filter("error,hello=off").unwrap(), - "apollo_router=error,hello=off" + "info,apollo_router=error,hello=off" ); - assert_eq!(add_log_filter("off").unwrap(), "apollo_router=off"); - assert_eq!(add_log_filter("OFF").unwrap(), "apollo_router=off"); - assert_eq!(add_log_filter("hello/foo").unwrap(), "hello/foo"); - assert_eq!(add_log_filter("hello/f.o").unwrap(), "hello/f.o"); + assert_eq!(add_log_filter("off").unwrap(), "info,apollo_router=off"); + assert_eq!(add_log_filter("OFF").unwrap(), "info,apollo_router=off"); + assert_eq!(add_log_filter("hello/foo").unwrap(), "info,hello/foo"); + assert_eq!(add_log_filter("hello/f.o").unwrap(), "info,hello/f.o"); assert_eq!( add_log_filter("hello=debug/foo*foo").unwrap(), - "hello=debug/foo*foo" + "info,hello=debug/foo*foo" ); assert_eq!( add_log_filter("error,hello=warn/[0-9]scopes").unwrap(), - "apollo_router=error,hello=warn/[0-9]scopes" + "info,apollo_router=error,hello=warn/[0-9]scopes" ); // Add some hard ones assert_eq!( add_log_filter("hyper=debug,warn,regex=warn,h2=off").unwrap(), - "hyper=debug,apollo_router=warn,regex=warn,h2=off" + "info,hyper=debug,apollo_router=warn,regex=warn,h2=off" ); assert_eq!( add_log_filter("hyper=debug,apollo_router=off,regex=info,h2=off").unwrap(), - "hyper=debug,apollo_router=off,regex=info,h2=off" + "info,hyper=debug,apollo_router=off,regex=info,h2=off" ); assert_eq!( add_log_filter("apollo_router::plugins=debug").unwrap(), - "apollo_router::plugins=debug" + "info,apollo_router::plugins=debug" ); } } diff --git a/apollo-router/src/plugins/telemetry/reload.rs b/apollo-router/src/plugins/telemetry/reload.rs index bd677acc3e..93f566d05e 100644 --- a/apollo-router/src/plugins/telemetry/reload.rs +++ b/apollo-router/src/plugins/telemetry/reload.rs @@ -105,7 +105,7 @@ pub(crate) fn init_telemetry(log_level: &str) -> Result<()> { .get_or_try_init(move || { // manually filter salsa logs because some of them run at the INFO level https://github.com/salsa-rs/salsa/issues/425 let log_level = format!("{log_level},salsa=error"); - + tracing::debug!("Running the router with log level set to {log_level}"); // Env filter is separate because of https://github.com/tokio-rs/tracing/issues/1629 // the tracing registry is only created once tracing_subscriber::registry() diff --git a/examples/supergraph-sdl/rust/src/supergraph_sdl.rs b/examples/supergraph-sdl/rust/src/supergraph_sdl.rs index 3e13acd1e8..fe97bb95a5 100644 --- a/examples/supergraph-sdl/rust/src/supergraph_sdl.rs +++ b/examples/supergraph-sdl/rust/src/supergraph_sdl.rs @@ -39,6 +39,8 @@ impl Plugin for SupergraphSDL { // These allow basic interception and transformation of request and response messages. ServiceBuilder::new() .map_request(move |req: supergraph::Request| { + tracing::info!(monotonic_counter.test_counter = 1u64); + // If we have a query if let Some(query) = &req.supergraph_request.body().query { // Parse our query against the schema