Skip to content

Commit

Permalink
feat(log): set log levels on the fly
Browse files Browse the repository at this point in the history
  • Loading branch information
RolandSherwin committed Mar 18, 2024
1 parent 7596739 commit b62f016
Show file tree
Hide file tree
Showing 7 changed files with 89 additions and 73 deletions.
2 changes: 1 addition & 1 deletion sn_cli/src/cli.rs
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ pub(crate) struct Opt {
/// - Windows: C:\Users\<username>\AppData\Roaming\safe\client\logs
#[allow(rustdoc::invalid_html_tags)]
#[clap(long, value_parser = parse_log_output, verbatim_doc_comment, default_value = "data-dir")]
pub log_output_dest: Option<LogOutputDest>,
pub log_output_dest: LogOutputDest,

/// Specify the logging format.
///
Expand Down
39 changes: 18 additions & 21 deletions sn_cli/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -45,27 +45,24 @@ const CLIENT_KEY: &str = "clientkey";
async fn main() -> Result<()> {
color_eyre::install()?;
let opt = Opt::parse();
let _log_appender_guard = if let Some(log_output_dest) = opt.log_output_dest {
let logging_targets = vec![
// TODO: Reset to nice and clean defaults once we have a better idea of what we want
("sn_networking".to_string(), Level::DEBUG),
("safe".to_string(), Level::TRACE),
("sn_build_info".to_string(), Level::TRACE),
("sn_cli".to_string(), Level::TRACE),
("sn_client".to_string(), Level::TRACE),
("sn_logging".to_string(), Level::TRACE),
("sn_peers_acquisition".to_string(), Level::TRACE),
("sn_protocol".to_string(), Level::TRACE),
("sn_registers".to_string(), Level::TRACE),
("sn_transfers".to_string(), Level::TRACE),
];
let mut log_builder = LogBuilder::new(logging_targets);
log_builder.output_dest(log_output_dest);
log_builder.format(opt.log_format.unwrap_or(LogFormat::Default));
log_builder.initialize()?
} else {
None
};
let logging_targets = vec![
// TODO: Reset to nice and clean defaults once we have a better idea of what we want
("sn_networking".to_string(), Level::DEBUG),
("safe".to_string(), Level::TRACE),
("sn_build_info".to_string(), Level::TRACE),
("sn_cli".to_string(), Level::TRACE),
("sn_client".to_string(), Level::TRACE),
("sn_logging".to_string(), Level::TRACE),
("sn_peers_acquisition".to_string(), Level::TRACE),
("sn_protocol".to_string(), Level::TRACE),
("sn_registers".to_string(), Level::TRACE),
("sn_transfers".to_string(), Level::TRACE),
];
let mut log_builder = LogBuilder::new(logging_targets);
log_builder.output_dest(opt.log_output_dest);
log_builder.format(opt.log_format.unwrap_or(LogFormat::Default));
let _log_handles = log_builder.initialize()?;

#[cfg(feature = "metrics")]
tokio::spawn(init_metrics(std::process::id()));

Expand Down
36 changes: 16 additions & 20 deletions sn_faucet/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -39,25 +39,21 @@ async fn main() -> Result<()> {
Some(bootstrap_peers)
};

let _log_appender_guard = if let Some(log_output_dest) = opt.log_output_dest {
let logging_targets = vec![
// TODO: Reset to nice and clean defaults once we have a better idea of what we want
("faucet".to_string(), Level::TRACE),
("sn_faucet".to_string(), Level::TRACE),
("sn_networking".to_string(), Level::DEBUG),
("sn_build_info".to_string(), Level::TRACE),
("sn_logging".to_string(), Level::TRACE),
("sn_peers_acquisition".to_string(), Level::TRACE),
("sn_protocol".to_string(), Level::TRACE),
("sn_registers".to_string(), Level::TRACE),
("sn_transfers".to_string(), Level::TRACE),
];
let mut log_builder = LogBuilder::new(logging_targets);
log_builder.output_dest(log_output_dest);
log_builder.initialize()?
} else {
None
};
let logging_targets = vec![
// TODO: Reset to nice and clean defaults once we have a better idea of what we want
("faucet".to_string(), Level::TRACE),
("sn_faucet".to_string(), Level::TRACE),
("sn_networking".to_string(), Level::DEBUG),
("sn_build_info".to_string(), Level::TRACE),
("sn_logging".to_string(), Level::TRACE),
("sn_peers_acquisition".to_string(), Level::TRACE),
("sn_protocol".to_string(), Level::TRACE),
("sn_registers".to_string(), Level::TRACE),
("sn_transfers".to_string(), Level::TRACE),
];
let mut log_builder = LogBuilder::new(logging_targets);
log_builder.output_dest(opt.log_output_dest);
let _log_handles = log_builder.initialize()?;

info!("Instantiating a SAFE Test Faucet...");

Expand Down Expand Up @@ -138,7 +134,7 @@ struct Opt {
/// - Windows: C:\Users\<username>\AppData\Roaming\safe\client\logs
#[allow(rustdoc::invalid_html_tags)]
#[clap(long, value_parser = parse_log_output, verbatim_doc_comment, default_value = "data-dir")]
pub log_output_dest: Option<LogOutputDest>,
pub log_output_dest: LogOutputDest,

#[command(flatten)]
peers: PeersArgs,
Expand Down
3 changes: 3 additions & 0 deletions sn_logging/src/error.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,9 @@ pub enum Error {
#[error(transparent)]
Io(#[from] std::io::Error),

#[error(transparent)]
ReloadError(#[from] tracing_subscriber::reload::Error),

#[cfg(feature = "otlp")]
#[error("OpenTelemetry Tracing error: {0}")]
OpenTelemetryTracing(#[from] opentelemetry::trace::TraceError),
Expand Down
40 changes: 33 additions & 7 deletions sn_logging/src/layers.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,14 +16,15 @@ use tracing_appender::non_blocking::WorkerGuard;
use tracing_core::{Event, Level, Subscriber};
use tracing_subscriber::{
filter::Targets,
fmt as tracing_fmt,
fmt::{
self as tracing_fmt,
format::Writer,
time::{FormatTime, SystemTime},
FmtContext, FormatEvent, FormatFields,
},
layer::Filter,
registry::LookupSpan,
reload::{self, Handle},
Layer, Registry,
};

Expand All @@ -35,6 +36,27 @@ const ALL_SN_LOGS: &str = "all";
// Trace at nodes, clients, debug at networking layer
const VERBOSE_SN_LOGS: &str = "v";

/// Handle that implements functions to change the log level on the fly.
pub struct ReloadHandle(Handle<Box<dyn Filter<Registry> + Send + Sync>, Registry>);

impl ReloadHandle {
/// Modify the log level to the provided CSV value
/// Example input: `libp2p=DEBUG, tokio=INFO, all, sn_client=ERROR`
/// If any custom keyword is encountered in the CSV, for e.g., VERBOSE_SN_LOGS ('all'), then they will override some
/// of the value that you might have provided, `sn_client=ERROR` in the above example will be ignored and
/// instead will be set to `TRACE` since `all` keyword is provided.
pub fn modify_log_level(&self, logging_value: &str) -> Result<()> {
let targets: Vec<(String, Level)> = get_logging_targets(logging_value)?;
self.0.modify(|old_filter| {
let new_filter: Box<dyn Filter<Registry> + Send + Sync> =
Box::new(Targets::new().with_targets(targets));
*old_filter = new_filter;
})?;

Ok(())
}
}

#[derive(Default)]
/// Tracing log formatter setup for easier span viewing
struct LogFormatter;
Expand Down Expand Up @@ -72,7 +94,7 @@ where
#[derive(Default)]
pub(crate) struct TracingLayers {
pub(crate) layers: Vec<Box<dyn Layer<Registry> + Send + Sync>>,
pub(crate) guard: Option<WorkerGuard>,
pub(crate) log_appender_guard: Option<WorkerGuard>,
}

impl TracingLayers {
Expand All @@ -83,7 +105,7 @@ impl TracingLayers {
format: LogFormat,
max_uncompressed_log_files: Option<usize>,
max_compressed_log_files: Option<usize>,
) -> Result<()> {
) -> Result<ReloadHandle> {
let layer = match output_dest {
LogOutputDest::Stdout => {
println!("Logging to stdout");
Expand Down Expand Up @@ -113,7 +135,7 @@ impl TracingLayers {
max_uncompressed_log_files,
max_log_files,
);
self.guard = Some(worker_guard);
self.log_appender_guard = Some(worker_guard);

match format {
LogFormat::Json => tracing_fmt::layer()
Expand All @@ -139,9 +161,13 @@ impl TracingLayers {

let target_filters: Box<dyn Filter<Registry> + Send + Sync> =
Box::new(Targets::new().with_targets(targets));
let layer = layer.with_filter(target_filters);

let (filter, reload_handle) = reload::Layer::new(target_filters);

let layer = layer.with_filter(filter);
self.layers.push(Box::new(layer));
Ok(())

Ok(ReloadHandle(reload_handle))
}

#[cfg(feature = "otlp")]
Expand Down Expand Up @@ -197,7 +223,7 @@ impl TracingLayers {

/// Parses the logging targets from the env variable (SN_LOG). The crates should be given as a CSV, for e.g.,
/// `export SN_LOG = libp2p=DEBUG, tokio=INFO, all, sn_client=ERROR`
/// If any custom keyword is encountered in the CSV, for e.g., VERBOSE_SN_LOGS ('all'), then they might override some
/// If any custom keyword is encountered in the CSV, for e.g., VERBOSE_SN_LOGS ('all'), then they will override some
/// of the value that you might have provided, `sn_client=ERROR` in the above example will be ignored and
/// instead will be set to `TRACE` since `all` keyword is provided.
fn get_logging_targets(logging_env_value: &str) -> Result<Vec<(String, Level)>> {
Expand Down
24 changes: 8 additions & 16 deletions sn_logging/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ use tracing_core::{dispatcher::DefaultGuard, Level};
use tracing_subscriber::{prelude::__tracing_subscriber_SubscriberExt, util::SubscriberInitExt};

pub use error::Error;
pub use layers::ReloadHandle;

#[derive(Debug, Clone)]
pub enum LogOutputDest {
Expand Down Expand Up @@ -102,12 +103,11 @@ impl LogBuilder {
/// This guard should be held for the life of the program.
///
/// Logging should be instantiated only once.
pub fn initialize(self) -> Result<Option<WorkerGuard>> {
pub fn initialize(self) -> Result<(ReloadHandle, Option<WorkerGuard>)> {
let mut layers = TracingLayers::default();

#[cfg(not(feature = "otlp"))]
layers.fmt_layer(
self.default_logging_targets,
let reload_handle = layers.fmt_layer(
self.default_logging_targets.clone(),
&self.output_dest,
self.format,
self.max_uncompressed_log_files,
Expand All @@ -116,14 +116,6 @@ impl LogBuilder {

#[cfg(feature = "otlp")]
{
layers.fmt_layer(
self.default_logging_targets.clone(),
&self.output_dest,
self.format,
self.max_uncompressed_log_files,
self.max_compressed_log_files,
)?;

match std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT") {
Ok(_) => layers.otlp_layer(self.default_logging_targets)?,
Err(_) => println!(
Expand All @@ -141,7 +133,7 @@ impl LogBuilder {
println!("Tried to initialize and set global default subscriber more than once");
}

Ok(layers.guard)
Ok((reload_handle, layers.log_appender_guard))
}

/// Logs to the data_dir. Should be called from a single threaded tokio/non-tokio context.
Expand All @@ -160,7 +152,7 @@ impl LogBuilder {
if let Some(test_name) = std::thread::current().name() {
info!("Running test: {test_name}");
}
(layers.guard, log_guard)
(layers.log_appender_guard, log_guard)
}

/// Logs to the data_dir. Should be called from a multi threaded tokio context.
Expand All @@ -176,7 +168,7 @@ impl LogBuilder {
.try_init()
.expect("You have tried to init multi_threaded tokio logging twice\nRefer sn_logging::get_test_layers docs for more.");

layers.guard
layers.log_appender_guard
}

/// Initialize just the fmt_layer for testing purposes.
Expand All @@ -202,7 +194,7 @@ impl LogBuilder {

let mut layers = TracingLayers::default();

layers
let _reload_handle = layers
.fmt_layer(vec![], &output_dest, LogFormat::Default, None, None)
.expect("Failed to get TracingLayers");
layers
Expand Down
18 changes: 10 additions & 8 deletions sn_node/src/bin/safenode/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ use eyre::{eyre, Result};
use libp2p::{identity::Keypair, PeerId};
#[cfg(feature = "metrics")]
use sn_logging::metrics::init_metrics;
use sn_logging::{LogFormat, LogOutputDest};
use sn_logging::{LogFormat, LogOutputDest, ReloadHandle};
use sn_node::{Marker, NodeBuilder, NodeEvent, NodeEventsReceiver};
use sn_peers_acquisition::{get_peers_from_args, PeersArgs};
use sn_protocol::{node::get_safenode_root_dir, node_rpc::NodeCtrl};
Expand Down Expand Up @@ -159,7 +159,8 @@ fn main() -> Result<()> {
let node_socket_addr = SocketAddr::new(opt.ip, opt.port);
let (root_dir, keypair) = get_root_dir_and_keypair(&opt.root_dir)?;

let (log_output_dest, _log_appender_guard) = init_logging(&opt, keypair.public().to_peer_id())?;
let (log_output_dest, _log_reload_handle, _log_appender_guard) =
init_logging(&opt, keypair.public().to_peer_id())?;

let rt = Runtime::new()?;
let bootstrap_peers = rt.block_on(get_peers_from_args(opt.peers))?;
Expand Down Expand Up @@ -360,7 +361,7 @@ fn monitor_node_events(mut node_events_rx: NodeEventsReceiver, ctrl_tx: mpsc::Se
});
}

fn init_logging(opt: &Opt, peer_id: PeerId) -> Result<(String, Option<WorkerGuard>)> {
fn init_logging(opt: &Opt, peer_id: PeerId) -> Result<(String, ReloadHandle, Option<WorkerGuard>)> {
let logging_targets = vec![
("sn_networking".to_string(), Level::INFO),
("safenode".to_string(), Level::DEBUG),
Expand All @@ -383,7 +384,7 @@ fn init_logging(opt: &Opt, peer_id: PeerId) -> Result<(String, Option<WorkerGuar
};

#[cfg(not(feature = "otlp"))]
let log_appender_guard = {
let (reload_handle, log_appender_guard) = {
let mut log_builder = sn_logging::LogBuilder::new(logging_targets);
log_builder.output_dest(output_dest.clone());
log_builder.format(opt.log_format.unwrap_or(LogFormat::Default));
Expand All @@ -398,10 +399,10 @@ fn init_logging(opt: &Opt, peer_id: PeerId) -> Result<(String, Option<WorkerGuar
};

#[cfg(feature = "otlp")]
let (_rt, log_appender_guard) = {
let (_rt, reload_handle, log_appender_guard) = {
// init logging in a separate runtime if we are sending traces to an opentelemetry server
let rt = Runtime::new()?;
let guard = rt.block_on(async {
let (reload_handle, log_appender_guard) = rt.block_on(async {
let mut log_builder = sn_logging::LogBuilder::new(logging_targets);
log_builder.output_dest(output_dest.clone());
log_builder.format(opt.log_format.unwrap_or(LogFormat::Default));
Expand All @@ -413,9 +414,10 @@ fn init_logging(opt: &Opt, peer_id: PeerId) -> Result<(String, Option<WorkerGuar
}
log_builder.initialize()
})?;
(rt, guard)
(rt, reload_handle, log_appender_guard)
};
Ok((output_dest.to_string(), log_appender_guard))

Ok((output_dest.to_string(), reload_handle, log_appender_guard))
}

fn create_secret_key_file(path: impl AsRef<Path>) -> Result<std::fs::File, std::io::Error> {
Expand Down

0 comments on commit b62f016

Please sign in to comment.