Finalize 'tracing' migration.

This commit complete the migration to 'tracing' for all logging. Below
is a summary of all relevant commits, including this one:

Log improvements:
  - All log (trace) messages are structured which means they contain fields
    that can formatted by any subscriber.
  - Logging can be disabled entirely by disabling the default `trace` feature.
  - Routes and catchers now contain location (file/line) information.
  - Two log format kinds: pretty and compact via ROCKET_LOG_FORMAT
  - Coloring is not disabled globally. Thus applications can color even if
    Rocket is configured not to.
  - Rocket is more conservative about 'warn' and 'error' messages, reserving
    those log levels for messages useful in production.
  - Errors from guards logged by codegen now use the 'Display' implementation of
    those errors when one exists.
  - Secrets are never logged, even when directly asked for.

New features:
  - Many Rocket types know how to trace themselves via a new `Trace` trait.
  - `Either` types can now be used in `uri!()` calls.
  - A `RequestIdLayer` tags all requests with a unique ID.

Breaking changes to configuration:
  - `Config::log_level` is of type `Option<Level>`. `None` disables tracing.
  - `log_level` now uses the traditional log level names: "off", "error",
    "warn", "info", "debug", "trace", or 0-5. This replace the Rocket-specific
    "normal", "debug", "critical".
  - A new option, `log_format`, which is either `compact` or `pretty`,
    determines how Rocket's tracing subscriber log trace messages.

Breaking changes:
  - Hidden `rocket::Either` is now publicly available at `rocket::either::Either`.
  - `rocket::Error` no longer panics when dropped.
  - `main` generated by `#[launch]` returns an `ExitCode`.
  - `FromParam` `Err` now always returns the actual error as opposed to the
    string that failed to parse. To recover the original string, use `Either<T,
    &str>`, where `T: FromParam`, as a parameter guard.
  - Many types that implemented `Display` now instead implement `Trace`.
  - `Error::pretty_print()` was removed. Use `Error::trace()` via `Trace` impl.

Internal improvements:
  - Made more space in CI machines for tasks.
  - Cleaned up testbench code using `inventory`.

Resolves #21.

benchmarks/src/routing.rs

@@ -1,5 +1,3 @@
-use std::collections::hash_set::HashSet;
-
 use criterion::{criterion_group, Criterion};
 
 use rocket::{route, config, Request, Data, Route, Config};
@@ -80,12 +78,12 @@ fn generate_matching_requests<'c>(client: &'c Client, routes: &[Route]) -> Vec<L
 fn client(routes: Vec<Route>) -> Client {
     let config = Config {
         profile: Config::RELEASE_PROFILE,
-        // log_level: rocket::config::LogLevel::Off,
+        log_level: None,
         cli_colors: config::CliColors::Never,
         shutdown: config::ShutdownConfig {
             ctrlc: false,
             #[cfg(unix)]
-            signals: HashSet::new(),
+            signals: std::collections::hash_set::HashSet::new(),
             ..Default::default()
         },
         ..Default::default()

contrib/db_pools/lib/Cargo.toml

@@ -21,9 +21,9 @@ workspace = true
 deadpool_postgres = ["deadpool-postgres", "deadpool"]
 deadpool_redis = ["deadpool-redis", "deadpool"]
 # sqlx features
-sqlx_mysql = ["sqlx", "sqlx/mysql"]
-sqlx_postgres = ["sqlx", "sqlx/postgres"]
-sqlx_sqlite = ["sqlx", "sqlx/sqlite"]
+sqlx_mysql = ["sqlx", "sqlx/mysql", "log"]
+sqlx_postgres = ["sqlx", "sqlx/postgres", "log"]
+sqlx_sqlite = ["sqlx", "sqlx/sqlite", "log"]
 sqlx_macros = ["sqlx/macros"]
 # diesel features
 diesel_postgres = ["diesel-async/postgres", "diesel-async/deadpool", "diesel", "deadpool_09"]
@@ -86,6 +86,11 @@ default-features = false
 features = ["runtime-tokio-rustls"]
 optional = true
 
+[dependencies.log]
+version = "0.4"
+default-features = false
+optional = true
+
 [dev-dependencies.rocket]
 path = "../../../core/lib"
 default-features = false

contrib/db_pools/lib/src/pool.rs

@@ -269,7 +269,7 @@ mod deadpool_old {
 mod sqlx {
     use sqlx::ConnectOptions;
     use super::{Duration, Error, Config, Figment};
-    // use rocket::config::LogLevel;
+    use rocket::tracing::level_filters::LevelFilter;
 
     type Options<D> = <<D as sqlx::Database>::Connection as sqlx::Connection>::Options;
 
@@ -301,12 +301,21 @@ mod sqlx {
             specialize(&mut opts, &config);
 
             opts = opts.disable_statement_logging();
-            // if let Ok(level) = figment.extract_inner::<LogLevel>(rocket::Config::LOG_LEVEL) {
-            //     if !matches!(level, LogLevel::Normal | LogLevel::Off) {
-            //         opts = opts.log_statements(level.into())
-            //             .log_slow_statements(level.into(), Duration::default());
-            //     }
-            // }
+            if let Ok(value) = figment.find_value(rocket::Config::LOG_LEVEL) {
+                if let Some(level) = value.as_str().and_then(|v| v.parse().ok()) {
+                    let log_level = match level {
+                        LevelFilter::OFF => log::LevelFilter::Off,
+                        LevelFilter::ERROR => log::LevelFilter::Error,
+                        LevelFilter::WARN => log::LevelFilter::Warn,
+                        LevelFilter::INFO => log::LevelFilter::Info,
+                        LevelFilter::DEBUG => log::LevelFilter::Debug,
+                        LevelFilter::TRACE => log::LevelFilter::Trace,
+                    };
+
+                    opts = opts.log_statements(log_level)
+                        .log_slow_statements(log_level, Duration::default());
+                }
+            }
 
             sqlx::pool::PoolOptions::new()
                 .max_connections(config.max_connections as u32)

contrib/dyn_templates/src/engine/minijinja.rs

@@ -42,20 +42,20 @@ impl Engine for Environment<'static> {
         Some(env)
     }
 
-    fn render<C: Serialize>(&self, name: &str, context: C) -> Option<String> {
-        let Ok(template) = self.get_template(name) else {
-            error!("Minijinja template '{name}' was not found.");
+    fn render<C: Serialize>(&self, template: &str, context: C) -> Option<String> {
+        let Ok(templ) = self.get_template(template) else {
+            error!(template, "requested template does not exist");
             return None;
         };
 
-        match template.render(context) {
+        match templ.render(context) {
             Ok(result) => Some(result),
             Err(e) => {
-                error_span!("Error rendering Minijinja template '{name}': {e}" => {
-                    let mut error = &e as &dyn std::error::Error;
-                    while let Some(source) = error.source() {
-                        error_!("caused by: {source}");
-                        error = source;
+                span_error!("templating", template, "failed to render Minijinja template" => {
+                    let mut error = Some(&e as &dyn std::error::Error);
+                    while let Some(err) = error {
+                        error!("{err}");
+                        error = err.source();
                     }
                 });
 

contrib/dyn_templates/src/engine/tera.rs

@@ -21,7 +21,7 @@ impl Engine for Tera {
 
         // Finally try to tell Tera about all of the templates.
         if let Err(e) = tera.add_template_files(files) {
-            error_span!("Tera templating initialization failed" => {
+            span_error!("templating", "Tera templating initialization failed" => {
                 let mut error = Some(&e as &dyn Error);
                 while let Some(err) = error {
                     error!("{err}");
@@ -48,7 +48,7 @@ impl Engine for Tera {
         match Tera::render(self, template, &tera_ctx) {
             Ok(string) => Some(string),
             Err(e) => {
-                error_span!("failed to render Tera template {name}" [template] => {
+                span_error!("templating", template, "failed to render Tera template" => {
                     let mut error = Some(&e as &dyn Error);
                     while let Some(err) = error {
                         error!("{err}");

contrib/dyn_templates/src/fairing.rs

@@ -1,6 +1,7 @@
 use rocket::{Rocket, Build, Orbit};
 use rocket::fairing::{self, Fairing, Info, Kind};
 use rocket::figment::{Source, value::magic::RelativePathBuf};
+use rocket::trace::Trace;
 
 use crate::context::{Callback, Context, ContextManager};
 use crate::template::DEFAULT_TEMPLATE_DIR;
@@ -40,7 +41,7 @@ impl Fairing for TemplateFairing {
             Ok(dir) => dir,
             Err(e) if e.missing() => DEFAULT_TEMPLATE_DIR.into(),
             Err(e) => {
-                rocket::config::pretty_print_error(e);
+                e.trace_error();
                 return Err(rocket);
             }
         };
@@ -57,7 +58,7 @@ impl Fairing for TemplateFairing {
         let cm = rocket.state::<ContextManager>()
             .expect("Template ContextManager registered in on_ignite");
 
-        info_span!("templating" => {
+        span_info!("templating" => {
             info!(directory = %Source::from(&*cm.context().root));
             info!(engines = ?Engines::ENABLED_EXTENSIONS);
         });

contrib/dyn_templates/src/template.rs

@@ -248,7 +248,7 @@ impl Template {
         })?;
 
         let value = self.value.map_err(|e| {
-            error_span!("template context failed to serialize" => e.trace_error());
+            span_error!("templating", "template context failed to serialize" => e.trace_error());
             Status::InternalServerError
         })?;
 

contrib/sync_db_pools/lib/src/connection.rs

@@ -68,7 +68,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
                 let config = match Config::from(database, &rocket) {
                     Ok(config) => config,
                     Err(e) => {
-                        error_span!("database configuration error" [database] => e.trace_error());
+                        span_error!("database configuration error", database => e.trace_error());
                         return Err(rocket);
                     }
                 };
@@ -82,7 +82,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
                         _marker: PhantomData,
                     })),
                     Err(Error::Config(e)) => {
-                        error_span!("database configuration error" [database] => e.trace_error());
+                        span_error!("database configuration error", database => e.trace_error());
                         Err(rocket)
                     }
                     Err(Error::Pool(reason)) => {

core/codegen/src/attribute/catch/mod.rs

@@ -80,9 +80,10 @@ pub fn _catch(
                 }
 
                 #_catcher::StaticInfo {
-                    name: stringify!(#user_catcher_fn_name),
+                    name: ::core::stringify!(#user_catcher_fn_name),
                     code: #status_code,
                     handler: monomorphized_function,
+                    location: (::core::file!(), ::core::line!(), ::core::column!()),
                 }
             }
 

core/codegen/src/attribute/entry/launch.rs

@@ -67,8 +67,7 @@ impl EntryAttr for Launch {
         // Always infer the type as `Rocket<Build>`.
         if let syn::ReturnType::Type(_, ref mut ty) = &mut f.sig.output {
             if let syn::Type::Infer(_) = &mut **ty {
-                let new = quote_spanned!(ty.span() => ::rocket::Rocket<::rocket::Build>);
-                *ty = syn::parse2(new).expect("path is type");
+                *ty = syn::parse_quote_spanned!(ty.span() => ::rocket::Rocket<::rocket::Build>);
             }
         }
 
@@ -105,8 +104,9 @@ impl EntryAttr for Launch {
         }
 
         let (vis, mut sig) = (&f.vis, f.sig.clone());
-        sig.ident = syn::Ident::new("main", sig.ident.span());
-        sig.output = syn::parse_quote!(-> #_ExitCode);
+        sig.ident = syn::Ident::new("main", f.sig.ident.span());
+        let ret_ty = _ExitCode.respanned(ty.span());
+        sig.output = syn::parse_quote_spanned!(ty.span() => -> #ret_ty);
         sig.asyncness = None;
 
         Ok(quote_spanned!(block.span() =>

core/codegen/src/attribute/route/mod.rs

@@ -105,9 +105,10 @@ fn query_decls(route: &Route) -> Option<TokenStream> {
             )*
 
             if !__e.is_empty() {
-                ::rocket::info_span!("query string failed to match route declaration" => {
-                    for _err in __e { ::rocket::info!("{_err}"); }
-                });
+                ::rocket::trace::span_info!("codegen",
+                    "query string failed to match route declaration" =>
+                    { for _err in __e { ::rocket::trace::info!("{_err}"); } }
+                );
 
                 return #Outcome::Forward((#__data, #Status::UnprocessableEntity));
             }
@@ -120,18 +121,25 @@ fn query_decls(route: &Route) -> Option<TokenStream> {
 fn request_guard_decl(guard: &Guard) -> TokenStream {
     let (ident, ty) = (guard.fn_ident.rocketized(), &guard.ty);
     define_spanned_export!(ty.span() =>
-        __req, __data, _request, FromRequest, Outcome
+        __req, __data, _request, display_hack, FromRequest, Outcome
     );
 
     quote_spanned! { ty.span() =>
         let #ident: #ty = match <#ty as #FromRequest>::from_request(#__req).await {
             #Outcome::Success(__v) => __v,
             #Outcome::Forward(__e) => {
-                ::rocket::info!(type_name = stringify!(#ty), "guard forwarding");
+                ::rocket::trace::info!(name: "forward", parameter = stringify!(#ident),
+                    type_name = stringify!(#ty), status = __e.code,
+                    "request guard forwarding");
+
                 return #Outcome::Forward((#__data, __e));
             },
+            #[allow(unreachable_code)]
             #Outcome::Error((__c, __e)) => {
-                ::rocket::info!(type_name = stringify!(#ty), "guard failed: {__e:?}");
+                ::rocket::trace::info!(name: "failure", parameter = stringify!(#ident),
+                    type_name = stringify!(#ty), reason = %#display_hack!(__e),
+                    "request guard failed");
+
                 return #Outcome::Error(__c);
             }
         };
@@ -142,14 +150,14 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
     let (i, name, ty) = (guard.index, &guard.name, &guard.ty);
     define_spanned_export!(ty.span() =>
         __req, __data, _None, _Some, _Ok, _Err,
-        Outcome, FromSegments, FromParam, Status
+        Outcome, FromSegments, FromParam, Status, display_hack
     );
 
     // Returned when a dynamic parameter fails to parse.
     let parse_error = quote!({
-        ::rocket::info!(name: "forward",
-            reason = %__error, parameter = #name, "type" = stringify!(#ty),
-            "parameter forwarding");
+        ::rocket::trace::info!(name: "forward", parameter = #name,
+            type_name = stringify!(#ty), reason = %#display_hack!(__error),
+            "path guard forwarding");
 
         #Outcome::Forward((#__data, #Status::UnprocessableEntity))
     });
@@ -161,10 +169,11 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
             match #__req.routed_segment(#i) {
                 #_Some(__s) => match <#ty as #FromParam>::from_param(__s) {
                     #_Ok(__v) => __v,
+                    #[allow(unreachable_code)]
                     #_Err(__error) => return #parse_error,
                 },
                 #_None => {
-                    ::rocket::error!(
+                    ::rocket::trace::error!(
                         "Internal invariant broken: dyn param {} not found.\n\
                         Please report this to the Rocket issue tracker.\n\
                         https://github.com/rwf2/Rocket/issues", #i);
@@ -176,6 +185,7 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
         true => quote_spanned! { ty.span() =>
             match <#ty as #FromSegments>::from_segments(#__req.routed_segments(#i..)) {
                 #_Ok(__v) => __v,
+                #[allow(unreachable_code)]
                 #_Err(__error) => return #parse_error,
             }
         },
@@ -187,17 +197,24 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
 
 fn data_guard_decl(guard: &Guard) -> TokenStream {
     let (ident, ty) = (guard.fn_ident.rocketized(), &guard.ty);
-    define_spanned_export!(ty.span() => __req, __data, FromData, Outcome);
+    define_spanned_export!(ty.span() => __req, __data, display_hack, FromData, Outcome);
 
     quote_spanned! { ty.span() =>
         let #ident: #ty = match <#ty as #FromData>::from_data(#__req, #__data).await {
             #Outcome::Success(__d) => __d,
             #Outcome::Forward((__d, __e)) => {
-                ::rocket::info!(type_name = stringify!(#ty), "data guard forwarding");
+                ::rocket::trace::info!(name: "forward", parameter = stringify!(#ident),
+                    type_name = stringify!(#ty), status = __e.code,
+                    "data guard forwarding");
+
                 return #Outcome::Forward((__d, __e));
             }
+            #[allow(unreachable_code)]
             #Outcome::Error((__c, __e)) => {
-                ::rocket::info!(type_name = stringify!(#ty), "data guard failed: {__e:?}");
+                ::rocket::trace::info!(name: "failure", parameter = stringify!(#ident),
+                    type_name = stringify!(#ty), reason = %#display_hack!(__e),
+                    "data guard failed");
+
                 return #Outcome::Error(__c);
             }
         };
@@ -232,7 +249,7 @@ fn internal_uri_macro_decl(route: &Route) -> TokenStream {
             /// Rocket generated URI macro.
             macro_rules! #inner_macro_name {
                 ($($token:tt)*) => {{
-                    rocket::rocket_internal_uri!(#route_uri, (#(#uri_args),*), $($token)*)
+                    ::rocket::rocket_internal_uri!(#route_uri, (#(#uri_args),*), $($token)*)
                 }};
             }
 
@@ -385,6 +402,7 @@ fn codegen_route(route: Route) -> Result<TokenStream> {
                     format: #format,
                     rank: #rank,
                     sentinels: #sentinels,
+                    location: (::core::file!(), ::core::line!(), ::core::column!()),
                 }
             }
 

core/codegen/src/exports.rs

@@ -86,6 +86,7 @@ define_exported_paths! {
     _Vec => ::std::vec::Vec,
     _Cow => ::std::borrow::Cow,
     _ExitCode => ::std::process::ExitCode,
+    display_hack => ::rocket::error::display_hack,
     BorrowMut => ::std::borrow::BorrowMut,
     Outcome => ::rocket::outcome::Outcome,
     FromForm => ::rocket::form::FromForm,

core/codegen/src/lib.rs

@@ -1328,7 +1328,7 @@ pub fn catchers(input: TokenStream) -> TokenStream {
 /// assert_eq!(bob2.to_string(), "/person/Bob%20Smith");
 ///
 /// #[get("/person/<age>")]
-/// fn ok(age: Result<u8, &str>) { }
+/// fn ok(age: Result<u8, std::num::ParseIntError>) { }
 ///
 /// let kid1 = uri!(ok(age = 10));
 /// let kid2 = uri!(ok(12));

core/codegen/tests/typed-uris.rs

@@ -709,3 +709,19 @@ fn test_vec_in_query() {
         uri!(h(v = &[1, 2, 3][..])) => "/?v=%01%02%03",
     }
 }
+
+#[test]
+fn test_either() {
+    use rocket::either::{Either, Left, Right};
+
+    #[get("/<_foo>")]
+    fn f(_foo: Either<usize, &str>) { }
+
+    assert_uri_eq! {
+        uri!(f(Left::<usize, &str>(123))) => "/123",
+        uri!(f(_foo = Left::<usize, &str>(710))) => "/710",
+
+        uri!(f(Right::<usize, &str>("hello world"))) => "/hello%20world",
+        uri!(f(_foo = Right::<usize, &str>("bye?"))) => "/bye%3F",
+    }
+}

core/codegen/tests/ui-fail-nightly/async-entry.stderr

@@ -114,14 +114,6 @@ error[E0728]: `await` is only allowed inside `async` functions and blocks
 73 |         let _ = rocket::build().launch().await;
    |                                          ^^^^^ only allowed inside `async` functions and blocks
 
-error[E0728]: `await` is only allowed inside `async` functions and blocks
-  --> tests/ui-fail-nightly/async-entry.rs:73:42
-   |
-72 |     fn rocket() -> _ {
-   |     ----------- this is not `async`
-73 |         let _ = rocket::build().launch().await;
-   |                                          ^^^^^ only allowed inside `async` functions and blocks
-
 error[E0277]: `main` has invalid return type `Rocket<Build>`
   --> tests/ui-fail-nightly/async-entry.rs:94:20
    |