Skip to content

Commit

Permalink
wip: allow dynamic selection of log fmt
Browse files Browse the repository at this point in the history
  • Loading branch information
SergioBenitez committed May 17, 2024
1 parent 67485ba commit c5979c5
Show file tree
Hide file tree
Showing 10 changed files with 141 additions and 62 deletions.
2 changes: 1 addition & 1 deletion core/lib/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,7 @@ thread_local = { version = "1.1", optional = true }
version = "0.3.18"
optional = true
default-features = false
features = ["fmt", "tracing-log"]
features = ["fmt", "tracing-log", "parking_lot"]

[dependencies.rocket_codegen]
version = "0.6.0-dev"
Expand Down
20 changes: 14 additions & 6 deletions core/lib/src/config/config.rs
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ use crate::config::{ShutdownConfig, Ident, CliColors};
use crate::request::{self, Request, FromRequest};
use crate::http::uncased::Uncased;
use crate::data::Limits;
use crate::trace::Traceable;
use crate::trace::{Traceable, TraceFormat};

/// Rocket server configuration.
///
Expand All @@ -26,9 +26,10 @@ use crate::trace::Traceable;
/// the debug profile while [`Config::release_default()`] the default values for
/// the release profile. The [`Config::default()`] method automatically selects
/// the appropriate of the two based on the selected profile. With the exception
/// of `log_level`, which is `normal` in `debug` and `critical` in `release`,
/// and `secret_key`, which is regenerated from a random value if not set in
/// "debug" mode only, all default values are identical in all profiles.
/// of `log_level` and `log_format`, which are `info` / `pretty` in `debug` and
/// `error` / `compact` in `release`, and `secret_key`, which is regenerated
/// from a random value if not set in "debug" mode only, all default values are
/// identical in all profiles.
///
/// # Provider Details
///
Expand Down Expand Up @@ -124,6 +125,8 @@ pub struct Config {
/// Max level to log. **(default: _debug_ `info` / _release_ `error`)**
#[serde(with = "crate::trace::level")]
pub log_level: Option<Level>,
/// Format to use when logging. **(default: _debug_ `pretty` / _release_ `compact`)**
pub log_format: TraceFormat,
/// Whether to use colors and emoji when logging. **(default:
/// [`CliColors::Auto`])**
pub cli_colors: CliColors,
Expand Down Expand Up @@ -193,6 +196,7 @@ impl Config {
secret_key: SecretKey::zero(),
shutdown: ShutdownConfig::default(),
log_level: Some(Level::INFO),
log_format: TraceFormat::Pretty,
cli_colors: CliColors::Auto,
__non_exhaustive: (),
}
Expand All @@ -217,6 +221,7 @@ impl Config {
Config {
profile: Self::RELEASE_PROFILE,
log_level: Some(Level::ERROR),
log_format: TraceFormat::Compact,
..Config::debug_default()
}
}
Expand Down Expand Up @@ -354,6 +359,9 @@ impl Config {
/// The stringy parameter name for setting/extracting [`Config::log_level`].
pub const LOG_LEVEL: &'static str = "log_level";

/// The stringy parameter name for setting/extracting [`Config::log_format`].
pub const LOG_FORMAT: &'static str = "log_format";

/// The stringy parameter name for setting/extracting [`Config::shutdown`].
pub const SHUTDOWN: &'static str = "shutdown";

Expand All @@ -364,8 +372,8 @@ impl Config {
pub const PARAMETERS: &'static [&'static str] = &[
Self::WORKERS, Self::MAX_BLOCKING, Self::KEEP_ALIVE, Self::IDENT,
Self::IP_HEADER, Self::PROXY_PROTO_HEADER, Self::LIMITS,
Self::SECRET_KEY, Self::TEMP_DIR, Self::LOG_LEVEL, Self::SHUTDOWN,
Self::CLI_COLORS,
Self::SECRET_KEY, Self::TEMP_DIR, Self::LOG_LEVEL, Self::LOG_FORMAT,
Self::SHUTDOWN, Self::CLI_COLORS,
];

/// The stringy parameter name for setting/extracting [`Config::profile`].
Expand Down
2 changes: 1 addition & 1 deletion core/lib/src/trace/level.rs
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ pub fn serialize<S: Serializer>(level: &Option<Level>, s: S) -> Result<S::Ok, S:
pub fn deserialize<'de, D: Deserializer<'de>>(de: D) -> Result<Option<Level>, D::Error> {
struct Visitor;

const E: &str = r#"one of "off", "error", "warn", "info", "debug", "trace", or a number 0-5"#;
const E: &str = r#"one of "off", "error", "warn", "info", "debug", "trace", or 0-5"#;

impl<'de> de::Visitor<'de> for Visitor {
type Value = Option<Level>;
Expand Down
19 changes: 14 additions & 5 deletions core/lib/src/trace/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -14,10 +14,19 @@ pub use traceable::{Traceable, TraceableCollection};
#[doc(inline)]
pub use macros::*;

pub fn init<'a, T: Into<Option<&'a crate::Config>>>(_config: T) {
#[cfg(all(feature = "trace", debug_assertions))]
subscriber::RocketFmt::<subscriber::Pretty>::init(_config.into());
#[derive(Debug, Copy, Clone, PartialEq, Eq, Hash, serde::Deserialize, serde::Serialize)]
#[serde(crate = "rocket::serde")]
pub enum TraceFormat {
#[serde(rename = "pretty")]
#[serde(alias = "PRETTY")]
Pretty,
#[serde(rename = "compact")]
#[serde(alias = "COMPACT")]
Compact
}

#[cfg(all(feature = "trace", not(debug_assertions)))]
subscriber::RocketFmt::<subscriber::Compact>::init(_config.into());
#[cfg_attr(nightly, doc(cfg(feature = "trace")))]
pub fn init<'a, T: Into<Option<&'a crate::Config>>>(config: T) {
#[cfg(feature = "trace")]
crate::trace::subscriber::RocketDynFmt::init(config.into())
}
39 changes: 7 additions & 32 deletions core/lib/src/trace/subscriber/common.rs
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,8 @@ use std::fmt;
use std::cell::Cell;
use std::sync::OnceLock;

use tracing::{Level, Metadata};
use tracing::field::Field;

use tracing::{Level, Metadata};
use tracing_subscriber::prelude::*;
use tracing_subscriber::layer::Layered;
use tracing_subscriber::{reload, filter, Layer, Registry};
Expand All @@ -18,10 +17,10 @@ use crate::trace::subscriber::{RecordDisplay, RequestId, RequestIdLayer};
use crate::util::Formatter;

mod private {
pub trait FmtKind: Default + Copy + Send + Sync + 'static { }
pub trait FmtKind: Send + Sync + 'static { }

impl FmtKind for crate::trace::subscriber::Pretty {}
impl FmtKind for crate::trace::subscriber::Compact {}
impl FmtKind for crate::trace::subscriber::Pretty { }
impl FmtKind for crate::trace::subscriber::Compact { }
}

#[derive(Default)]
Expand All @@ -34,7 +33,7 @@ pub struct RocketFmt<K: private::FmtKind> {

pub type Handle<K> = reload::Handle<RocketFmt<K>, Layered<RequestIdLayer, Registry>>;

impl<K: private::FmtKind> RocketFmt<K> {
impl<K: private::FmtKind + Default + Copy> RocketFmt<K> {
pub(crate) fn state(&self) -> K {
self.state.get_or_default().get()
}
Expand All @@ -45,33 +44,9 @@ impl<K: private::FmtKind> RocketFmt<K> {
update(&mut old);
cell.set(old);
}
}

pub(crate) fn init_with(config: Option<&Config>, handle: &OnceLock<Handle<K>>)
where Self: Layer<Layered<RequestIdLayer, Registry>>
{
// Do nothing if there's no config and we've already initialized.
if config.is_none() && handle.get().is_some() {
return;
}

let workers = config.map(|c| c.workers).unwrap_or(num_cpus::get());
let cli_colors = config.map(|c| c.cli_colors).unwrap_or(CliColors::Auto);
let log_level = config.map(|c| c.log_level).unwrap_or(Some(Level::INFO));

let formatter = RocketFmt::new(workers, cli_colors, log_level);
let (layer, reload_handle) = reload::Layer::new(formatter);
let result = tracing_subscriber::registry()
.with(RequestId::layer())
.with(layer)
.try_init();

if result.is_ok() {
assert!(handle.set(reload_handle).is_ok());
} if let Some(handle) = handle.get() {
assert!(handle.modify(|layer| layer.reset(cli_colors, log_level)).is_ok());
}
}

impl<K: private::FmtKind> RocketFmt<K> {
pub fn new(workers: usize, cli_colors: CliColors, level: Option<Level>) -> Self {
Self {
state: ThreadLocal::with_capacity(workers),
Expand Down
16 changes: 5 additions & 11 deletions core/lib/src/trace/subscriber/compact.rs
Original file line number Diff line number Diff line change
@@ -1,10 +1,9 @@
use std::num::NonZeroU64;

use std::fmt;
use std::sync::OnceLock;
use std::time::Instant;
use std::num::NonZeroU64;

use time::OffsetDateTime;
use tracing::level_filters::LevelFilter;
use tracing::{Event, Level, Metadata, Subscriber};
use tracing::span::{Attributes, Id, Record};

Expand All @@ -15,7 +14,7 @@ use tracing_subscriber::field::RecordFields;
use yansi::{Paint, Painted};

use crate::util::Formatter;
use crate::trace::subscriber::{Data, Handle, RocketFmt};
use crate::trace::subscriber::{Data, RocketFmt};

#[derive(Debug, Default, Copy, Clone)]
pub struct Compact {
Expand All @@ -39,12 +38,6 @@ impl RequestData {
}

impl RocketFmt<Compact> {
pub fn init(config: Option<&crate::Config>) {
static HANDLE: OnceLock<Handle<Compact>> = OnceLock::new();

Self::init_with(config, &HANDLE);
}

fn request_span_id(&self) -> Option<Id> {
self.state().request.map(Id::from_non_zero_u64)
}
Expand All @@ -69,8 +62,9 @@ impl RocketFmt<Compact> {
.then_some(meta.target())
.unwrap_or(meta.name());

let pad = self.level.map_or(0, |lvl| lvl.as_str().len());
let timestamp = self.timestamp_for(OffsetDateTime::now_utc());
Formatter(move |f| write!(f, "{} {:>5} {} ",
Formatter(move |f| write!(f, "{} {:>pad$} {} ",
timestamp.paint(style).primary().dim(),
meta.level().paint(style),
name.paint(style).primary()))
Expand Down
96 changes: 96 additions & 0 deletions core/lib/src/trace/subscriber/dynamic.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,96 @@
use std::sync::OnceLock;

use tracing::{Dispatch, Event, Level, Metadata};
use tracing::subscriber::{Subscriber, Interest};
use tracing::span::{Attributes, Id, Record};
use tracing_subscriber::registry::{Registry, LookupSpan};
use tracing_subscriber::layer::{Context, Layer, Layered, SubscriberExt};
use tracing_subscriber::reload;
use tracing_subscriber::util::SubscriberInitExt;

use crate::config::{Config, CliColors};
use crate::trace::subscriber::{Compact, Pretty, RequestId, RequestIdLayer, RocketFmt};
use crate::trace::TraceFormat;

pub struct RocketDynFmt {
inner: either::Either<RocketFmt<Compact>, RocketFmt<Pretty>>,
}

impl From<RocketFmt<Compact>> for RocketDynFmt {
fn from(value: RocketFmt<Compact>) -> Self {
RocketDynFmt { inner: either::Either::Left(value) }
}
}

impl From<RocketFmt<Pretty>> for RocketDynFmt {
fn from(value: RocketFmt<Pretty>) -> Self {
RocketDynFmt { inner: either::Either::Right(value) }
}
}

impl RocketDynFmt {
pub fn init(config: Option<&Config>) {
type Handle = reload::Handle<RocketDynFmt, Layered<RequestIdLayer, Registry>>;

static HANDLE: OnceLock<Handle> = OnceLock::new();

// Do nothing if there's no config and we've already initialized.
if config.is_none() && HANDLE.get().is_some() {
return;
}

let workers = config.map(|c| c.workers).unwrap_or(num_cpus::get());
let colors = config.map(|c| c.cli_colors).unwrap_or(CliColors::Auto);
let level = config.map(|c| c.log_level).unwrap_or(Some(Level::INFO));
let format = config.map(|c| c.log_format).unwrap_or(TraceFormat::Pretty);

let formatter = |format| match format {
TraceFormat::Pretty => Self::from(RocketFmt::<Pretty>::new(workers, colors, level)),
TraceFormat::Compact => Self::from(RocketFmt::<Compact>::new(workers, colors, level)),
};

let (layer, reload_handle) = reload::Layer::new(formatter(format));
let result = tracing_subscriber::registry()
.with(RequestId::layer())
.with(layer)
.try_init();

if result.is_ok() {
assert!(HANDLE.set(reload_handle).is_ok());
} if let Some(handle) = HANDLE.get() {
assert!(handle.modify(|layer| *layer = formatter(format)).is_ok());
}
}

pub fn reset(&mut self, cli_colors: CliColors, level: Option<Level>) {
either::for_both!(&mut self.inner, f => f.reset(cli_colors, level))
}
}

macro_rules! forward {
($T:ident => $(& $r:tt)? $method:ident ( $($p:ident : $t:ty),* ) $(-> $R:ty)?) => {
#[inline(always)]
fn $method(& $($r)? self $(, $p : $t)*) $(-> $R)? {
match & $($r)* self.inner {
either::Either::Left(layer) => Layer::<$T>::$method(layer, $($p),*),
either::Either::Right(layer) => Layer::<$T>::$method(layer, $($p),*),
}
}
};
}

impl<S: Subscriber + for<'a> LookupSpan<'a>> Layer<S> for RocketDynFmt {
forward!(S => on_register_dispatch(subscriber: &Dispatch));
forward!(S => &mut on_layer(subscriber: &mut S));
forward!(S => register_callsite(metadata: &'static Metadata<'static>) -> Interest);
forward!(S => enabled(metadata: &Metadata<'_>, ctx: Context<'_, S>) -> bool);
forward!(S => on_new_span(attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>));
forward!(S => on_record(_span: &Id, _values: &Record<'_>, _ctx: Context<'_, S>));
forward!(S => on_follows_from(_span: &Id, _follows: &Id, _ctx: Context<'_, S>));
forward!(S => event_enabled(_event: &Event<'_>, _ctx: Context<'_, S>) -> bool);
forward!(S => on_event(_event: &Event<'_>, _ctx: Context<'_, S>));
forward!(S => on_enter(_id: &Id, _ctx: Context<'_, S>));
forward!(S => on_exit(_id: &Id, _ctx: Context<'_, S>));
forward!(S => on_close(_id: Id, _ctx: Context<'_, S>));
forward!(S => on_id_change(_old: &Id, _new: &Id, _ctx: Context<'_, S>));
}
2 changes: 2 additions & 0 deletions core/lib/src/trace/subscriber/mod.rs
Original file line number Diff line number Diff line change
@@ -1,13 +1,15 @@
mod visit;
mod pretty;
mod compact;
mod dynamic;
mod common;
mod request_id;

pub use pretty::Pretty;
pub use compact::Compact;
pub use common::RocketFmt;
pub use request_id::{RequestId, RequestIdLayer};
pub use dynamic::RocketDynFmt;

pub(crate) use common::Handle;
pub(crate) use visit::{RecordDisplay, Data};
6 changes: 0 additions & 6 deletions core/lib/src/trace/subscriber/pretty.rs
Original file line number Diff line number Diff line change
Expand Up @@ -20,12 +20,6 @@ pub struct Pretty {
}

impl RocketFmt<Pretty> {
pub fn init(config: Option<&crate::Config>) {
static HANDLE: OnceLock<Handle<Pretty>> = OnceLock::new();

Self::init_with(config, &HANDLE);
}

fn indent(&self) -> &'static str {
static INDENT: &[&str] = &["", " ", " "];
INDENT.get(self.state().depth as usize).copied().unwrap_or(" ")
Expand Down
1 change: 1 addition & 0 deletions core/lib/src/trace/traceable.rs
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,7 @@ impl Traceable for Config {
event! { level, "config",
http2 = cfg!(feature = "http2"),
log_level = self.log_level.map(|l| l.as_str()),
log_format = ?self.log_format,
cli_colors = %self.cli_colors,
workers = self.workers,
max_blocking = self.max_blocking,
Expand Down

0 comments on commit c5979c5

Please sign in to comment.