Constrain APOLLO_ROUTER_LOG and --log global levels to the router (#3477

)

It would be nice if users could specify just a log level and the router
applied the required filtering to constrain the logging to the
`apollo_router` module.

It would also be nice if, for advanced users, you could exercise the
full power of a logging filter.

This PR enables both these use cases.

If you set a filter using `RUST_LOG`, it is used as is.

If you set it using `APOLLO_ROUTER_LOG` or `--log`, then any "global"
scope levels are constrained to `apollo_router`.

Thus:

```
RUST_LOG=apollo_router=warn
--log warn
APOLLO_ROUTER_LOG=warn
```

are equivalent with all three statements resulting in `warn` level
logging for the router.

For more details, read the logging configuration documentation.

fixes: #3474

<!-- start metadata -->

**Checklist**

Complete the checklist (and note appropriate exceptions) before a final
PR is raised.

- [ ] Changes are compatible[^1]
- [x] Documentation[^2] completed
- [ ] Performance impact assessed and acceptable
- Tests added and passing[^3]
    - [x] Unit Tests
    - [ ] Integration Tests
    - [ ] Manual Tests

**Exceptions**

*Note any exceptions here*

**Notes**

[^1]. It may be appropriate to bring upcoming changes to the attention
of other (impacted) groups. Please endeavour to do this before seeking
PR approval. The mechanism for doing this will vary considerably, so use
your judgement as to how and when to do this.
[^2]. Configuration is an important part of many changes. Where
applicable please try to document configuration examples.
[^3]. Tick whichever testing boxes are applicable. If you are adding
Manual Tests:
- please document the manual testing (extensively) in the Exceptions.
- please raise a separate issue to automate the test and label it (or
ask for it to be labeled) as `manual test`

---------

Co-authored-by: Bryn Cooke <BrynCooke@gmail.com>

.changesets/feat_garypen_3474_log_filter.md

@@ -0,0 +1,19 @@
+### Constrain APOLLO_ROUTER_LOG and --log global levels to the router ([Issue #3474](https://github.com/apollographql/router/issues/3474))
+
+`APOLLO_ROUTER_LOG` and `--log` now implicitly set a filter constraining the logging to the `apollo_router` module, simplifying the debugging experience for users.
+
+For advanced users `RUST_LOG` can be used for standard log filter behavior.
+
+Thus:
+
+```
+RUST_LOG=apollo_router=warn
+--log warn
+APOLLO_ROUTER_LOG=warn
+```
+
+are equivalent with all three statements resulting in `warn` level logging for the router.
+
+For more details, read the logging configuration documentation.
+
+By [@garypen](https://github.com/garypen) in https://github.com/apollographql/router/pull/3477

apollo-router/src/executable.rs

@@ -20,6 +20,8 @@ use clap::Subcommand;
 use directories::ProjectDirs;
 #[cfg(any(feature = "dhat-heap", feature = "dhat-ad-hoc"))]
 use once_cell::sync::OnceCell;
+use regex::Captures;
+use regex::Regex;
 use url::ParseError;
 use url::Url;
 
@@ -151,6 +153,7 @@ pub struct Opt {
         long = "log",
         default_value = "info",
         alias = "log-level",
+        value_parser = add_log_filter,
         env = "APOLLO_ROUTER_LOG"
     )]
     log_level: String,
@@ -241,6 +244,27 @@ pub struct Opt {
     pub(crate) version: bool,
 }
 
+// Add a filter to global log level settings so that the level only applies to the router.
+//
+// If you want to set a complex logging filter which isn't modified in this way, use RUST_LOG.
+fn add_log_filter(raw: &str) -> Result<String, String> {
+    match std::env::var("RUST_LOG") {
+        Ok(filter) => Ok(filter),
+        Err(_e) => {
+            // Directives are case-insensitive. Convert to lowercase before processing.
+            let lowered = raw.to_lowercase();
+            // Find "global" directives and limit them to apollo_router
+            let rgx =
+                Regex::new(r"(^|,)(off|error|warn|info|debug|trace)").expect("regex must be valid");
+            let res = rgx.replace_all(&lowered, |caps: &Captures| {
+                // If the pattern matches, we must have caps 1 and 2
+                format!("{}apollo_router={}", &caps[1], &caps[2])
+            });
+            Ok(res.into_owned())
+        }
+    }
+}
+
 impl Opt {
     pub(crate) fn uplink_config(&self) -> Result<UplinkConfig, anyhow::Error> {
         Ok(UplinkConfig {
@@ -651,3 +675,70 @@ fn copy_args_to_env() {
         }
     });
 }
+
+#[cfg(test)]
+mod tests {
+    use crate::executable::add_log_filter;
+
+    #[test]
+    fn simplest_logging_modifications() {
+        for level in ["off", "error", "warn", "info", "debug", "trace"] {
+            assert_eq!(
+                add_log_filter(level).expect("conversion works"),
+                format!("apollo_router={level}")
+            );
+        }
+    }
+
+    // It's hard to have comprehensive tests for this kind of functionality,
+    // so this set is derived from the examples at:
+    // https://docs.rs/env_logger/latest/env_logger/#filtering-results
+    // 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,std::option").unwrap(),
+            "hello,std::option"
+        );
+        assert_eq!(
+            add_log_filter("error,hello=warn").unwrap(),
+            "apollo_router=error,hello=warn"
+        );
+        assert_eq!(
+            add_log_filter("error,hello=off").unwrap(),
+            "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("hello=debug/foo*foo").unwrap(),
+            "hello=debug/foo*foo"
+        );
+        assert_eq!(
+            add_log_filter("error,hello=warn/[0-9]scopes").unwrap(),
+            "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"
+        );
+        assert_eq!(
+            add_log_filter("hyper=debug,apollo_router=off,regex=info,h2=off").unwrap(),
+            "hyper=debug,apollo_router=off,regex=info,h2=off"
+        );
+        assert_eq!(
+            add_log_filter("apollo_router::plugins=debug").unwrap(),
+            "apollo_router::plugins=debug"
+        );
+    }
+}

docs/source/configuration/logging.mdx

@@ -34,7 +34,32 @@ The default value is `info`.
 </tbody>
 </table>
 
-The router also accepts an `APOLLO_ROUTER_LOG` environment variable with the same possible values as the command-line argument. If you provide _both_, the command-line argument takes precedence.
+The router also accepts both `RUST_LOG` and `APOLLO_ROUTER_LOG` environment variables with the same possible values as the command-line argument. The precedence is as follows (top to bottom):
+ - RUST_LOG
+ - command-line argument
+ - APOLLO_ROUTER_LOG
+
+`RUST_LOG` is supported for advanced users with specific filtering requirements who may wish to see log messages from crates consumed by the router. Most users should use the command-line argument or APOLLO_ROUTER_LOG. Both of these options constrain log output to the router.
+
+To be clear:
+
+```
+RUST_LOG=apollo_router::debug
+APOLLO_ROUTER_LOG=debug
+--log=debug
+```
+
+are equivalent, as are:
+
+```
+RUST_LOG=hyper=debug,apollo_router::info,h2=trace
+APOLLO_ROUTER_LOG=hyper=debug,info,h2=trace
+--log=hyper=debug,info,h2=trace
+```
+
+In both examples, the actual filter used by the router is as defined in the RUST_LOG entry.
+
+For more information about specifying filters for more granular control over Apollo Router logging, see the [Env Logger documentation](https://docs.rs/env_logger/latest/env_logger/).
 
 ## Output formats
 
@@ -96,7 +121,3 @@ telemetry:
         match: ^Mozilla/5.0 (iPhone*
         headers: true
 ```
-
-## Advanced configuration
-
-For more granular control over Apollo Router logging, see the [Env Logger documentation](https://docs.rs/env_logger/latest/env_logger/).