Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use 'tracing' library instead of 'log'. #1579

Closed
wants to merge 4 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
2 changes: 1 addition & 1 deletion contrib/lib/Cargo.toml
Expand Up @@ -45,7 +45,7 @@ diesel_mysql_pool = ["databases", "diesel/mysql", "diesel/r2d2"]
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"] }
Expand Down
8 changes: 4 additions & 4 deletions contrib/lib/src/compression/fairing.rs
Expand Up @@ -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
);
Expand All @@ -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
);
Expand Down
15 changes: 8 additions & 7 deletions contrib/lib/src/databases/connection.rs
Expand Up @@ -4,6 +4,7 @@ use std::sync::Arc;
use rocket::{Rocket, Phase};
use rocket::fairing::{AdHoc, Fairing};
use rocket::request::{Request, Outcome, FromRequest};
use rocket::trace::error;
use rocket::outcome::IntoOutcome;
use rocket::http::Status;

Expand Down Expand Up @@ -62,8 +63,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);
error!(concat!("database ", $msg, " error for pool named `{}`"), $db_name);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please just one log per message / error + please keep logmessage clean from values (it is easier to indexing, search and anonymize in log systems, if all values are in defined files):

Suggested change
error!(concat!("database ", $msg, " error for pool named `{}`"), $db_name);
error!(
database.name = $msg,
database.pool = $db_name,
error = $error,
$efmt
);

error!($efmt, $error);
return Err($rocket);
});
}
Expand Down Expand Up @@ -96,7 +97,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(());
}
};
Expand All @@ -111,7 +112,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(())
}
}
Expand All @@ -123,12 +124,12 @@ impl<K: 'static, C: Poolable> ConnectionPool<K, C> {
Some(pool) => match pool.get().await.ok() {
Some(conn) => Some(conn),
None => {
error_!("no connections available for `{}`", std::any::type_name::<K>());
error!("no connections available for `{}`", std::any::type_name::<K>());
None
}
},
None => {
error_!("missing database fairing for `{}`", std::any::type_name::<K>());
error!("missing database fairing for `{}`", std::any::type_name::<K>());
None
}
}
Expand Down Expand Up @@ -190,7 +191,7 @@ impl<'r, K: 'static, C: Poolable> FromRequest<'r> for Connection<K, C> {
match request.rocket().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, ()))
}
}
Expand Down
11 changes: 6 additions & 5 deletions contrib/lib/src/helmet/helmet.rs
Expand Up @@ -171,8 +171,8 @@ 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!(header = %name, "Space Helmet: response contains already contains this header");
warn!("Refusing to overwrite existing header.");
continue
}

Expand Down Expand Up @@ -202,9 +202,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);
}
}
Expand Down
2 changes: 1 addition & 1 deletion contrib/lib/src/json.rs
Expand Up @@ -197,7 +197,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
})?;

Expand Down
2 changes: 1 addition & 1 deletion contrib/lib/src/lib.rs
Expand Up @@ -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;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should we be using whatever rocket is using?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you suggest changing here? I assume #[macro_use] was used to avoid needing to add use statements to each file, and I'm not aware of another way to do this (aside from making all of the different logging macros top-level exports from rocket, and #[macro_use] extern crate rocket;)

#[allow(unused_imports)] #[macro_use] extern crate rocket;

#[cfg(feature="json")] #[macro_use] pub mod json;
Expand Down
2 changes: 1 addition & 1 deletion contrib/lib/src/msgpack.rs
Expand Up @@ -185,7 +185,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
})?;

Expand Down
3 changes: 1 addition & 2 deletions contrib/lib/src/serve.rs
Expand Up @@ -317,8 +317,7 @@ 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()));
error!(path = %Paint::white(path.display()), "Bad `StaticFiles` path: invalid directory");
panic!("refusing to continue due to invalid static files path");
}

Expand Down
9 changes: 5 additions & 4 deletions contrib/lib/src/templates/context.rs
Expand Up @@ -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(|| {
jebrosen marked this conversation as resolved.
Show resolved Hide resolved
info!(path = ?info.path, "Existing");
info!(path = ?path, "Additional");
warn!("Using existing path for template '{}'.", name);
});
continue;
}

Expand Down
44 changes: 24 additions & 20 deletions contrib/lib/src/templates/fairing.rs
Expand Up @@ -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
}
};
Expand Down Expand Up @@ -94,20 +95,23 @@ 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 span = info_span!("Change detected: reloading templates.");
let _e = span.enter();
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.");
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.");
warn!("An error occurred while reloading templates.");
warn!("The existing templates will remain active.");
};
}
}
Expand Down Expand Up @@ -159,29 +163,29 @@ impl Fairing for TemplateFairing {
Some(mut ctxt) => {
match (self.callback)(&mut ctxt.engines) {
Ok(()) => Ok(rocket.manage(ContextManager::new(ctxt))),
Err(e) => {
error_!("The template customization callback returned an error:");
error_!("{}", e);
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)
}
}
}

async fn on_liftoff(&self, rocket: &Rocket<Orbit>) {
use rocket::{figment::Source, logger::PaintExt, yansi::Paint};
use rocket::{figment::Source, trace::PaintExt, yansi::Paint};

let cm = rocket.state::<ContextManager>()
.expect("Template ContextManager registered in on_ignite");

info!("{}{}:", Paint::emoji("📐 "), Paint::magenta("Templating"));
info_!("directory: {}", Paint::white(Source::from(&*cm.context().root)));
info_!("engines: {:?}", Paint::white(Engines::ENABLED_EXTENSIONS));
let span = info_span!("templating", "{}{}:", Paint::emoji("📐 "), Paint::magenta("Templating"));
let _e = span.enter();
info!(directory = %Paint::white(Source::from(&*cm.context().root)));
info!(engines = ?Paint::white(Engines::ENABLED_EXTENSIONS));
}

#[cfg(debug_assertions)]
Expand Down
13 changes: 7 additions & 6 deletions contrib/lib/src/templates/handlebars_templates.rs
Expand Up @@ -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(|| {
jebrosen marked this conversation as resolved.
Show resolved Hide resolved
info!(template.error = %e);
info!(template.path = %path.to_string_lossy());
});
return None;
}
}
Expand All @@ -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
}
}
Expand Down
7 changes: 4 additions & 3 deletions contrib/lib/src/templates/metadata.rs
Expand Up @@ -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, ()))
})
}
Expand Down
25 changes: 14 additions & 11 deletions contrib/lib/src/templates/mod.rs
Expand Up @@ -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
})?;

Expand All @@ -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
})?;

Expand All @@ -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.rocket().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();

Expand Down