Skip to content

Commit

Permalink
Finalize 'tracing' migration.
Browse files Browse the repository at this point in the history
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.
  • Loading branch information
SergioBenitez committed Jun 3, 2024
1 parent 45264de commit 110c15b
Show file tree
Hide file tree
Showing 66 changed files with 1,247 additions and 812 deletions.
2 changes: 1 addition & 1 deletion benchmarks/src/routing.rs
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,7 @@ 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,
Expand Down
11 changes: 8 additions & 3 deletions contrib/db_pools/lib/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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"]
Expand Down Expand Up @@ -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
Expand Down
23 changes: 16 additions & 7 deletions contrib/db_pools/lib/src/pool.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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)
Expand Down
18 changes: 9 additions & 9 deletions contrib/dyn_templates/src/engine/minijinja.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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();
}
});

Expand Down
4 changes: 2 additions & 2 deletions contrib/dyn_templates/src/engine/tera.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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}");
Expand All @@ -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}");
Expand Down
5 changes: 3 additions & 2 deletions contrib/dyn_templates/src/fairing.rs
Original file line number Diff line number Diff line change
@@ -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;
Expand Down Expand Up @@ -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);
}
};
Expand All @@ -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);
});
Expand Down
2 changes: 1 addition & 1 deletion contrib/dyn_templates/src/template.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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
})?;

Expand Down
4 changes: 2 additions & 2 deletions contrib/sync_db_pools/lib/src/connection.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
};
Expand All @@ -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)) => {
Expand Down
3 changes: 2 additions & 1 deletion core/codegen/src/attribute/catch/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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!()),
}
}

Expand Down
8 changes: 4 additions & 4 deletions core/codegen/src/attribute/entry/launch.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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>);
}
}

Expand Down Expand Up @@ -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() =>
Expand Down
48 changes: 33 additions & 15 deletions core/codegen/src/attribute/route/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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));
}
Expand All @@ -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);
}
};
Expand All @@ -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))
});
Expand All @@ -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);
Expand All @@ -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,
}
},
Expand All @@ -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);
}
};
Expand Down Expand Up @@ -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)*)
}};
}

Expand Down Expand Up @@ -385,6 +402,7 @@ fn codegen_route(route: Route) -> Result<TokenStream> {
format: #format,
rank: #rank,
sentinels: #sentinels,
location: (::core::file!(), ::core::line!(), ::core::column!()),
}
}

Expand Down
1 change: 1 addition & 0 deletions core/codegen/src/exports.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
2 changes: 1 addition & 1 deletion core/codegen/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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));
Expand Down
16 changes: 16 additions & 0 deletions core/codegen/tests/typed-uris.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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",
}
}
8 changes: 0 additions & 8 deletions core/codegen/tests/ui-fail-nightly/async-entry.stderr
Original file line number Diff line number Diff line change
Expand Up @@ -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
|
Expand Down
Loading

0 comments on commit 110c15b

Please sign in to comment.