Use 'tracing' library instead of 'log'.

'tracing' is now used for all messages and for Rocket's default logger.

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
Co-authored-by: Jeb Rosen <jeb@jebrosen.com>

contrib/lib/Cargo.toml

@@ -46,7 +46,7 @@ memcache_pool = ["databases", "memcache", "r2d2-memcache"]
 tokio = { version = "1.0", optional = true }
 rocket_contrib_codegen = { version = "0.5.0-dev", path = "../codegen", optional = true }
 rocket = { version = "0.5.0-dev", path = "../../core/lib/", default-features = false }
-log = "0.4"
+tracing = { version = "0.1", default-features = false }
 
 # Serialization and templating dependencies.
 serde = { version = "1.0", optional = true, features = ["derive"] }

contrib/lib/src/compression/fairing.rs

@@ -115,17 +115,17 @@ impl Fairing for Compression {
                         if let Value::String(s) = ex {
                             let mt = MediaType::parse_flexible(s);
                             if mt.is_none() {
-                                warn_!("Ignoring invalid media type '{:?}'", s);
+                                warn!("Ignoring invalid media type '{:?}'", s);
                             }
                             mt
                         } else {
-                            warn_!("Ignoring non-string media type '{:?}'", ex);
+                            warn!("Ignoring non-string media type '{:?}'", ex);
                             None
                         }
                     }).collect();
                 }
                 None => {
-                    warn_!(
+                    warn!(
                         "Exclusions is not an array; using default compression exclusions '{:?}'",
                         ctxt.exclusions
                     );
@@ -134,7 +134,7 @@ impl Fairing for Compression {
             Err(ConfigError::Missing(_)) => { /* ignore missing */ }
             Err(e) => {
                 e.pretty_print();
-                warn_!(
+                warn!(
                     "Using default compression exclusions '{:?}'",
                     ctxt.exclusions
                 );

contrib/lib/src/databases/connection.rs

@@ -3,6 +3,7 @@ use std::sync::Arc;
 
 use rocket::fairing::{AdHoc, Fairing};
 use rocket::request::{Request, Outcome, FromRequest};
+use rocket::trace::error;
 use rocket::outcome::IntoOutcome;
 use rocket::http::Status;
 
@@ -61,8 +62,8 @@ async fn run_blocking<F, R>(job: F) -> R
 
 macro_rules! dberr {
     ($msg:literal, $db_name:expr, $efmt:literal, $error:expr, $rocket:expr) => ({
-        rocket::error!(concat!("database ", $msg, " error for pool named `{}`"), $db_name);
-        error_!($efmt, $error);
+        rocket::trace::error!(concat!("database ", $msg, " error for pool named `{}`"), $db_name);
+        error!($efmt, $error);
         return Err($rocket);
     });
 }
@@ -95,7 +96,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
         let permit = match timeout(duration, self.semaphore.clone().acquire_owned()).await {
             Ok(p) => p.expect("internal invariant broken: semaphore should not be closed"),
             Err(_) => {
-                error_!("database connection retrieval timed out");
+                error!("database connection retrieval timed out");
                 return Err(());
             }
         };
@@ -110,7 +111,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
                 _marker: PhantomData,
             }),
             Err(e) => {
-                error_!("failed to get a database connection: {}", e);
+                error!("failed to get a database connection: {}", e);
                 Err(())
             }
         }
@@ -180,7 +181,7 @@ impl<'r, K: 'static, C: Poolable> FromRequest<'r> for Connection<K, C> {
         match request.managed_state::<ConnectionPool<K, C>>() {
             Some(c) => c.get().await.into_outcome(Status::ServiceUnavailable),
             None => {
-                error_!("Missing database fairing for `{}`", std::any::type_name::<K>());
+                error!("Missing database fairing for `{}`", std::any::type_name::<K>());
                 Outcome::Failure((Status::InternalServerError, ()))
             }
         }

contrib/lib/src/helmet/helmet.rs

@@ -171,8 +171,10 @@ impl SpaceHelmet {
         for policy in self.policies.values() {
             let name = policy.name();
             if response.headers().contains(name.as_str()) {
-                warn!("Space Helmet: response contains a '{}' header.", name);
-                warn_!("Refusing to overwrite existing header.");
+                warn_span!(
+                    "Space Helmet: response contains already contains this header",
+                    header = %name,
+                ).in_scope(|| warn!("Refusing to overwrite existing header."));
                 continue
             }
 
@@ -206,9 +208,10 @@ impl Fairing for SpaceHelmet {
             && rocket.figment().profile() != rocket::Config::DEBUG_PROFILE
             && !self.is_enabled::<Hsts>()
         {
-            warn_!("Space Helmet: deploying with TLS without enabling HSTS.");
-            warn_!("Enabling default HSTS policy.");
-            info_!("To disable this warning, configure an HSTS policy.");
+            warn_span!("Space Helmet: deploying with TLS without enabling HSTS.").in_scope(|| {
+                warn!("Enabling default HSTS policy.");
+                info!("To disable this warning, configure an HSTS policy.");
+            });
             self.force_hsts.store(true, Ordering::Relaxed);
         }
     }

contrib/lib/src/json.rs

@@ -193,7 +193,7 @@ impl<'r, T: Serialize> Responder<'r, 'static> for Json<T> {
     fn respond_to(self, req: &'r Request<'_>) -> response::Result<'static> {
         let string = serde_json::to_string(&self.0)
             .map_err(|e| {
-                error_!("JSON failed to serialize: {:?}", e);
+                error!("JSON failed to serialize: {:?}", e);
                 Status::InternalServerError
             })?;
 

contrib/lib/src/lib.rs

@@ -40,7 +40,7 @@
 //! This crate is expected to grow with time, bringing in outside crates to be
 //! officially supported by Rocket.
 
-#[allow(unused_imports)] #[macro_use] extern crate log;
+#[allow(unused_imports)] #[macro_use] extern crate tracing;
 #[allow(unused_imports)] #[macro_use] extern crate rocket;
 
 #[cfg(feature="json")] #[macro_use] pub mod json;

contrib/lib/src/msgpack.rs

@@ -179,7 +179,7 @@ impl<'r, T: Serialize> Responder<'r, 'static> for MsgPack<T> {
     fn respond_to(self, req: &'r Request<'_>) -> response::Result<'static> {
         let buf = rmp_serde::to_vec(&self.0)
             .map_err(|e| {
-                error_!("MsgPack failed to serialize: {:?}", e);
+                error!("MsgPack failed to serialize: {:?}", e);
                 Status::InternalServerError
             })?;
 

contrib/lib/src/serve.rs

@@ -317,9 +317,10 @@ impl StaticFiles {
 
         let path = path.as_ref();
         if !path.is_dir() {
-            error!("`StaticFiles` supplied with invalid path");
-            info_!("'{}' is not a directory", Paint::white(path.display()));
-            panic!("refusing to continue due to invalid static files path");
+            error_span!("`StaticFiles` supplied with invalid path").in_scope(|| {
+                info!(path = %Paint::white(path.display()), "Path is not a directory");
+                panic!("refusing to continue due to invalid static files path");
+            });
         }
 
         StaticFiles { root: path.into(), options, rank: Self::DEFAULT_RANK }

contrib/lib/src/templates/context.rs

@@ -37,10 +37,11 @@ impl Context {
             for path in glob::glob(glob_path).unwrap().filter_map(Result::ok) {
                 let (name, data_type_str) = split_path(&root, &path);
                 if let Some(info) = templates.get(&*name) {
-                    warn_!("Template name '{}' does not have a unique path.", name);
-                    info_!("Existing path: {:?}", info.path);
-                    info_!("Additional path: {:?}", path);
-                    warn_!("Using existing path for template '{}'.", name);
+                    warn_span!("invalid_template_path", "Template name '{}' does not have a unique path.", name).in_scope(|| {
+                        info!(path = ?info.path, "Existing");
+                        info!(path = ?path, "Additiona");
+                        warn!("Using existing path for template '{}'.", name);
+                    });
                     continue;
                 }
 

contrib/lib/src/templates/fairing.rs

@@ -62,10 +62,11 @@ mod context {
 
             let watcher = match watcher {
                 Ok(watcher) => Some((watcher, Mutex::new(rx))),
-                Err(e) => {
-                    warn!("Failed to enable live template reloading: {}", e);
-                    debug_!("Reload error: {:?}", e);
-                    warn_!("Live template reloading is unavailable.");
+                Err(error) => {
+                    warn_span!("Failed to enable live template reloading", %error).in_scope(|| {
+                        debug!(reload_error = ?error);
+                        warn!("Live template reloading is unavailable.");
+                    });
                     None
                 }
             };
@@ -94,21 +95,24 @@ mod context {
                 .map(|(_, rx)| rx.lock().expect("fsevents lock").try_iter().count() > 0);
 
             if let Some(true) = templates_changes {
-                info_!("Change detected: reloading templates.");
-                let root = self.context().root.clone();
-                if let Some(mut new_ctxt) = Context::initialize(&root) {
-                    match callback(&mut new_ctxt.engines) {
-                        Ok(()) => *self.context_mut() = new_ctxt,
-                        Err(e) => {
-                            warn_!("The template customization callback returned an error:");
-                            warn_!("{}", e);
-                            warn_!("The existing templates will remain active.");
+                info_span!("Change detected: reloading templates.").in_scope(|| {
+                    let root = self.context().root.clone();
+                    if let Some(mut new_ctxt) = Context::initialize(&root) {
+                        match callback(&mut new_ctxt.engines) {
+                            Ok(()) => {
+                                *self.context_mut() = new_ctxt;
+                                debug!("reloaded!");
+                            }
+                            Err(error) => {
+                                warn!(%error, "The template customization callback returned an error");
+                                warn!("The existing templates will remain active.");
+                            }
                         }
-                    }
-                } else {
-                    warn_!("An error occurred while reloading templates.");
-                    warn_!("The existing templates will remain active.");
-                };
+                    } else {
+                        warn!("An error occurred while reloading templates.");
+                        warn!("The existing templates will remain active.");
+                    };
+                });
             }
         }
     }
@@ -158,26 +162,26 @@ impl Fairing for TemplateFairing {
 
         match Context::initialize(&path) {
             Some(mut ctxt) => {
-                use rocket::{logger::PaintExt, yansi::Paint};
+                use rocket::{trace::PaintExt, yansi::Paint};
                 use crate::templates::Engines;
 
-                info!("{}{}", Paint::emoji("📐 "), Paint::magenta("Templating:"));
+                info_span!("templating", "{}{}", Paint::emoji("📐 "), Paint::magenta("Templating:")).in_scope(|| {
 
-                match (self.callback)(&mut ctxt.engines) {
-                    Ok(()) => {
-                        info_!("directory: {}", Paint::white(Source::from(&*path)));
-                        info_!("engines: {:?}", Paint::white(Engines::ENABLED_EXTENSIONS));
-                        Ok(rocket.manage(ContextManager::new(ctxt)))
-                    }
-                    Err(e) => {
-                        error_!("The template customization callback returned an error:");
-                        error_!("{}", e);
-                        Err(rocket)
+                    match (self.callback)(&mut ctxt.engines) {
+                        Ok(()) => {
+                            info!(directory = %Paint::white(Source::from(&*path)));
+                            info!(engines =?Paint::white(Engines::ENABLED_EXTENSIONS));
+                            Ok(rocket.manage(ContextManager::new(ctxt)))
+                        }
+                        Err(error) => {
+                            error!(%error, "The template customization callback returned an error");
+                            Err(rocket)
+                        }
                     }
-                }
+                })
             }
             None => {
-                error_!("Launch will be aborted due to failed template initialization.");
+                error!("Launch will be aborted due to failed template initialization.");
                 Err(rocket)
             }
         }

contrib/lib/src/templates/handlebars_templates.rs

@@ -12,9 +12,10 @@ impl Engine for Handlebars<'static> {
         for &(name, info) in templates {
             let path = &info.path;
             if let Err(e) = hb.register_template_file(name, path) {
-                error!("Error in Handlebars template '{}'.", name);
-                info_!("{}", e);
-                info_!("Template path: '{}'.", path.to_string_lossy());
+                error_span!("template_error", template = %name, "Error in Handlebars template",).in_scope(|| {
+                    info!(template.error = %e);
+                    info!(template.path = %path.to_string_lossy());
+                });
                 return None;
             }
         }
@@ -24,14 +25,14 @@ impl Engine for Handlebars<'static> {
 
     fn render<C: Serialize>(&self, name: &str, context: C) -> Option<String> {
         if self.get_template(name).is_none() {
-            error_!("Handlebars template '{}' does not exist.", name);
+            error!(template = %name, "Handlebars template does not exist.");
             return None;
         }
 
         match Handlebars::render(self, name, &context) {
             Ok(string) => Some(string),
-            Err(e) => {
-                error_!("Error rendering Handlebars template '{}': {}", name, e);
+            Err(error) => {
+                error!(template = %name, %error, "Error rendering Handlebars template");
                 None
             }
         }

contrib/lib/src/templates/metadata.rs

@@ -93,9 +93,10 @@ impl<'r> FromRequest<'r> for Metadata<'r> {
             .succeeded()
             .and_then(|cm| Some(request::Outcome::Success(Metadata(cm.inner()))))
             .unwrap_or_else(|| {
-                error_!("Uninitialized template context: missing fairing.");
-                info_!("To use templates, you must attach `Template::fairing()`.");
-                info_!("See the `Template` documentation for more information.");
+                error_span!("missing_fairing", "Uninitialized template context: missing fairing.").in_scope(|| {
+                    info!("To use templates, you must attach `Template::fairing()`.");
+                    info!("See the `Template` documentation for more information.");
+                });
                 request::Outcome::Failure((Status::InternalServerError, ()))
             })
     }

contrib/lib/src/templates/mod.rs

@@ -377,9 +377,10 @@ impl Template {
         where S: Into<Cow<'static, str>>, C: Serialize
     {
         let ctxt = rocket.state::<ContextManager>().map(ContextManager::context).or_else(|| {
-            warn!("Uninitialized template context: missing fairing.");
-            info!("To use templates, you must attach `Template::fairing()`.");
-            info!("See the `Template` documentation for more information.");
+            warn_span!("missing_fairing", "Uninitialized template context: missing fairing.").in_scope(|| {
+                info!("To use templates, you must attach `Template::fairing()`.");
+                info!("See the `Template` documentation for more information.");
+            });
             None
         })?;
 
@@ -394,19 +395,20 @@ impl Template {
         let name = &*self.name;
         let info = ctxt.templates.get(name).ok_or_else(|| {
             let ts: Vec<_> = ctxt.templates.keys().map(|s| s.as_str()).collect();
-            error_!("Template '{}' does not exist.", name);
-            info_!("Known templates: {}", ts.join(","));
-            info_!("Searched in '{:?}'.", ctxt.root);
+            error_span!("Template does not exist.", template = %name).in_scope(|| {
+                info!("Known templates: {}", ts.join(","));
+                info!("Searched in '{:?}'.", ctxt.root);
+            });
             Status::InternalServerError
         })?;
 
         let value = self.value.ok_or_else(|| {
-            error_!("The provided template context failed to serialize.");
+            error!("The provided template context failed to serialize.");
             Status::InternalServerError
         })?;
 
         let string = ctxt.engines.render(name, &info, value).ok_or_else(|| {
-            error_!("Template '{}' failed to render.", name);
+            error!(template = %name, "Template failed to render.");
             Status::InternalServerError
         })?;
 
@@ -421,9 +423,10 @@ impl<'r> Responder<'r, 'static> for Template {
     fn respond_to(self, req: &'r Request<'_>) -> response::Result<'static> {
         let (render, content_type) = {
             let ctxt = req.managed_state::<ContextManager>().ok_or_else(|| {
-                error_!("Uninitialized template context: missing fairing.");
-                info_!("To use templates, you must attach `Template::fairing()`.");
-                info_!("See the `Template` documentation for more information.");
+                error_span!("missing_fairing", "Uninitialized template context: missing fairing.").in_scope(|| {
+                    info!("To use templates, you must attach `Template::fairing()`.");
+                    info!("See the `Template` documentation for more information.");
+                });
                 Status::InternalServerError
             })?.context();