Skip to content
This repository was archived by the owner on Nov 15, 2023. It is now read-only.
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
59 commits
Select commit Hold shift + click to select a range
0c480ef
Add filter reload handle
mattrutherford Oct 30, 2020
767f61a
add RPC, move logging module from cli to tracing
mattrutherford Oct 30, 2020
5643e7e
remove dup fn
mattrutherford Oct 30, 2020
cd8815e
working example
mattrutherford Oct 31, 2020
eb429e1
Update client/rpc-api/src/system/mod.rs
dvdplm Nov 2, 2020
884c1db
Prefer "set" to "reload"
dvdplm Nov 3, 2020
57ae457
Re-enable the commented out features of the logger
dvdplm Nov 4, 2020
297e75f
Merge branch 'master' into log-reloading
dvdplm Nov 4, 2020
7960ebb
Remove duplicate code
dvdplm Nov 4, 2020
8ca1301
cleanup
dvdplm Nov 4, 2020
2b11d45
unneeded lvar
dvdplm Nov 8, 2020
86ad90a
Merge branch 'master' into log-reloading
dvdplm Nov 9, 2020
1406207
Bump to latest patch release
dvdplm Nov 9, 2020
2d8dfa0
Add new CLI option to disable log filter reloading,
mattrutherford Nov 9, 2020
992e69c
Merge branch 'log-reloading' of github.com:paritytech/substrate into …
mattrutherford Nov 9, 2020
65ad10d
Apply suggestions from code review
mattrutherford Nov 9, 2020
d9a815a
Applied suggestions from reviews
mattrutherford Nov 10, 2020
f2c57fb
Fix calls to init_logger()
dvdplm Nov 11, 2020
1906cc9
Handle errors when parsing logging directives
dvdplm Nov 11, 2020
714eb48
Deny `system_setLogFilter` RPC by default
dvdplm Nov 11, 2020
3d7d458
One more time
dvdplm Nov 11, 2020
d82a74a
Don't ignore parse errors for log directives set via CLI or RPC
mattrutherford Nov 18, 2020
437295b
Merge branch 'log-reloading' of github.com:paritytech/substrate into …
mattrutherford Nov 18, 2020
ae4a0ac
Improve docs
mattrutherford Nov 18, 2020
f81577f
Apply suggestions from code review
mattrutherford Nov 18, 2020
b18002d
Update client/cli/src/config.rs
mattrutherford Nov 18, 2020
57bc9ac
Merge branch 'master' into log-reloading
mattrutherford Nov 18, 2020
1e8b115
fix merge errors
mattrutherford Nov 19, 2020
dbd3a12
include default directives with system_setLogFilter RPC,
mattrutherford Nov 19, 2020
8f4810f
Merge branch 'log-reloading' of github.com:paritytech/substrate into …
mattrutherford Nov 19, 2020
fd82f68
docs etc...
mattrutherford Nov 19, 2020
89f615d
update test
mattrutherford Nov 19, 2020
65f58b7
refactor: rename fn
mattrutherford Nov 19, 2020
4c51a08
Add a test for system_set_log_filter – NOTE: the code should likely c…
dvdplm Nov 20, 2020
04e1786
Update client/cli/src/lib.rs
dvdplm Nov 24, 2020
c0996c5
Address review grumbles
dvdplm Nov 24, 2020
68f208e
Merge branch 'log-reloading' of github.com:paritytech/substrate into …
dvdplm Nov 24, 2020
cd51835
Add doc note on panicking behaviour
dvdplm Nov 24, 2020
f41b93f
print all invalid directives before panic
mattrutherford Nov 24, 2020
23938a4
change RPCs to: addLogFilter and resetLogFilter
mattrutherford Nov 24, 2020
f90443a
make CLI log directives default
mattrutherford Nov 24, 2020
37565c1
add comments
mattrutherford Nov 24, 2020
d827037
restore previous behaviour to panic when hard-coded directives are in…
mattrutherford Nov 25, 2020
08c8753
change/refactor directive parsing
mattrutherford Nov 25, 2020
59ad63e
fix line width
mattrutherford Nov 25, 2020
2d96c18
add test for log filter reloading
mattrutherford Nov 27, 2020
3d49c2a
Apply suggestions from code review
mattrutherford Nov 30, 2020
098e730
finish up suggestions from code review
mattrutherford Nov 30, 2020
b5d4378
improve test
mattrutherford Nov 30, 2020
5da34f0
change expect message
mattrutherford Nov 30, 2020
728ed21
change fn name
mattrutherford Nov 30, 2020
990c0c9
Apply suggestions from code review
mattrutherford Nov 30, 2020
1a7cf5c
Apply suggestions from code review
mattrutherford Nov 30, 2020
b941066
add docs, remove unused fn
mattrutherford Nov 30, 2020
1207ef7
propagate Err on invalid log directive
mattrutherford Dec 1, 2020
042e4fe
Merge branch 'master' into log-reloading
mattrutherford Dec 1, 2020
397b09c
Update tracing-subscriber version
mattrutherford Dec 1, 2020
0489d8a
Improve docs for `disable_log_reloading` CLI param
mattrutherford Dec 2, 2020
5baa021
Merge branch 'master' into log-reloading
mattrutherford Dec 2, 2020
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 7 additions & 1 deletion Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

5 changes: 2 additions & 3 deletions client/cli/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -16,8 +16,6 @@ targets = ["x86_64-unknown-linux-gnu"]
log = "0.4.11"
atty = "0.2.13"
regex = "1.4.2"
lazy_static = "1.4.0"
ansi_term = "0.12.1"
tokio = { version = "0.2.21", features = [ "signal", "rt-core", "rt-threaded", "blocking" ] }
futures = "0.3.4"
fdlimit = "0.2.1"
Expand Down Expand Up @@ -47,7 +45,7 @@ chrono = "0.4.10"
serde = "1.0.111"
tracing = "0.1.22"
tracing-log = "0.1.1"
tracing-subscriber = "0.2.10"
tracing-subscriber = "0.2.15"
sc-cli-proc-macro = { version = "2.0.0", path = "./proc-macro" }
thiserror = "1.0.21"

Expand All @@ -56,6 +54,7 @@ rpassword = "5.0.0"

[dev-dependencies]
tempfile = "3.1.0"
ansi_term = "0.12.1"

[features]
wasmtime = [
Expand Down
28 changes: 17 additions & 11 deletions client/cli/src/config.rs
Original file line number Diff line number Diff line change
Expand Up @@ -408,22 +408,18 @@ pub trait CliConfiguration<DCV: DefaultConfigurationValues = ()>: Sized {

/// Get the tracing targets from the current object (if any)
///
/// By default this is retrieved from `ImportParams` if it is available. Otherwise its
/// By default this is retrieved from [`SharedParams`] if it is available. Otherwise its
/// `None`.
fn tracing_targets(&self) -> Result<Option<String>> {
Ok(self.import_params()
.map(|x| x.tracing_targets())
.unwrap_or_else(|| Default::default()))
Ok(self.shared_params().tracing_targets())
}

/// Get the TracingReceiver value from the current object
///
/// By default this is retrieved from `ImportParams` if it is available. Otherwise its
/// By default this is retrieved from [`SharedParams`] if it is available. Otherwise its
/// `TracingReceiver::default()`.
fn tracing_receiver(&self) -> Result<TracingReceiver> {
Ok(self.import_params()
.map(|x| x.tracing_receiver())
.unwrap_or_default())
Ok(self.shared_params().tracing_receiver())
}

/// Get the node key from the current object
Expand Down Expand Up @@ -519,6 +515,7 @@ pub trait CliConfiguration<DCV: DefaultConfigurationValues = ()>: Sized {
dev_key_seed: self.dev_key_seed(is_dev)?,
tracing_targets: self.tracing_targets()?,
tracing_receiver: self.tracing_receiver()?,
disable_log_reloading: self.is_log_filter_reloading_disabled()?,
chain_spec,
max_runtime_instances,
announce_block: self.announce_block()?,
Expand All @@ -538,6 +535,11 @@ pub trait CliConfiguration<DCV: DefaultConfigurationValues = ()>: Sized {
Ok(self.shared_params().log_filters().join(","))
}

/// Is log reloading disabled (enabled by default)
fn is_log_filter_reloading_disabled(&self) -> Result<bool> {
Ok(self.shared_params().is_log_filter_reloading_disabled())
}

/// Initialize substrate. This must be done only once per process.
///
/// This method:
Expand All @@ -549,12 +551,16 @@ pub trait CliConfiguration<DCV: DefaultConfigurationValues = ()>: Sized {
let logger_pattern = self.log_filters()?;
let tracing_receiver = self.tracing_receiver()?;
let tracing_targets = self.tracing_targets()?;
let disable_log_reloading = self.is_log_filter_reloading_disabled()?;

sp_panic_handler::set(&C::support_url(), &C::impl_version());

if let Err(e) = init_logger(&logger_pattern, tracing_receiver, tracing_targets) {
log::warn!("💬 Problem initializing global logging framework: {:}", e)
}
init_logger(
&logger_pattern,
tracing_receiver,
tracing_targets,
disable_log_reloading,
)?;

if let Some(new_limit) = fdlimit::raise_fd_limit() {
if new_limit < RECOMMENDED_OPEN_FILE_DESCRIPTOR_LIMIT {
Expand Down
110 changes: 69 additions & 41 deletions client/cli/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@ pub mod arg_enums;
mod commands;
mod config;
mod error;
mod logging;
mod params;
mod runner;

Expand All @@ -48,8 +47,13 @@ use structopt::{
StructOpt,
};
use tracing_subscriber::{
filter::Directive, fmt::time::ChronoLocal, layer::SubscriberExt, FmtSubscriber, Layer,
fmt::time::ChronoLocal,
EnvFilter,
FmtSubscriber,
Layer,
layer::SubscriberExt,
};
pub use sc_tracing::logging;

pub use logging::PREFIX_LOG_SPAN;
#[doc(hidden)]
Expand Down Expand Up @@ -243,12 +247,16 @@ pub fn init_logger(
pattern: &str,
tracing_receiver: sc_tracing::TracingReceiver,
profiling_targets: Option<String>,
disable_log_reloading: bool,
) -> std::result::Result<(), String> {
fn parse_directives(dirs: impl AsRef<str>) -> Vec<Directive> {
dirs.as_ref()
.split(',')
.filter_map(|s| s.parse().ok())
.collect()
use sc_tracing::parse_default_directive;

// Accept all valid directives and print invalid ones
fn parse_user_directives(mut env_filter: EnvFilter, dirs: &str) -> std::result::Result<EnvFilter, String> {
for dir in dirs.split(',') {
env_filter = env_filter.add_directive(parse_default_directive(&dir)?);
}
Ok(env_filter)
}

if let Err(e) = tracing_log::LogTracer::init() {
Expand All @@ -257,33 +265,35 @@ pub fn init_logger(
))
}

let mut env_filter = tracing_subscriber::EnvFilter::default()
// Initialize filter - ensure to use `parse_default_directive` for any defaults to persist
// after log filter reloading by RPC
let mut env_filter = EnvFilter::default()
// Enable info
.add_directive(parse_default_directive("info")
.expect("provided directive is valid"))
// Disable info logging by default for some modules.
.add_directive("ws=off".parse().expect("provided directive is valid"))
.add_directive("yamux=off".parse().expect("provided directive is valid"))
.add_directive("cranelift_codegen=off".parse().expect("provided directive is valid"))
.add_directive(parse_default_directive("ws=off")
.expect("provided directive is valid"))
.add_directive(parse_default_directive("yamux=off")
.expect("provided directive is valid"))
.add_directive(parse_default_directive("cranelift_codegen=off")
.expect("provided directive is valid"))
// Set warn logging by default for some modules.
.add_directive("cranelift_wasm=warn".parse().expect("provided directive is valid"))
.add_directive("hyper=warn".parse().expect("provided directive is valid"))
// Enable info for others.
.add_directive(tracing_subscriber::filter::LevelFilter::INFO.into());
.add_directive(parse_default_directive("cranelift_wasm=warn")
.expect("provided directive is valid"))
.add_directive(parse_default_directive("hyper=warn")
.expect("provided directive is valid"));

if let Ok(lvl) = std::env::var("RUST_LOG") {
if lvl != "" {
// We're not sure if log or tracing is available at this moment, so silently ignore the
// parse error.
for directive in parse_directives(lvl) {
env_filter = env_filter.add_directive(directive);
}
env_filter = parse_user_directives(env_filter, &lvl)?;
}
}

if pattern != "" {
// We're not sure if log or tracing is available at this moment, so silently ignore the
// parse error.
for directive in parse_directives(pattern) {
env_filter = env_filter.add_directive(directive);
}
env_filter = parse_user_directives(env_filter, pattern)?;
}

// If we're only logging `INFO` entries then we'll use a simplified logging format.
Expand All @@ -293,19 +303,16 @@ pub fn init_logger(
};

// Always log the special target `sc_tracing`, overrides global level.
// Required because profiling traces are emitted via `sc_tracing`
// NOTE: this must be done after we check the `max_level_hint` otherwise
// it is always raised to `TRACE`.
env_filter = env_filter.add_directive(
"sc_tracing=trace"
.parse()
.expect("provided directive is valid"),
parse_default_directive("sc_tracing=trace").expect("provided directive is valid")
);

// Make sure to include profiling targets in the filter
if let Some(profiling_targets) = profiling_targets.clone() {
for directive in parse_directives(profiling_targets) {
env_filter = env_filter.add_directive(directive);
}
env_filter = parse_user_directives(env_filter, &profiling_targets)?;
}

let enable_color = atty::is(atty::Stream::Stderr);
Expand All @@ -315,22 +322,42 @@ pub fn init_logger(
"%Y-%m-%d %H:%M:%S%.3f".to_string()
});

let subscriber = FmtSubscriber::builder()
let subscriber_builder = FmtSubscriber::builder()
.with_env_filter(env_filter)
.with_writer(std::io::stderr)
.with_writer(std::io::stderr as _)
.event_format(logging::EventFormat {
timer,
enable_color,
display_target: !simple,
display_level: !simple,
display_thread_name: !simple,
enable_color,
})
.finish()
.with(logging::NodeNameLayer);
});
if disable_log_reloading {
let subscriber = subscriber_builder
.finish()
.with(logging::NodeNameLayer);
initialize_tracing(subscriber, tracing_receiver, profiling_targets)
} else {
let subscriber_builder = subscriber_builder.with_filter_reloading();
let handle = subscriber_builder.reload_handle();
sc_tracing::set_reload_handle(handle);
let subscriber = subscriber_builder
.finish()
.with(logging::NodeNameLayer);
initialize_tracing(subscriber, tracing_receiver, profiling_targets)
}
}

fn initialize_tracing<S>(
subscriber: S,
tracing_receiver: sc_tracing::TracingReceiver,
profiling_targets: Option<String>,
) -> std::result::Result<(), String>
where
S: tracing::Subscriber + Send + Sync + 'static,
{
if let Some(profiling_targets) = profiling_targets {
let profiling = sc_tracing::ProfilingLayer::new(tracing_receiver, &profiling_targets);

if let Err(e) = tracing::subscriber::set_global_default(subscriber.with(profiling)) {
return Err(format!(
"Registering Substrate tracing subscriber failed: {:}!", e
Expand All @@ -339,7 +366,7 @@ pub fn init_logger(
} else {
if let Err(e) = tracing::subscriber::set_global_default(subscriber) {
return Err(format!(
"Registering Substrate tracing subscriber failed: {:}!", e
"Registering Substrate tracing subscriber failed: {:}!", e
))
}
}
Expand All @@ -356,7 +383,7 @@ mod tests {
#[test]
fn test_logger_filters() {
let test_pattern = "afg=debug,sync=trace,client=warn,telemetry,something-with-dash=error";
init_logger(&test_pattern, Default::default(), Default::default()).unwrap();
init_logger(&test_pattern, Default::default(), Default::default(), false).unwrap();

tracing::dispatcher::get_default(|dispatcher| {
let test_filter = |target, level| {
Expand Down Expand Up @@ -415,7 +442,7 @@ mod tests {
fn log_something_with_dash_target_name() {
if env::var("ENABLE_LOGGING").is_ok() {
let test_pattern = "test-target=info";
init_logger(&test_pattern, Default::default(), Default::default()).unwrap();
init_logger(&test_pattern, Default::default(), Default::default(), false).unwrap();

log::info!(target: "test-target", "{}", EXPECTED_LOG_MESSAGE);
}
Expand Down Expand Up @@ -450,7 +477,8 @@ mod tests {
#[test]
fn prefix_in_log_lines_entrypoint() {
if env::var("ENABLE_LOGGING").is_ok() {
init_logger("", Default::default(), Default::default()).unwrap();
let test_pattern = "test-target=info";
init_logger(&test_pattern, Default::default(), Default::default(), false).unwrap();
prefix_in_log_lines_process();
}
}
Expand All @@ -466,7 +494,7 @@ mod tests {
#[test]
fn do_not_write_with_colors_on_tty_entrypoint() {
if env::var("ENABLE_LOGGING").is_ok() {
init_logger("", Default::default(), Default::default()).unwrap();
init_logger("", Default::default(), Default::default(), false).unwrap();
log::info!("{}", ansi_term::Colour::Yellow.paint(EXPECTED_LOG_MESSAGE));
}
}
Expand Down
25 changes: 1 addition & 24 deletions client/cli/src/params/import_params.rs
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@
// along with this program. If not, see <https://www.gnu.org/licenses/>.

use crate::arg_enums::{
ExecutionStrategy, TracingReceiver, WasmExecutionMethod, DEFAULT_EXECUTION_BLOCK_CONSTRUCTION,
ExecutionStrategy, WasmExecutionMethod, DEFAULT_EXECUTION_BLOCK_CONSTRUCTION,
DEFAULT_EXECUTION_IMPORT_BLOCK, DEFAULT_EXECUTION_IMPORT_BLOCK_VALIDATOR,
DEFAULT_EXECUTION_OFFCHAIN_WORKER, DEFAULT_EXECUTION_OTHER, DEFAULT_EXECUTION_SYNCING,
};
Expand Down Expand Up @@ -73,32 +73,9 @@ pub struct ImportParams {
default_value = "67108864"
)]
pub state_cache_size: usize,

/// Comma separated list of targets for tracing.
#[structopt(long = "tracing-targets", value_name = "TARGETS")]
pub tracing_targets: Option<String>,

/// Receiver to process tracing messages.
#[structopt(
long = "tracing-receiver",
value_name = "RECEIVER",
possible_values = &TracingReceiver::variants(),
case_insensitive = true,
default_value = "Log"
)]
pub tracing_receiver: TracingReceiver,
}

impl ImportParams {
/// Receiver to process tracing messages.
pub fn tracing_receiver(&self) -> sc_service::TracingReceiver {
self.tracing_receiver.clone().into()
}

/// Comma separated list of targets for tracing.
pub fn tracing_targets(&self) -> Option<String> {
self.tracing_targets.clone()
}

/// Specify the state cache size.
pub fn state_cache_size(&self) -> usize {
Expand Down
Loading