Skip to content

Commit 926e06e

Browse files
SergioBenitezSergioBenitez
committed
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 rwf2#21.
1 parent 45264de commit 926e06e

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

66 files changed

+1250
-817
lines changed

‎benchmarks/src/routing.rs

+2-4
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,3 @@
1-
use std::collections::hash_set::HashSet;
2-
31
use criterion::{criterion_group, Criterion};
42

53
use rocket::{route, config, Request, Data, Route, Config};
@@ -80,12 +78,12 @@ fn generate_matching_requests<'c>(client: &'c Client, routes: &[Route]) -> Vec<L
8078
fn client(routes: Vec<Route>) -> Client {
8179
let config = Config {
8280
profile: Config::RELEASE_PROFILE,
83-
// log_level: rocket::config::LogLevel::Off,
81+
log_level: None,
8482
cli_colors: config::CliColors::Never,
8583
shutdown: config::ShutdownConfig {
8684
ctrlc: false,
8785
#[cfg(unix)]
88-
signals: HashSet::new(),
86+
signals: std::collections::hash_set::HashSet::new(),
8987
..Default::default()
9088
},
9189
..Default::default()

‎contrib/db_pools/lib/Cargo.toml

+8-3
Original file line numberDiff line numberDiff line change
@@ -21,9 +21,9 @@ workspace = true
2121
deadpool_postgres = ["deadpool-postgres", "deadpool"]
2222
deadpool_redis = ["deadpool-redis", "deadpool"]
2323
# sqlx features
24-
sqlx_mysql = ["sqlx", "sqlx/mysql"]
25-
sqlx_postgres = ["sqlx", "sqlx/postgres"]
26-
sqlx_sqlite = ["sqlx", "sqlx/sqlite"]
24+
sqlx_mysql = ["sqlx", "sqlx/mysql", "log"]
25+
sqlx_postgres = ["sqlx", "sqlx/postgres", "log"]
26+
sqlx_sqlite = ["sqlx", "sqlx/sqlite", "log"]
2727
sqlx_macros = ["sqlx/macros"]
2828
# diesel features
2929
diesel_postgres = ["diesel-async/postgres", "diesel-async/deadpool", "diesel", "deadpool_09"]
@@ -86,6 +86,11 @@ default-features = false
8686
features = ["runtime-tokio-rustls"]
8787
optional = true
8888

89+
[dependencies.log]
90+
version = "0.4"
91+
default-features = false
92+
optional = true
93+
8994
[dev-dependencies.rocket]
9095
path = "../../../core/lib"
9196
default-features = false

‎contrib/db_pools/lib/src/pool.rs

+16-7
Original file line numberDiff line numberDiff line change
@@ -269,7 +269,7 @@ mod deadpool_old {
269269
mod sqlx {
270270
use sqlx::ConnectOptions;
271271
use super::{Duration, Error, Config, Figment};
272-
// use rocket::config::LogLevel;
272+
use rocket::tracing::level_filters::LevelFilter;
273273

274274
type Options<D> = <<D as sqlx::Database>::Connection as sqlx::Connection>::Options;
275275

@@ -301,12 +301,21 @@ mod sqlx {
301301
specialize(&mut opts, &config);
302302

303303
opts = opts.disable_statement_logging();
304-
// if let Ok(level) = figment.extract_inner::<LogLevel>(rocket::Config::LOG_LEVEL) {
305-
// if !matches!(level, LogLevel::Normal | LogLevel::Off) {
306-
// opts = opts.log_statements(level.into())
307-
// .log_slow_statements(level.into(), Duration::default());
308-
// }
309-
// }
304+
if let Ok(value) = figment.find_value(rocket::Config::LOG_LEVEL) {
305+
if let Some(level) = value.as_str().and_then(|v| v.parse().ok()) {
306+
let log_level = match level {
307+
LevelFilter::OFF => log::LevelFilter::Off,
308+
LevelFilter::ERROR => log::LevelFilter::Error,
309+
LevelFilter::WARN => log::LevelFilter::Warn,
310+
LevelFilter::INFO => log::LevelFilter::Info,
311+
LevelFilter::DEBUG => log::LevelFilter::Debug,
312+
LevelFilter::TRACE => log::LevelFilter::Trace,
313+
};
314+
315+
opts = opts.log_statements(log_level)
316+
.log_slow_statements(log_level, Duration::default());
317+
}
318+
}
310319

311320
sqlx::pool::PoolOptions::new()
312321
.max_connections(config.max_connections as u32)

‎contrib/dyn_templates/src/engine/minijinja.rs

+9-9
Original file line numberDiff line numberDiff line change
@@ -42,20 +42,20 @@ impl Engine for Environment<'static> {
4242
Some(env)
4343
}
4444

45-
fn render<C: Serialize>(&self, name: &str, context: C) -> Option<String> {
46-
let Ok(template) = self.get_template(name) else {
47-
error!("Minijinja template '{name}' was not found.");
45+
fn render<C: Serialize>(&self, template: &str, context: C) -> Option<String> {
46+
let Ok(templ) = self.get_template(template) else {
47+
error!(template, "requested template does not exist");
4848
return None;
4949
};
5050

51-
match template.render(context) {
51+
match templ.render(context) {
5252
Ok(result) => Some(result),
5353
Err(e) => {
54-
error_span!("Error rendering Minijinja template '{name}': {e}" => {
55-
let mut error = &e as &dyn std::error::Error;
56-
while let Some(source) = error.source() {
57-
error_!("caused by: {source}");
58-
error = source;
54+
span_error!("templating", template, "failed to render Minijinja template" => {
55+
let mut error = Some(&e as &dyn std::error::Error);
56+
while let Some(err) = error {
57+
error!("{err}");
58+
error = err.source();
5959
}
6060
});
6161

‎contrib/dyn_templates/src/engine/tera.rs

+2-2
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ impl Engine for Tera {
2121

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

‎contrib/dyn_templates/src/fairing.rs

+3-2
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
use rocket::{Rocket, Build, Orbit};
22
use rocket::fairing::{self, Fairing, Info, Kind};
33
use rocket::figment::{Source, value::magic::RelativePathBuf};
4+
use rocket::trace::Trace;
45

56
use crate::context::{Callback, Context, ContextManager};
67
use crate::template::DEFAULT_TEMPLATE_DIR;
@@ -40,7 +41,7 @@ impl Fairing for TemplateFairing {
4041
Ok(dir) => dir,
4142
Err(e) if e.missing() => DEFAULT_TEMPLATE_DIR.into(),
4243
Err(e) => {
43-
rocket::config::pretty_print_error(e);
44+
e.trace_error();
4445
return Err(rocket);
4546
}
4647
};
@@ -57,7 +58,7 @@ impl Fairing for TemplateFairing {
5758
let cm = rocket.state::<ContextManager>()
5859
.expect("Template ContextManager registered in on_ignite");
5960

60-
info_span!("templating" => {
61+
span_info!("templating" => {
6162
info!(directory = %Source::from(&*cm.context().root));
6263
info!(engines = ?Engines::ENABLED_EXTENSIONS);
6364
});

‎contrib/dyn_templates/src/template.rs

+1-1
Original file line numberDiff line numberDiff line change
@@ -248,7 +248,7 @@ impl Template {
248248
})?;
249249

250250
let value = self.value.map_err(|e| {
251-
error_span!("template context failed to serialize" => e.trace_error());
251+
span_error!("templating", "template context failed to serialize" => e.trace_error());
252252
Status::InternalServerError
253253
})?;
254254

‎contrib/sync_db_pools/lib/src/connection.rs

+2-2
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
6868
let config = match Config::from(database, &rocket) {
6969
Ok(config) => config,
7070
Err(e) => {
71-
error_span!("database configuration error" [database] => e.trace_error());
71+
span_error!("database configuration error", database => e.trace_error());
7272
return Err(rocket);
7373
}
7474
};
@@ -82,7 +82,7 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
8282
_marker: PhantomData,
8383
})),
8484
Err(Error::Config(e)) => {
85-
error_span!("database configuration error" [database] => e.trace_error());
85+
span_error!("database configuration error", database => e.trace_error());
8686
Err(rocket)
8787
}
8888
Err(Error::Pool(reason)) => {

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

+2-1
Original file line numberDiff line numberDiff line change
@@ -80,9 +80,10 @@ pub fn _catch(
8080
}
8181

8282
#_catcher::StaticInfo {
83-
name: stringify!(#user_catcher_fn_name),
83+
name: ::core::stringify!(#user_catcher_fn_name),
8484
code: #status_code,
8585
handler: monomorphized_function,
86+
location: (::core::file!(), ::core::line!(), ::core::column!()),
8687
}
8788
}
8889

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

+4-4
Original file line numberDiff line numberDiff line change
@@ -67,8 +67,7 @@ impl EntryAttr for Launch {
6767
// Always infer the type as `Rocket<Build>`.
6868
if let syn::ReturnType::Type(_, ref mut ty) = &mut f.sig.output {
6969
if let syn::Type::Infer(_) = &mut **ty {
70-
let new = quote_spanned!(ty.span() => ::rocket::Rocket<::rocket::Build>);
71-
*ty = syn::parse2(new).expect("path is type");
70+
*ty = syn::parse_quote_spanned!(ty.span() => ::rocket::Rocket<::rocket::Build>);
7271
}
7372
}
7473

@@ -105,8 +104,9 @@ impl EntryAttr for Launch {
105104
}
106105

107106
let (vis, mut sig) = (&f.vis, f.sig.clone());
108-
sig.ident = syn::Ident::new("main", sig.ident.span());
109-
sig.output = syn::parse_quote!(-> #_ExitCode);
107+
sig.ident = syn::Ident::new("main", f.sig.ident.span());
108+
let ret_ty = _ExitCode.respanned(ty.span());
109+
sig.output = syn::parse_quote_spanned!(ty.span() => -> #ret_ty);
110110
sig.asyncness = None;
111111

112112
Ok(quote_spanned!(block.span() =>

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

+33-15
Original file line numberDiff line numberDiff line change
@@ -105,9 +105,10 @@ fn query_decls(route: &Route) -> Option<TokenStream> {
105105
)*
106106

107107
if !__e.is_empty() {
108-
::rocket::info_span!("query string failed to match route declaration" => {
109-
for _err in __e { ::rocket::info!("{_err}"); }
110-
});
108+
::rocket::trace::span_info!("codegen",
109+
"query string failed to match route declaration" =>
110+
{ for _err in __e { ::rocket::trace::info!("{_err}"); } }
111+
);
111112

112113
return #Outcome::Forward((#__data, #Status::UnprocessableEntity));
113114
}
@@ -120,18 +121,25 @@ fn query_decls(route: &Route) -> Option<TokenStream> {
120121
fn request_guard_decl(guard: &Guard) -> TokenStream {
121122
let (ident, ty) = (guard.fn_ident.rocketized(), &guard.ty);
122123
define_spanned_export!(ty.span() =>
123-
__req, __data, _request, FromRequest, Outcome
124+
__req, __data, _request, display_hack, FromRequest, Outcome
124125
);
125126

126127
quote_spanned! { ty.span() =>
127128
let #ident: #ty = match <#ty as #FromRequest>::from_request(#__req).await {
128129
#Outcome::Success(__v) => __v,
129130
#Outcome::Forward(__e) => {
130-
::rocket::info!(type_name = stringify!(#ty), "guard forwarding");
131+
::rocket::trace::info!(name: "forward", parameter = stringify!(#ident),
132+
type_name = stringify!(#ty), status = __e.code,
133+
"request guard forwarding");
134+
131135
return #Outcome::Forward((#__data, __e));
132136
},
137+
#[allow(unreachable_code)]
133138
#Outcome::Error((__c, __e)) => {
134-
::rocket::info!(type_name = stringify!(#ty), "guard failed: {__e:?}");
139+
::rocket::trace::info!(name: "failure", parameter = stringify!(#ident),
140+
type_name = stringify!(#ty), reason = %#display_hack!(__e),
141+
"request guard failed");
142+
135143
return #Outcome::Error(__c);
136144
}
137145
};
@@ -142,14 +150,14 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
142150
let (i, name, ty) = (guard.index, &guard.name, &guard.ty);
143151
define_spanned_export!(ty.span() =>
144152
__req, __data, _None, _Some, _Ok, _Err,
145-
Outcome, FromSegments, FromParam, Status
153+
Outcome, FromSegments, FromParam, Status, display_hack
146154
);
147155

148156
// Returned when a dynamic parameter fails to parse.
149157
let parse_error = quote!({
150-
::rocket::info!(name: "forward",
151-
reason = %__error, parameter = #name, "type" = stringify!(#ty),
152-
"parameter forwarding");
158+
::rocket::trace::info!(name: "forward", parameter = #name,
159+
type_name = stringify!(#ty), reason = %#display_hack!(__error),
160+
"path guard forwarding");
153161

154162
#Outcome::Forward((#__data, #Status::UnprocessableEntity))
155163
});
@@ -161,10 +169,11 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
161169
match #__req.routed_segment(#i) {
162170
#_Some(__s) => match <#ty as #FromParam>::from_param(__s) {
163171
#_Ok(__v) => __v,
172+
#[allow(unreachable_code)]
164173
#_Err(__error) => return #parse_error,
165174
},
166175
#_None => {
167-
::rocket::error!(
176+
::rocket::trace::error!(
168177
"Internal invariant broken: dyn param {} not found.\n\
169178
Please report this to the Rocket issue tracker.\n\
170179
https://github.com/rwf2/Rocket/issues", #i);
@@ -176,6 +185,7 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
176185
true => quote_spanned! { ty.span() =>
177186
match <#ty as #FromSegments>::from_segments(#__req.routed_segments(#i..)) {
178187
#_Ok(__v) => __v,
188+
#[allow(unreachable_code)]
179189
#_Err(__error) => return #parse_error,
180190
}
181191
},
@@ -187,17 +197,24 @@ fn param_guard_decl(guard: &Guard) -> TokenStream {
187197

188198
fn data_guard_decl(guard: &Guard) -> TokenStream {
189199
let (ident, ty) = (guard.fn_ident.rocketized(), &guard.ty);
190-
define_spanned_export!(ty.span() => __req, __data, FromData, Outcome);
200+
define_spanned_export!(ty.span() => __req, __data, display_hack, FromData, Outcome);
191201

192202
quote_spanned! { ty.span() =>
193203
let #ident: #ty = match <#ty as #FromData>::from_data(#__req, #__data).await {
194204
#Outcome::Success(__d) => __d,
195205
#Outcome::Forward((__d, __e)) => {
196-
::rocket::info!(type_name = stringify!(#ty), "data guard forwarding");
206+
::rocket::trace::info!(name: "forward", parameter = stringify!(#ident),
207+
type_name = stringify!(#ty), status = __e.code,
208+
"data guard forwarding");
209+
197210
return #Outcome::Forward((__d, __e));
198211
}
212+
#[allow(unreachable_code)]
199213
#Outcome::Error((__c, __e)) => {
200-
::rocket::info!(type_name = stringify!(#ty), "data guard failed: {__e:?}");
214+
::rocket::trace::info!(name: "failure", parameter = stringify!(#ident),
215+
type_name = stringify!(#ty), reason = %#display_hack!(__e),
216+
"data guard failed");
217+
201218
return #Outcome::Error(__c);
202219
}
203220
};
@@ -232,7 +249,7 @@ fn internal_uri_macro_decl(route: &Route) -> TokenStream {
232249
/// Rocket generated URI macro.
233250
macro_rules! #inner_macro_name {
234251
($($token:tt)*) => {{
235-
rocket::rocket_internal_uri!(#route_uri, (#(#uri_args),*), $($token)*)
252+
::rocket::rocket_internal_uri!(#route_uri, (#(#uri_args),*), $($token)*)
236253
}};
237254
}
238255

@@ -385,6 +402,7 @@ fn codegen_route(route: Route) -> Result<TokenStream> {
385402
format: #format,
386403
rank: #rank,
387404
sentinels: #sentinels,
405+
location: (::core::file!(), ::core::line!(), ::core::column!()),
388406
}
389407
}
390408

‎core/codegen/src/exports.rs

+1
Original file line numberDiff line numberDiff line change
@@ -86,6 +86,7 @@ define_exported_paths! {
8686
_Vec => ::std::vec::Vec,
8787
_Cow => ::std::borrow::Cow,
8888
_ExitCode => ::std::process::ExitCode,
89+
display_hack => ::rocket::error::display_hack,
8990
BorrowMut => ::std::borrow::BorrowMut,
9091
Outcome => ::rocket::outcome::Outcome,
9192
FromForm => ::rocket::form::FromForm,

‎core/codegen/src/lib.rs

+1-1
Original file line numberDiff line numberDiff line change
@@ -1328,7 +1328,7 @@ pub fn catchers(input: TokenStream) -> TokenStream {
13281328
/// assert_eq!(bob2.to_string(), "/person/Bob%20Smith");
13291329
///
13301330
/// #[get("/person/<age>")]
1331-
/// fn ok(age: Result<u8, &str>) { }
1331+
/// fn ok(age: Result<u8, std::num::ParseIntError>) { }
13321332
///
13331333
/// let kid1 = uri!(ok(age = 10));
13341334
/// let kid2 = uri!(ok(12));

‎core/codegen/tests/typed-uris.rs

+16
Original file line numberDiff line numberDiff line change
@@ -709,3 +709,19 @@ fn test_vec_in_query() {
709709
uri!(h(v = &[1, 2, 3][..])) => "/?v=%01%02%03",
710710
}
711711
}
712+
713+
#[test]
714+
fn test_either() {
715+
use rocket::either::{Either, Left, Right};
716+
717+
#[get("/<_foo>")]
718+
fn f(_foo: Either<usize, &str>) { }
719+
720+
assert_uri_eq! {
721+
uri!(f(Left::<usize, &str>(123))) => "/123",
722+
uri!(f(_foo = Left::<usize, &str>(710))) => "/710",
723+
724+
uri!(f(Right::<usize, &str>("hello world"))) => "/hello%20world",
725+
uri!(f(_foo = Right::<usize, &str>("bye?"))) => "/bye%3F",
726+
}
727+
}

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

-8
Original file line numberDiff line numberDiff line change
@@ -114,14 +114,6 @@ error[E0728]: `await` is only allowed inside `async` functions and blocks
114114
73 | let _ = rocket::build().launch().await;
115115
| ^^^^^ only allowed inside `async` functions and blocks
116116

117-
error[E0728]: `await` is only allowed inside `async` functions and blocks
118-
--> tests/ui-fail-nightly/async-entry.rs:73:42
119-
|
120-
72 | fn rocket() -> _ {
121-
| ----------- this is not `async`
122-
73 | let _ = rocket::build().launch().await;
123-
| ^^^^^ only allowed inside `async` functions and blocks
124-
125117
error[E0277]: `main` has invalid return type `Rocket<Build>`
126118
--> tests/ui-fail-nightly/async-entry.rs:94:20
127119
|

0 commit comments

Comments
 (0)