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

Allow overriding tracing filter with RUST_LOG env var #1896

Merged
merged 6 commits into from
Feb 21, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
- Allow overriding the tracing filter with `RUST_LOG` environment variable
([#1895](https://github.com/informalsystems/ibc-rs/issues/1895))
2 changes: 1 addition & 1 deletion relayer-cli/src/commands/start.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ impl Runnable for StartCmd {
let config = (*app_config()).clone();
let config = Arc::new(RwLock::new(config));

let supervisor_handle = make_supervisor::<ProdChainHandle>(config.clone(), self.full_scan)
let supervisor_handle = make_supervisor::<ProdChainHandle>(config, self.full_scan)
Copy link
Contributor

Choose a reason for hiding this comment

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

Less cloning of massive data structures, good.

Copy link
Contributor

@seanchen1991 seanchen1991 Feb 21, 2022

Choose a reason for hiding this comment

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

Looks like it was just cloning an Arc though, so it should have just consisted of incrementing a reference count.

Copy link
Contributor

@mzabaluev mzabaluev Feb 22, 2022

Choose a reason for hiding this comment

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

It likely does not matter in the startup code, but in general coercing an Arc to a reference is still cheaper than atomically incrementing a ref count.

.unwrap_or_else(|e| {
Output::error(format!("Hermes failed to start, last error: {}", e)).exit()
});
Expand Down
46 changes: 29 additions & 17 deletions relayer-cli/src/components.rs
Original file line number Diff line number Diff line change
@@ -1,10 +1,14 @@
use abscissa_core::{Component, FrameworkError, FrameworkErrorKind};
use tracing_subscriber::{filter::EnvFilter, util::SubscriberInitExt, FmtSubscriber};

use ibc_relayer::config::GlobalConfig;
use ibc_relayer::config::{GlobalConfig, LogLevel};

use crate::config::Error;

/// The name of the environment variable through which one can override
/// the tracing filter built in [`build_tracing_filter`].
const HERMES_LOG_VAR: &str = "RUST_LOG";
Copy link
Member

Choose a reason for hiding this comment

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

I recall the integration tests framework making use of RUST_LOG, eg in cargo test. Would just like to flag that -- is there any interference between this approach and the pre-existing support for RUST_LOG in cargo?

Copy link
Member Author

Choose a reason for hiding this comment

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

The logs from the integration tests look fine to me: https://github.com/informalsystems/ibc-rs/runs/5272869928?check_suite_focus=true (modulo some doc tests failures, unrelated to this PR and best fixed elsewhere)

Copy link
Member Author

Choose a reason for hiding this comment

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

By the way, just to clarify, cargo test does not care itself about RUST_LOG but the integration tests themselves do, cf. https://github.com/informalsystems/ibc-rs/blob/8329d856844df30651f68a25ca5c5db4addbaa2b/tools/integration-test/src/bootstrap/single.rs#L75

Copy link
Member Author

Choose a reason for hiding this comment

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

What the test suite does is look at the RUST_LOG env variable, and then sets the log_level property in config.toml to that. If the test suite is only ever run with RUST_LOG=info/trace/debug/error/warn then everything should work as expected with no change in the output.

Copy link
Member

Choose a reason for hiding this comment

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

By the way, just to clarify, cargo test does not care itself about RUST_LOG but the integration tests themselves do, cf.

Thanks for clarifying that! This part wasn't obvious to me.


/// A custom component for parametrizing `tracing` in the relayer.
/// Primarily used for:
///
Expand All @@ -17,7 +21,7 @@ pub struct JsonTracing;
impl JsonTracing {
/// Creates a new [`JsonTracing`] component
pub fn new(cfg: GlobalConfig) -> Result<Self, FrameworkError> {
let filter = build_tracing_filter(cfg.log_level.to_string())?;
let filter = build_tracing_filter(cfg.log_level)?;
// Note: JSON formatter is un-affected by ANSI 'color' option. Set to 'false'.
let use_color = false;

Expand All @@ -43,7 +47,7 @@ pub struct PrettyTracing;
impl PrettyTracing {
/// Creates a new [`PrettyTracing`] component
pub fn new(cfg: GlobalConfig) -> Result<Self, FrameworkError> {
let filter = build_tracing_filter(cfg.log_level.to_string())?;
let filter = build_tracing_filter(cfg.log_level)?;

// Construct a tracing subscriber with the supplied filter and enable reloading.
let builder = FmtSubscriber::builder()
Expand All @@ -68,30 +72,38 @@ pub fn enable_ansi() -> bool {
atty::is(atty::Stream::Stdout) && atty::is(atty::Stream::Stderr)
}

/// Builds a tracing filter based on the input `log_level`.
/// Enables tracing exclusively for the relayer crates.
/// Returns error if the filter failed to build.
fn build_tracing_filter(log_level: String) -> Result<EnvFilter, FrameworkError> {
let target_crates = ["ibc_relayer", "ibc_relayer_cli"];
/// The relayer crates targeted by the default log level.
const TARGET_CRATES: [&str; 2] = ["ibc_relayer", "ibc_relayer_cli"];

/// Build a tracing directive setting the log level for the relayer crates to the
/// given `log_level`.
fn default_directive(log_level: LogLevel) -> String {
use itertools::Itertools;

// SAFETY: unwrap() below works as long as `target_crates` is not empty.
let directive_raw = target_crates
TARGET_CRATES
.iter()
.map(|&c| format!("{}={}", c, log_level))
.reduce(|a, b| format!("{},{}", a, b))
.unwrap();
.join(",")
}

/// Builds a tracing filter based on the input `log_level`.
/// Enables tracing exclusively for the relayer crates.
/// Returns error if the filter failed to build.
fn build_tracing_filter(default_level: LogLevel) -> Result<EnvFilter, FrameworkError> {
let directive =
std::env::var(HERMES_LOG_VAR).unwrap_or_else(|_| default_directive(default_level));

// Build the filter directive
match EnvFilter::try_new(directive_raw.clone()) {
match EnvFilter::try_new(&directive) {
Ok(out) => Ok(out),
Err(e) => {
eprintln!(
"Unable to initialize Hermes from filter directive {:?}: {}",
directive_raw, e
"ERROR: unable to initialize Hermes with log filtering directive {:?}: {}",
directive, e
);
let our_err = Error::invalid_log_level(log_level, e);

Err(FrameworkErrorKind::ConfigError
.context(format!("{}", our_err))
.context(Error::invalid_log_directive(directive, e))
.into())
}
}
Expand Down
7 changes: 3 additions & 4 deletions relayer-cli/src/config.rs
Original file line number Diff line number Diff line change
Expand Up @@ -28,12 +28,11 @@ define_error! {
ZeroChain
|_| { "config file does not specify any chain" },

InvalidLogLevel
{ log_level: String, }
InvalidLogDirective
{ directive: String, }
[ TraceError<ParseError> ]
|e| {
format!("config file specifies an invalid log level ('{0}'), caused by",
e.log_level)
format!("invalid log directive: {0:?}", e.directive)
},

InvalidMode
Expand Down
2 changes: 1 addition & 1 deletion relayer/src/config.rs
Original file line number Diff line number Diff line change
Expand Up @@ -265,7 +265,7 @@ impl Default for Packets {
/// Log levels are wrappers over [`tracing_core::Level`].
///
/// [`tracing_core::Level`]: https://docs.rs/tracing-core/0.1.17/tracing_core/struct.Level.html
#[derive(Clone, Debug, PartialEq, Deserialize, Serialize)]
#[derive(Copy, Clone, Debug, PartialEq, Deserialize, Serialize)]
#[serde(rename_all = "lowercase")]
pub enum LogLevel {
Trace,
Expand Down