From e8077becb59ea705b609fe89d440106ca1487fbb Mon Sep 17 00:00:00 2001 From: Sergio Benitez Date: Tue, 14 May 2024 12:22:16 -0700 Subject: [PATCH] wip: convert all lifecycle logs to traces --- core/lib/src/lifecycle.rs | 37 ++++++++++++------------- core/lib/src/response/responder.rs | 2 +- core/lib/src/trace/subscriber/pretty.rs | 12 ++++---- core/lib/src/trace/traceable.rs | 7 +++-- 4 files changed, 30 insertions(+), 28 deletions(-) diff --git a/core/lib/src/lifecycle.rs b/core/lib/src/lifecycle.rs index d34f4b6b8f..72eac73cb2 100644 --- a/core/lib/src/lifecycle.rs +++ b/core/lib/src/lifecycle.rs @@ -1,8 +1,8 @@ use futures::future::{FutureExt, Future}; +use crate::{route, catcher, Rocket, Orbit, Request, Response, Data}; use crate::trace::traceable::Traceable; use crate::util::Formatter; -use crate::{route, Rocket, Orbit, Request, Response, Data}; use crate::data::IoHandler; use crate::http::{Method, Status, Header}; use crate::outcome::Outcome; @@ -236,23 +236,22 @@ impl Rocket { // We may wish to relax this in the future. req.cookies().reset_delta(); - // Dispatch to the `status` catcher. - if let Ok(r) = self.invoke_catcher(status, req).await { - return r; - } - - // If it fails and it's not a 500, try the 500 catcher. - if status != Status::InternalServerError { - error_!("Catcher failed. Attempting 500 error catcher."); - status = Status::InternalServerError; - if let Ok(r) = self.invoke_catcher(status, req).await { - return r; + loop { + // Dispatch to the `status` catcher. + match self.invoke_catcher(status, req).await { + Ok(r) => return r, + // If the catcher failed, try `500` catcher, unless this is it. + Err(e) if status.code != 500 => { + warn!(status = e.map(|r| r.code), "catcher failed: trying 500 catcher"); + status = Status::InternalServerError; + } + // The 500 catcher failed. There's no recourse. Use default. + Err(e) => { + error!(status = e.map(|r| r.code), "500 catcher failed"); + return catcher::default_handler(Status::InternalServerError, req); + } } } - - // If it failed again or if it was already a 500, use Rocket's default. - error_!("{} catcher failed. Using Rocket default 500.", status.code); - crate::catcher::default_handler(Status::InternalServerError, req) } /// Invokes the handler with `req` for catcher with status `status`. @@ -276,9 +275,9 @@ impl Rocket { .map(|result| result.map_err(Some)) .unwrap_or_else(|| Err(None)) } else { - info!("no user catcher found: using Rocket default"); - Ok(crate::catcher::default_handler(status, req)) + info!(name: "catcher", name = "rocket::default", code = status.code, + "no registered catcher: using Rocket default"); + Ok(catcher::default_handler(status, req)) } } - } diff --git a/core/lib/src/response/responder.rs b/core/lib/src/response/responder.rs index 3c1ba95699..8ff963eaee 100644 --- a/core/lib/src/response/responder.rs +++ b/core/lib/src/response/responder.rs @@ -484,7 +484,7 @@ impl<'r, 'o: 'r, R: Responder<'r, 'o>> Responder<'r, 'o> for Option { match self { Some(r) => r.respond_to(req), None => { - warn_!("Response was `None`."); + debug!("{} responder returned `None`", std::any::type_name::()); Err(Status::NotFound) }, } diff --git a/core/lib/src/trace/subscriber/pretty.rs b/core/lib/src/trace/subscriber/pretty.rs index d0f4affa06..2b5e5469e5 100644 --- a/core/lib/src/trace/subscriber/pretty.rs +++ b/core/lib/src/trace/subscriber/pretty.rs @@ -41,7 +41,7 @@ impl RocketFmt { #[cfg(not(windows))] { emoji.paint(self.style).mask() } } - fn pretty_prefix<'a>(&self, meta: &'a Metadata<'_>) -> impl fmt::Display + 'a { + fn prefix<'a>(&self, meta: &'a Metadata<'_>) -> impl fmt::Display + 'a { let (i, m, s) = (self.indent(), self.marker(), self.style(meta)); Formatter(move |f| match *meta.level() { Level::WARN => write!(f, "{i}{m}{} ", "warning:".paint(s).bold()), @@ -52,7 +52,7 @@ impl RocketFmt { } fn print_pretty(&self, m: &Metadata<'_>, data: F) { - let prefix = self.pretty_prefix(m); + let prefix = self.prefix(m); let cont_prefix = Formatter(|f| { let style = self.style(m); write!(f, "{}{} ", self.indent(), "++".paint(style).dim()) @@ -65,7 +65,7 @@ impl RocketFmt { where F: RecordFields { let style = self.style(metadata); - let prefix = self.pretty_prefix(metadata); + let prefix = self.prefix(metadata); fields.record_display(|key: &Field, value: &dyn fmt::Display| { if key.name() != "message" { println!("{prefix}{}: {}", key.paint(style), value.paint(style).primary()); @@ -85,7 +85,7 @@ impl LookupSpan<'a>> Layer for RocketFmt { match meta.name() { "config" => self.print_fields(meta, event), "liftoff" => { - let prefix = self.pretty_prefix(meta); + let prefix = self.prefix(meta); println!("{prefix}{}{} {}", self.emoji("🚀 "), "Rocket has launched from".paint(style).primary().bold(), &data["endpoint"].paint(style).primary().bold().underline()); @@ -111,7 +111,7 @@ impl LookupSpan<'a>> Layer for RocketFmt { let meta = span.metadata(); let style = self.style(meta); - let prefix = self.pretty_prefix(meta); + let prefix = self.prefix(meta); let emoji = self.emoji(icon); let name = name.paint(style).bold(); @@ -133,7 +133,7 @@ impl LookupSpan<'a>> Layer for RocketFmt { } let meta = span.metadata(); - println!("{}{}", self.pretty_prefix(meta), self.compact_fields(meta, values)); + println!("{}{}", self.prefix(meta), self.compact_fields(meta, values)); } fn on_enter(&self, _: &Id, _: Context<'_, S>) { diff --git a/core/lib/src/trace/traceable.rs b/core/lib/src/trace/traceable.rs index a698ccf8a6..df45f4cfa2 100644 --- a/core/lib/src/trace/traceable.rs +++ b/core/lib/src/trace/traceable.rs @@ -141,7 +141,7 @@ impl Traceable for Route { event! { Level::DEBUG, "route", route = self.name.as_ref().map(|n| &**n), - sentinels = %Formatter(|f|{ + sentinels = %Formatter(|f| { f.debug_set() .entries(self.sentinels.iter().filter(|s| s.specialized).map(|s| s.type_name)) .finish() @@ -154,7 +154,10 @@ impl Traceable for Catcher { fn trace(&self, level: Level) { event! { level, "catcher", name = self.name.as_ref().map(|n| &**n), - code = self.code, + status = %Formatter(|f| match self.code { + Some(code) => write!(f, "{}", code), + None => write!(f, "default"), + }), rank = self.rank, uri.base = %self.base(), }