Adopt Tracing

Cargo.toml

@@ -42,4 +42,4 @@ members = [
   "examples/tls",
   "examples/fairings",
   "examples/hello_2018",
-]
+]

contrib/codegen/src/database.rs

@@ -99,15 +99,20 @@ pub fn database_attr(attr: TokenStream, input: TokenStream) -> Result<TokenStrea
                     match pool {
                         Ok(Ok(p)) => Ok(rocket.manage(#pool_type(p))),
                         Err(config_error) => {
-                            ::rocket::logger::error(
-                                &format!("Database configuration failure: '{}'", #name));
-                            ::rocket::logger::error_(&format!("{}", config_error));
+                            let span = ::rocket::trace::error_span!(
+                                "db_config_error",
+                                database = %#name,
+                                "Database configuration failure"
+                            );
+                            ::rocket::trace::error!(parent: &span, %error);
                             Err(rocket)
                         },
                         Ok(Err(pool_error)) => {
-                            ::rocket::logger::error(
-                                &format!("Failed to initialize pool for '{}'", #name));
-                            ::rocket::logger::error_(&format!("{:?}", pool_error));
+                            let span = ::rocket::trace::error_span!(
+                                "db_pool_error"
+                                database = %#name,
+                               "Failed to initialize pool");
+                            ::rocket::trace::error!(parent: &span, error = ?pool_error);
                             Err(rocket)
                         },
                     }

contrib/lib/Cargo.toml

@@ -42,7 +42,7 @@ memcache_pool = ["databases", "memcache", "r2d2-memcache"]
 tokio = { version = "0.2.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 }

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/helmet/helmet.rs

@@ -171,8 +171,11 @@ 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.");
+                let span = warn_span!(
+                    "Space Helmet: response contains already contains this header",
+                    header = %name,
+                );
+                warn!(parent: &span, "Refusing to overwrite existing header.");
                 continue
             }
 
@@ -206,9 +209,9 @@ impl Fairing for SpaceHelmet {
             && !cargo.config().environment.is_dev()
             && !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.");
+            let span = warn_span!("Space Helmet: deploying with TLS without enabling HSTS.");
+            warn!(parent: &span, "Enabling default HSTS policy.");
+            info!(parent: &span, "To disable this warning, configure an HSTS policy.");
             self.force_hsts.store(true, Ordering::Relaxed);
         }
     }

contrib/lib/src/json.rs

@@ -147,7 +147,7 @@ impl<'a, T: Deserialize<'a>> FromTransformedData<'a> for Json<T> {
             match serde_json::from_str(&string) {
                 Ok(v) => Success(Json(v)),
                 Err(e) => {
-                    error_!("Couldn't parse JSON body: {:?}", e);
+                    error!("Couldn't parse JSON body: {:?}", e);
                     if e.is_data() {
                         Failure((Status::UnprocessableEntity, JsonError::Parse(string, e)))
                     } else {
@@ -166,7 +166,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

@@ -138,7 +138,7 @@ impl<'a, T: Deserialize<'a>> FromTransformedData<'a> for MsgPack<T> {
             match rmp_serde::from_slice(&buf) {
                 Ok(val) => Success(MsgPack(val)),
                 Err(e) => {
-                    error_!("Couldn't parse MessagePack body: {:?}", e);
+                    error!("Couldn't parse MessagePack body: {:?}", e);
                     match e {
                         TypeMismatch(_) | OutOfRange | LengthMismatch(_) => {
                             Failure((Status::UnprocessableEntity, e))
@@ -158,7 +158,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/templates/context.rs

@@ -28,10 +28,10 @@ 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);
+                    let span = warn_span!("invalid_template_path", "Template name '{}' does not have a unique path.", name);
+                    info!(parent: &span, "Existing path: {:?}", info.path);
+                    info!(parent: &span, "Additional path: {:?}", path);
+                    warn!(parent: &span, "Using existing path for template '{}'.", name);
                     continue;
                 }
 

contrib/lib/src/templates/fairing.rs

@@ -59,10 +59,10 @@ mod context {
 
             let watcher = match watcher {
                 Ok(watcher) => Some(Mutex::new((watcher, rx))),
-                Err(e) => {
-                    warn!("Failed to enable live template reloading: {}", e);
-                    debug_!("Reload error: {:?}", e);
-                    warn_!("Live template reloading is unavailable.");
+                Err(error) => {
+                    let span = warn_span!("Failed to enable live template reloading", %error);
+                    debug!(parent: &span, reload_error = ?error);
+                    warn!(parent: &span, "Live template reloading is unavailable.");
                     None
                 }
             };
@@ -98,14 +98,16 @@ mod context {
                 }
 
                 if changed {
-                    info_!("Change detected: reloading templates.");
+                    let span = info_span!("Change detected: reloading templates.");
+                    let _entered = span.enter();
                     let mut ctxt = self.context_mut();
                     if let Some(mut new_ctxt) = Context::initialize(ctxt.root.clone()) {
                         custom_callback(&mut new_ctxt.engines);
                         *ctxt = new_ctxt;
+                        info!("reloaded!");
                     } else {
-                        warn_!("An error occurred while reloading templates.");
-                        warn_!("The previous templates will remain active.");
+                        warn!("An error occurred while reloading templates.");
+                        warn!("The previous templates will remain active.");
                     };
                 }
             });
@@ -159,7 +161,7 @@ impl Fairing for TemplateFairing {
             Err(ConfigError::Missing(_)) => { /* ignore missing */ }
             Err(e) => {
                 e.pretty_print();
-                warn_!("Using default templates directory '{:?}'", template_root);
+                warn!("Using default templates directory '{:?}'", template_root);
             }
         };
 

contrib/lib/src/templates/handlebars_templates.rs

@@ -12,9 +12,9 @@ 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());
+                let span = error_span!("Error in Handlebars template", template = %name);
+                info!(parent: &span, template.error = %e);
+                info!(parent: &span, template.path = path.to_string_lossy());
                 return None;
             }
         }
@@ -24,14 +24,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,9 @@ impl<'a, 'r> FromRequest<'a, 'r> for Metadata<'a> {
             .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.");
+                let span = error_span!("Uninitialized template context: missing fairing.");
+                info!(parent: &span, "To use templates, you must attach `Template::fairing()`.");
+                info!(parent: &span, "See the `Template` documentation for more information.");
                 request::Outcome::Failure((Status::InternalServerError, ()))
             })
     }

contrib/lib/src/templates/mod.rs

@@ -345,9 +345,9 @@ impl Template {
         where S: Into<Cow<'static, str>>, C: Serialize
     {
         let ctxt = cargo.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.");
+            let span = warn_span!("Uninitialized template context: missing fairing.");
+            info!(parent: &span, "To use templates, you must attach `Template::fairing()`.");
+            info!(parent: &span, "See the `Template` documentation for more information.");
             None
         })?;
 
@@ -362,19 +362,19 @@ 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);
+            let span = error_span!("Template does not exist.", template = %name);
+            info!(parent: &span, "Known templates: {}", ts.join(","));
+            info!(parent: &span, "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
         })?;
 
@@ -389,9 +389,9 @@ 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.");
+                let span = error_span!("Uninitialized template context: missing fairing.");
+                info!(parent: &span, "To use templates, you must attach `Template::fairing()`.");
+                info!(parent: &span, "See the `Template` documentation for more information.");
                 Status::InternalServerError
             })?.context();
 

contrib/lib/src/templates/tera_templates.rs

@@ -21,11 +21,12 @@ impl Engine for Tera {
 
         // Finally try to tell Tera about all of the templates.
         if let Err(e) = tera.add_template_files(tera_templates) {
-            error!("Failed to initialize Tera templating.");
+            let span = error_span!("Failed to initialize Tera templating.");
+            let _entered = span.enter();
 
             let mut error = Some(&e as &dyn Error);
             while let Some(err) = error {
-                info_!("{}", err);
+                error!(error = %err);
                 error = err.source();
             }
 
@@ -36,17 +37,19 @@ impl Engine for Tera {
     }
 
     fn render<C: Serialize>(&self, name: &str, context: C) -> Option<String> {
+        let span = info_span!("Rendering Tera template", template = %name);
+        let _entered = span.enter();
         if self.get_template(name).is_err() {
-            error_!("Tera template '{}' does not exist.", name);
+            error!("Tera template '{}' does not exist.", name);
             return None;
         };
 
         let tera_ctx = match Context::from_serialize(context) {
             Ok(ctx) => ctx,
             Err(_) => {
-                error_!(
+                error!(
                     "Error generating context when rendering Tera template '{}'.",
-                    name
+                    name,
                 );
                 return None;
             }
@@ -55,11 +58,11 @@ impl Engine for Tera {
         match Tera::render(self, name, &tera_ctx) {
             Ok(string) => Some(string),
             Err(e) => {
-                error_!("Error rendering Tera template '{}'.", name);
-
+                let span = error_span!("Error rendering Tera template", template = %name);
+                let _entered = span.enter();
                 let mut error = Some(&e as &dyn Error);
                 while let Some(err) = error {
-                    error_!("{}", err);
+                    error!(error = %err);
                     error = err.source();
                 }
 

core/codegen/src/attribute/catch.rs

@@ -77,12 +77,13 @@ pub fn _catch(
     let user_catcher_fn_name = catch.function.sig.ident.clone();
     let generated_struct_name = user_catcher_fn_name.prepend(CATCH_STRUCT_PREFIX);
     let generated_fn_name = user_catcher_fn_name.prepend(CATCH_FN_PREFIX);
+    let generated_span_name = user_catcher_fn_name.to_string();
     let (vis, catcher_status) = (&catch.function.vis, &catch.status);
     let status_code = Optional(catcher_status.as_ref().map(|s| s.0.code));
 
     // Variables names we'll use and reuse.
     define_vars_and_mods!(catch.function.span().into() =>
-        req, status, _Box, Request, Response, ErrorHandlerFuture, Status);
+        req, status, log, _Box, Request, Response, ErrorHandlerFuture, Status);
 
     // Determine the number of parameters that will be passed in.
     if catch.function.sig.inputs.len() > 2 {
@@ -125,13 +126,14 @@ pub fn _catch(
             #status: #Status,
             #req: &'_b #Request
         ) -> #ErrorHandlerFuture<'_b> {
+            use #log::Instrument as _;
             #_Box::pin(async move {
                 let __response = #catcher_response;
                 #Response::build()
                     .status(#status)
                     .merge(__response)
                     .ok()
-            })
+            }.instrument(#log::info_span!(#generated_span_name, status = %#status)))
         }
 
         /// Rocket code generated static catcher info.