diff --git a/Cargo.lock b/Cargo.lock index 9a4b6f05cf..d5b58b7930 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -807,6 +807,7 @@ dependencies = [ "ckb-jsonrpc-types", "ckb-launcher", "ckb-logger", + "ckb-logger-config", "ckb-logger-service", "ckb-memory-tracker", "ckb-metrics-service", @@ -833,6 +834,7 @@ dependencies = [ "serde_json", "serde_plain", "tempfile", + "time", "tokio", "toml", ] @@ -1248,6 +1250,7 @@ dependencies = [ "ckb-channel", "ckb-logger", "ckb-logger-config", + "ckb-notify", "ckb-util", "env_logger", "log", diff --git a/ckb-bin/Cargo.toml b/ckb-bin/Cargo.toml index 433d28ecb2..770a875de7 100644 --- a/ckb-bin/Cargo.toml +++ b/ckb-bin/Cargo.toml @@ -40,6 +40,7 @@ ckb-async-runtime.workspace = true ckb-migrate.workspace = true ckb-launcher.workspace = true ckb-constant.workspace = true +ckb-logger-config.workspace = true base64.workspace = true tempfile.workspace = true rayon.workspace = true @@ -48,6 +49,7 @@ is-terminal.workspace = true fdlimit.workspace = true ckb-stop-handler.workspace = true tokio = { workspace = true, features = ["sync"] } +time = { workspace = true } [target.'cfg(not(target_os="windows"))'.dependencies] daemonize-me = { version = "2" } diff --git a/ckb-bin/src/lib.rs b/ckb-bin/src/lib.rs index 3078bf7b36..9f8aa028b5 100644 --- a/ckb-bin/src/lib.rs +++ b/ckb-bin/src/lib.rs @@ -12,12 +12,13 @@ mod tests; use ckb_app_config::ExitCode; use ckb_async_runtime::new_global_runtime; use ckb_build_info::Version; -use ckb_logger::{debug, info}; +use ckb_logger::debug; use ckb_network::tokio; use clap::ArgMatches; use helper::raise_fd_limit; use setup::Setup; use setup_guard::SetupGuard; +use time::OffsetDateTime; #[cfg(not(target_os = "windows"))] use colored::Colorize; @@ -28,6 +29,26 @@ use subcommand::check_process; #[cfg(feature = "with_sentry")] pub(crate) const LOG_TARGET_SENTRY: &str = "sentry"; +/// Print a log-like message to stderr. +/// Format: `YYYY-MM-DD HH:MM:SS.mmm +00:00 thread_name INFO module message` +fn log_println(message: &str) { + let now = OffsetDateTime::now_utc(); + let thread = std::thread::current(); + let thread_name = thread.name().unwrap_or("main"); + eprintln!( + "{:04}-{:02}-{:02} {:02}:{:02}:{:02}.{:03} +00:00 {} INFO ckb_bin {}", + now.year(), + now.month() as u8, + now.day(), + now.hour(), + now.minute(), + now.second(), + now.millisecond(), + thread_name, + message + ); +} + /// The executable main entry. /// /// It returns `Ok` when the process exist normally, otherwise the `ExitCode` is converted to the @@ -109,11 +130,11 @@ fn run_app_in_daemon( match daemon.start() { Ok(_) => { - info!("Success, daemonized ..."); + ckb_logger::info!("Success, daemonized ..."); run_app_inner(version, bin_name, cmd, matches) } Err(e) => { - info!("daemonize error: {}", e); + ckb_logger::info!("daemonize error: {}", e); Err(ExitCode::Failure) } } @@ -128,12 +149,21 @@ fn run_app_inner( let is_silent_logging = is_silent_logging(cmd); let (mut handle, mut handle_stop_rx, _runtime) = new_global_runtime(None); let setup = Setup::from_matches(bin_name, cmd, matches)?; - let _guard = SetupGuard::from_setup(&setup, &version, handle.clone(), is_silent_logging)?; + // Disable logging here if the user is executing `ckb run`. + // Logs subscription of RPC service requires access to `struct Shared`, + // so logger of `ckb run` will be initialized in `subcommand::run`. + let (_guard, log_config) = SetupGuard::from_setup( + &setup, + &version, + handle.clone(), + is_silent_logging, + cmd != cli::CMD_RUN, + )?; raise_fd_limit(); let ret = match cmd { - cli::CMD_RUN => subcommand::run(setup.run(matches)?, version, handle.clone()), + cli::CMD_RUN => subcommand::run(setup.run(matches)?, version, handle.clone(), log_config), cli::CMD_MINER => subcommand::miner(setup.miner(matches)?, handle.clone()), cli::CMD_REPLAY => subcommand::replay(setup.replay(matches)?, handle.clone()), cli::CMD_EXPORT => subcommand::export(setup.export(matches)?, handle.clone()), @@ -150,9 +180,18 @@ fn run_app_inner( handle.drop_guard(); tokio::task::block_in_place(|| { - info!("Waiting for all tokio tasks to exit..."); + // Here we use `log_println` instead of `info!` because the Logger has already been + // shut down when `subcommand::run()` returned (LoggerGuard was dropped there). + // + // We cannot simply extend the LoggerGuard's lifetime to here because it would cause + // a deadlock: NotifyController (held by Logger's background thread) contains a clone + // of Handle, which holds a clone of `guard` (Sender). If LoggerGuard is not dropped + // before `handle_stop_rx.blocking_recv()`, the Logger thread won't terminate, and + // the Sender inside NotifyController won't be dropped, causing blocking_recv() to + // wait forever. + log_println("Waiting for all tokio tasks to exit..."); handle_stop_rx.blocking_recv(); - info!("All tokio tasks and threads have exited. CKB shutdown"); + log_println("All tokio tasks and threads have exited. CKB shutdown"); }); } diff --git a/ckb-bin/src/setup_guard.rs b/ckb-bin/src/setup_guard.rs index c02d050e23..78c4e62929 100644 --- a/ckb-bin/src/setup_guard.rs +++ b/ckb-bin/src/setup_guard.rs @@ -6,10 +6,10 @@ use ckb_metrics_service::{self, Guard as MetricsInitGuard}; use crate::setup::Setup; -const CKB_LOG_ENV: &str = "CKB_LOG"; +pub const CKB_LOG_ENV: &str = "CKB_LOG"; pub struct SetupGuard { - _logger_guard: LoggerInitGuard, + _logger_guard: Option, #[cfg(feature = "with_sentry")] _sentry_guard: Option, _metrics_guard: MetricsInitGuard, @@ -22,18 +22,23 @@ impl SetupGuard { version: &Version, async_handle: Handle, silent_logging: bool, - ) -> Result { + enable_logging: bool, + ) -> Result<(Self, ckb_logger_config::Config), ExitCode> { // Initialization of logger must do before sentry, since `logger::init()` and // `sentry_config::init()` both registers custom panic hooks, but `logger::init()` // replaces all hooks previously registered. - let logger_guard = if silent_logging { - ckb_logger_service::init_silent()? + let logger_guard = if enable_logging { + Some(if silent_logging { + ckb_logger_service::init_silent()? + } else { + let mut logger_config = setup.config.logger().to_owned(); + if logger_config.emit_sentry_breadcrumbs.is_none() { + logger_config.emit_sentry_breadcrumbs = Some(setup.is_sentry_enabled); + } + ckb_logger_service::init(Some(CKB_LOG_ENV), logger_config, None)? + }) } else { - let mut logger_config = setup.config.logger().to_owned(); - if logger_config.emit_sentry_breadcrumbs.is_none() { - logger_config.emit_sentry_breadcrumbs = Some(setup.is_sentry_enabled); - } - ckb_logger_service::init(Some(CKB_LOG_ENV), logger_config)? + None }; let sentry_guard = if setup.is_sentry_enabled { @@ -67,11 +72,14 @@ impl SetupGuard { ExitCode::Config })?; - Ok(Self { - _logger_guard: logger_guard, - _sentry_guard: sentry_guard, - _metrics_guard: metrics_guard, - }) + Ok(( + Self { + _logger_guard: logger_guard, + _sentry_guard: sentry_guard, + _metrics_guard: metrics_guard, + }, + setup.config.logger().to_owned(), + )) } #[cfg(not(feature = "with_sentry"))] @@ -80,12 +88,18 @@ impl SetupGuard { _version: &Version, async_handle: Handle, silent_logging: bool, - ) -> Result { - let logger_guard = if silent_logging { - ckb_logger_service::init_silent()? + // For ckb run, logging can be disabled here, since it requires `Shared` to create a logger that will be used for `ckb run` + enable_logging: bool, + ) -> Result<(Self, ckb_logger_config::Config), ExitCode> { + let logger_guard = if enable_logging { + Some(if silent_logging { + ckb_logger_service::init_silent()? + } else { + let logger_config = setup.config.logger().to_owned(); + ckb_logger_service::init(Some(CKB_LOG_ENV), logger_config, None)? + }) } else { - let logger_config = setup.config.logger().to_owned(); - ckb_logger_service::init(Some(CKB_LOG_ENV), logger_config)? + None }; let metrics_config = setup.config.metrics().to_owned(); @@ -95,9 +109,12 @@ impl SetupGuard { ExitCode::Config })?; - Ok(Self { - _logger_guard: logger_guard, - _metrics_guard: metrics_guard, - }) + Ok(( + Self { + _logger_guard: logger_guard, + _metrics_guard: metrics_guard, + }, + setup.config.logger().to_owned(), + )) } } diff --git a/ckb-bin/src/subcommand/run.rs b/ckb-bin/src/subcommand/run.rs index 9c253aaa15..163ba10802 100644 --- a/ckb-bin/src/subcommand/run.rs +++ b/ckb-bin/src/subcommand/run.rs @@ -1,6 +1,7 @@ use std::thread::available_parallelism; use crate::helper::deadlock_detection; +use crate::setup_guard::CKB_LOG_ENV; use ckb_app_config::{ExitCode, RunArgs}; use ckb_async_runtime::{Handle, new_global_runtime}; use ckb_build_info::Version; @@ -13,15 +14,18 @@ use ckb_stop_handler::{broadcast_exit_signals, wait_all_ckb_services_exit}; use ckb_types::core::cell::setup_system_cell_cache; -pub fn run(args: RunArgs, version: Version, async_handle: Handle) -> Result<(), ExitCode> { +pub fn run( + args: RunArgs, + version: Version, + async_handle: Handle, + log_config: ckb_logger_config::Config, +) -> Result<(), ExitCode> { check_default_db_options_exists(&args)?; deadlock_detection(); let rpc_threads_num = calc_rpc_threads_num(&args); - info!("ckb version: {}", version); - info!("run rpc server with {} threads", rpc_threads_num); let (mut rpc_handle, _rpc_stop_rx, _runtime) = new_global_runtime(Some(rpc_threads_num)); - let launcher = Launcher::new(args, version, async_handle, rpc_handle.clone()); + let launcher = Launcher::new(args, version.clone(), async_handle, rpc_handle.clone()); let block_assembler_config = launcher.sanitize_block_assembler_config()?; let miner_enable = block_assembler_config.is_some(); @@ -29,6 +33,14 @@ pub fn run(args: RunArgs, version: Version, async_handle: Handle) -> Result<(), launcher.check_indexer_config()?; let (shared, mut pack) = launcher.build_shared(block_assembler_config)?; + let _logger_guard = ckb_logger_service::init( + Some(CKB_LOG_ENV), + log_config, + Some(shared.notify_controller().clone()), + )?; + + info!("ckb version: {}", version); + info!("run rpc server with {} threads", rpc_threads_num); // spawn freezer background process let _freezer = shared.spawn_freeze(); diff --git a/notify/src/lib.rs b/notify/src/lib.rs index 596e5f691d..2b7b9447d0 100644 --- a/notify/src/lib.rs +++ b/notify/src/lib.rs @@ -5,7 +5,7 @@ //! notifications about these events asynchronously. use ckb_app_config::NotifyConfig; use ckb_async_runtime::Handle; -use ckb_logger::{debug, error, info, trace}; +use ckb_logger::{Level, debug, error, info, trace}; use ckb_stop_handler::{CancellationToken, new_tokio_exit_rx}; use ckb_types::packed::Byte32; use ckb_types::{ @@ -23,6 +23,19 @@ use tokio::time::timeout; pub use ckb_types::core::tx_pool::PoolTransactionEntry; +/// A log entry containing the message and log level. +#[derive(Clone, Debug)] +pub struct LogEntry { + /// The log message. + pub message: String, + /// The log level. + pub level: Level, + /// The log target + pub target: String, + /// The date + pub date: String, +} + /// Asynchronous request sent to the service. pub struct Request { /// Oneshot channel for the service to send back the response. @@ -106,6 +119,8 @@ pub struct NotifyController { reject_transaction_notifier: Sender<(PoolTransactionEntry, Reject)>, network_alert_register: NotifyRegister, network_alert_notifier: Sender, + log_register: NotifyRegister, + log_notifier: Sender, handle: Handle, } @@ -120,6 +135,7 @@ pub struct NotifyService { proposed_transaction_subscribers: HashMap>, reject_transaction_subscribers: HashMap>, network_alert_subscribers: HashMap>, + log_subscribers: HashMap>, timeout: NotifyTimeout, handle: Handle, } @@ -137,6 +153,7 @@ impl NotifyService { proposed_transaction_subscribers: HashMap::default(), reject_transaction_subscribers: HashMap::default(), network_alert_subscribers: HashMap::default(), + log_subscribers: HashMap::default(), timeout, handle, } @@ -144,7 +161,7 @@ impl NotifyService { /// start background tokio spawned task. pub fn start(mut self) -> NotifyController { - let signal_receiver: CancellationToken = new_tokio_exit_rx(); + let stop_token: CancellationToken = new_tokio_exit_rx(); let handle = self.handle.clone(); let (new_block_register, mut new_block_register_receiver) = @@ -172,6 +189,10 @@ impl NotifyService { mpsc::channel(REGISTER_CHANNEL_SIZE); let (network_alert_sender, mut network_alert_receiver) = mpsc::channel(NOTIFY_CHANNEL_SIZE); + let (log_register, mut log_register_receiver) = mpsc::channel(REGISTER_CHANNEL_SIZE); + let (log_sender, mut log_receiver) = mpsc::channel(NOTIFY_CHANNEL_SIZE); + + let stop_token_clone = stop_token; handle.spawn(async move { loop { tokio::select! { @@ -186,7 +207,9 @@ impl NotifyService { Some(msg) = reject_transaction_receiver.recv() => { self.handle_notify_reject_transaction(msg) }, Some(msg) = network_alert_register_receiver.recv() => { self.handle_register_network_alert(msg) }, Some(msg) = network_alert_receiver.recv() => { self.handle_notify_network_alert(msg) }, - _ = signal_receiver.cancelled() => { + Some(msg) = log_register_receiver.recv() => { self.handle_register_log(msg) }, + Some(msg) = log_receiver.recv() => { self.handle_notify_log(msg) }, + _ = stop_token_clone.cancelled() => { info!("NotifyService received exit signal, exit now"); break; } @@ -207,6 +230,8 @@ impl NotifyService { reject_transaction_notifier: reject_transaction_sender, network_alert_register, network_alert_notifier: network_alert_sender, + log_register, + log_notifier: log_sender, handle, } } @@ -415,6 +440,26 @@ impl NotifyService { }); } } + + fn handle_register_log(&mut self, msg: Request>) { + let Request { + responder, + arguments: name, + } = msg; + debug!("Register log {:?}", name); + let (sender, receiver) = mpsc::channel(NOTIFY_CHANNEL_SIZE); + self.log_subscribers.insert(name, sender); + let _ = responder.send(receiver); + } + + fn handle_notify_log(&self, log_entry: LogEntry) { + for subscriber in self.log_subscribers.values() { + let log_entry = log_entry.clone(); + let subscriber = subscriber.clone(); + // Ignore failures + subscriber.try_send(log_entry).ok(); + } + } } impl NotifyController { @@ -528,4 +573,20 @@ impl NotifyController { } }); } + + /// Subscribes to log notifications with the given name. + /// + /// Returns a receiver channel that will receive log events. + pub async fn subscribe_log(&self, name: S) -> Receiver { + Request::call(&self.log_register, name.to_string()) + .await + .expect("Subscribe log should be OK") + } + + /// Notifies all subscribers of a log entry. + pub fn notify_log(&self, log_entry: LogEntry) { + let log_notifier = self.log_notifier.clone(); + // Ignore failures + log_notifier.try_send(log_entry).ok(); + } } diff --git a/rpc/README.md b/rpc/README.md index 1ba9fdedc6..0db0012b75 100644 --- a/rpc/README.md +++ b/rpc/README.md @@ -5267,7 +5267,7 @@ Subscribes to a topic. ###### Params -* `topic` - Subscription topic (enum: new_tip_header | new_tip_block | new_transaction | proposed_transaction | rejected_transaction) +* `topic` - Subscription topic (enum: new_tip_header | new_tip_block | new_transaction | proposed_transaction | rejected_transaction | logs) ###### Returns @@ -5327,6 +5327,12 @@ The type of the `params.result` in the push message is a two-elements array, whe - the first item type is [`PoolTransactionEntry`](../../ckb_jsonrpc_types/struct.PoolTransactionEntry.html), and - the second item type is [`PoolTransactionReject`](../../ckb_jsonrpc_types/struct.PoolTransactionReject.html). +###### `log` + +Subscribers will get notified when a new log message is generated. + +The type of the `params.result` in the push message is [`LogEntry`](../../ckb_jsonrpc_types/struct.LogEntry.html). + ###### Examples Subscribe Request diff --git a/rpc/src/module/subscription.rs b/rpc/src/module/subscription.rs index 13d69d6f34..3757ad4b99 100644 --- a/rpc/src/module/subscription.rs +++ b/rpc/src/module/subscription.rs @@ -3,8 +3,8 @@ use broadcast::error::RecvError; use ckb_async_runtime::Handle; use ckb_jsonrpc_types::Topic; use ckb_logger::error; -use ckb_notify::NOTIFY_CHANNEL_SIZE; use ckb_notify::NotifyController; +use ckb_notify::{LogEntry, NOTIFY_CHANNEL_SIZE}; use ckb_stop_handler::new_tokio_exit_rx; use futures_util::{Stream, stream::BoxStream}; use jsonrpc_core::Result; @@ -60,7 +60,7 @@ pub trait SubscriptionRpc { /// /// ###### Params /// - /// * `topic` - Subscription topic (enum: new_tip_header | new_tip_block | new_transaction | proposed_transaction | rejected_transaction) + /// * `topic` - Subscription topic (enum: new_tip_header | new_tip_block | new_transaction | proposed_transaction | rejected_transaction | logs) /// /// ###### Returns /// @@ -120,6 +120,12 @@ pub trait SubscriptionRpc { /// - the first item type is [`PoolTransactionEntry`](../../ckb_jsonrpc_types/struct.PoolTransactionEntry.html), and /// - the second item type is [`PoolTransactionReject`](../../ckb_jsonrpc_types/struct.PoolTransactionReject.html). /// + /// ###### `log` + /// + /// Subscribers will get notified when a new log message is generated. + /// + /// The type of the `params.result` in the push message is [`LogEntry`](../../ckb_jsonrpc_types/struct.LogEntry.html). + /// /// ###### Examples /// /// Subscribe Request @@ -191,6 +197,7 @@ pub struct SubscriptionRpcImpl { pub new_transaction_sender: broadcast::Sender>, pub proposed_transaction_sender: broadcast::Sender>, pub new_reject_transaction_sender: broadcast::Sender>, + pub log_sender: broadcast::Sender>, } macro_rules! publiser_send { @@ -211,6 +218,7 @@ impl SubscriptionRpc for SubscriptionRpcImpl { Topic::NewTransaction => self.new_transaction_sender.clone(), Topic::ProposedTransaction => self.proposed_transaction_sender.clone(), Topic::RejectedTransaction => self.new_reject_transaction_sender.clone(), + Topic::Log => self.log_sender.clone(), }; let mut rx = tx.subscribe(); Ok(Box::pin(async_stream::stream! { @@ -231,6 +239,23 @@ impl SubscriptionRpc for SubscriptionRpcImpl { } } +fn convert_log_entry(entry: LogEntry) -> ckb_jsonrpc_types::LogEntry { + use ckb_logger::Level; + let level = match entry.level { + Level::Error => ckb_jsonrpc_types::LogLevel::Error, + Level::Warn => ckb_jsonrpc_types::LogLevel::Warn, + Level::Info => ckb_jsonrpc_types::LogLevel::Info, + Level::Debug => ckb_jsonrpc_types::LogLevel::Debug, + Level::Trace => ckb_jsonrpc_types::LogLevel::Trace, + }; + ckb_jsonrpc_types::LogEntry { + message: entry.message, + level, + date: entry.date, + target: entry.target, + } +} + impl SubscriptionRpcImpl { pub fn new(notify_controller: NotifyController, handle: Handle) -> Self { const SUBSCRIBER_NAME: &str = "TcpSubscription"; @@ -244,12 +269,15 @@ impl SubscriptionRpcImpl { ); let mut reject_transaction_receiver = handle .block_on(notify_controller.subscribe_reject_transaction(SUBSCRIBER_NAME.to_string())); + let mut log_receiver = + handle.block_on(notify_controller.subscribe_log(SUBSCRIBER_NAME.to_string())); let (new_tip_header_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); let (new_tip_block_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); let (proposed_transaction_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); let (new_transaction_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); let (new_reject_transaction_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); + let (log_sender, _) = broadcast::channel(NOTIFY_CHANNEL_SIZE); let stop_rx = new_tokio_exit_rx(); handle.spawn({ @@ -258,6 +286,7 @@ impl SubscriptionRpcImpl { let new_transaction_sender = new_transaction_sender.clone(); let proposed_transaction_sender = proposed_transaction_sender.clone(); let new_reject_transaction_sender = new_reject_transaction_sender.clone(); + let log_sender = log_sender.clone(); async move { loop { tokio::select! { @@ -275,7 +304,10 @@ impl SubscriptionRpcImpl { publiser_send!((ckb_jsonrpc_types::PoolTransactionEntry, ckb_jsonrpc_types::PoolTransactionReject), (tx_entry.into(), reject.into()), new_reject_transaction_sender); - } + }, + Some(log_entry) = log_receiver.recv() => { + publiser_send!(ckb_jsonrpc_types::LogEntry, convert_log_entry(log_entry), log_sender); + }, _ = stop_rx.cancelled() => { break; }, @@ -294,6 +326,7 @@ impl SubscriptionRpcImpl { new_transaction_sender, proposed_transaction_sender, new_reject_transaction_sender, + log_sender, } } } diff --git a/test/src/lib.rs b/test/src/lib.rs index 01edc08cb1..10809267a1 100644 --- a/test/src/lib.rs +++ b/test/src/lib.rs @@ -127,7 +127,7 @@ pub fn main_test() { } else { logger_config.log_to_file = false; } - ckb_logger_service::init(None, logger_config) + ckb_logger_service::init(None, logger_config, None) .unwrap_or_else(|err| panic!("failed to init the logger service since {err}")) }; diff --git a/util/jsonrpc-types/src/lib.rs b/util/jsonrpc-types/src/lib.rs index 0d7b654042..aa7c749ad5 100644 --- a/util/jsonrpc-types/src/lib.rs +++ b/util/jsonrpc-types/src/lib.rs @@ -52,7 +52,7 @@ pub use self::pool::{ TxPoolInfo, }; pub use self::proposal_short_id::ProposalShortId; -pub use self::subscription::Topic; +pub use self::subscription::{LogEntry, LogLevel, Topic}; pub use self::uints::{Uint32, Uint64, Uint128}; pub use ckb_types::core::RationalU256; pub use indexer::{ diff --git a/util/jsonrpc-types/src/subscription.rs b/util/jsonrpc-types/src/subscription.rs index 9c5c914e33..f840c2c810 100644 --- a/util/jsonrpc-types/src/subscription.rs +++ b/util/jsonrpc-types/src/subscription.rs @@ -14,4 +14,35 @@ pub enum Topic { ProposedTransaction, /// Subscribe transactions which are abandoned by tx-pool. RejectedTransaction, + /// Subscribe to logs. + Log, +} + +/// Log entry received from the subscription. +#[derive(Debug, Clone, Serialize, Deserialize, PartialEq, Eq, Hash)] +pub struct LogEntry { + /// The log message. + pub message: String, + /// The log level. + pub level: LogLevel, + /// The log target + pub target: String, + /// The date + pub date: String, +} + +/// Log level for log subscription. +#[derive(Debug, Clone, Copy, Serialize, Deserialize, PartialEq, Eq, Hash)] +#[serde(rename_all = "snake_case")] +pub enum LogLevel { + /// Error level. + Error, + /// Warn level. + Warn, + /// Info level. + Info, + /// Debug level. + Debug, + /// Trace level. + Trace, } diff --git a/util/logger-service/Cargo.toml b/util/logger-service/Cargo.toml index c7d1df466e..864bb2de2a 100644 --- a/util/logger-service/Cargo.toml +++ b/util/logger-service/Cargo.toml @@ -20,7 +20,7 @@ regex.workspace = true backtrace.workspace = true sentry = { workspace = true, features = ["log"], optional = true } time = { workspace = true, features = ["formatting"] } - +ckb-notify.workspace = true [dev-dependencies] ckb-logger.workspace = true tempfile.workspace = true diff --git a/util/logger-service/src/lib.rs b/util/logger-service/src/lib.rs index 09b1439e03..665346d5dc 100644 --- a/util/logger-service/src/lib.rs +++ b/util/logger-service/src/lib.rs @@ -2,6 +2,7 @@ use backtrace::Backtrace; use ckb_channel::{self, unbounded}; +use ckb_notify::{LogEntry, NotifyController}; use env_logger::filter::{Builder, Filter}; use log::{LevelFilter, Log, Metadata, Record, SetLoggerError}; use regex::Regex; @@ -31,6 +32,10 @@ enum Message { is_match: bool, extras: Vec, data: String, + level: log::Level, + target: String, + date: String, + original_message: String, }, UpdateMainLogger { filter: Option, @@ -101,7 +106,7 @@ pub(crate) fn convert_compatible_crate_name(spec: &str) -> String { } impl Logger { - fn new(env_opt: Option<&str>, config: Config) -> Logger { + fn new(env_opt: Option<&str>, config: Config, notifier: Option) -> Logger { for name in config.extra.keys() { if let Err(err) = Self::check_extra_logger_name(name) { eprintln!("Error: {err}"); @@ -197,6 +202,10 @@ impl Logger { is_match, extras, data, + level, + target, + date, + original_message, }) => { let removed_color = if (is_match && (!main_logger.color || main_logger.to_file)) @@ -207,6 +216,14 @@ impl Logger { "".to_owned() }; if is_match { + if let Some(notifier) = ¬ifier { + notifier.notify_log(LogEntry { + level, + message: original_message, + date, + target, + }); + } if main_logger.to_stdout { let output = if main_logger.color { data.as_str() @@ -423,7 +440,7 @@ impl Log for Logger { if let Ok(dt) = utc.format(&fmt) { let with_color = { let thread_name = format!("{}", Paint::blue(thread_name).bold()); - let date = format!("{}", Paint::rgb(47, 79, 79, dt).bold()); // darkslategrey + let date = format!("{}", Paint::rgb(47, 79, 79, &dt).bold()); // darkslategrey format!( "{} {} {} {} {}", date, @@ -437,6 +454,10 @@ impl Log for Logger { is_match, extras, data: with_color, + level: record.level(), + target: record.target().to_string(), + date: dt, + original_message: format!("{}", record.args()), }); } } @@ -478,14 +499,18 @@ fn modify_logger_filter(filter: String) -> String { } /// Initializes the [Logger](struct.Logger.html) and run the logging service. -pub fn init(env_opt: Option<&str>, config: Config) -> Result { +pub fn init( + env_opt: Option<&str>, + config: Config, + notifier: Option, +) -> Result { setup_panic_logger(); let mut config = config; if let Some(filter) = config.filter { config.filter = Some(modify_logger_filter(filter)); }; - let logger = Logger::new(env_opt, config); + let logger = Logger::new(env_opt, config, notifier); let filter = logger.filter(); log::set_boxed_logger(Box::new(logger)).map(|_| { log::set_max_level(filter); @@ -562,7 +587,7 @@ pub fn init_for_test(filter: &str) -> Result { extra: Default::default(), }; - let logger = Logger::new(None, config); + let logger = Logger::new(None, config, None); let filter = logger.filter(); log::set_boxed_logger(Box::new(logger)).map(|_| { log::set_max_level(filter); diff --git a/util/logger-service/tests/utils/mod.rs b/util/logger-service/tests/utils/mod.rs index d34b1b0a6a..c8e621b5b0 100644 --- a/util/logger-service/tests/utils/mod.rs +++ b/util/logger-service/tests/utils/mod.rs @@ -56,7 +56,7 @@ pub fn do_tests(config: Config, func: F) where F: Fn(), { - let guard = ckb_logger_service::init(None, config).unwrap(); + let guard = ckb_logger_service::init(None, config, None).unwrap(); func(); drop(guard); } @@ -68,7 +68,7 @@ where unsafe { std::env::set_var(DEFAULT_LOG_ENV, env_filter); } - let guard = ckb_logger_service::init(Some(DEFAULT_LOG_ENV), config).unwrap(); + let guard = ckb_logger_service::init(Some(DEFAULT_LOG_ENV), config, None).unwrap(); func(); drop(guard); }