From e13c80e169f7e5308ad623353e87a41cfbde7b63 Mon Sep 17 00:00:00 2001 From: sisungo Date: Sat, 13 Jul 2024 08:51:39 +0800 Subject: [PATCH] Use custom logging facility instead of `tracing` For `init`'s purpose of displaying boot status on the screen, general-purposed loggers like `tracing` are not enough, so we should use our own logging facility instead. --- airupd/Cargo.toml | 2 - airupd/src/ace/builtins.rs | 18 +++-- airupd/src/log.rs | 138 ++++++++++++++++++++++++++++++++ airupd/src/logging.rs | 85 -------------------- airupd/src/main.rs | 5 +- airupd/src/milestones/mod.rs | 39 ++++----- airupd/src/milestones/reboot.rs | 5 +- airupd/src/rpc/mod.rs | 24 +----- airupfx/airupfx/Cargo.toml | 1 - airupfx/airupfx/src/util.rs | 6 +- 10 files changed, 179 insertions(+), 144 deletions(-) create mode 100644 airupd/src/log.rs delete mode 100644 airupd/src/logging.rs diff --git a/airupd/Cargo.toml b/airupd/Cargo.toml index 580c087..bd7418d 100644 --- a/airupd/Cargo.toml +++ b/airupd/Cargo.toml @@ -23,5 +23,3 @@ libc = "0.2" once_cell = "1" thiserror = "1" tokio = { workspace = true } -tracing = "0.1" -tracing-subscriber = "0.3" diff --git a/airupd/src/ace/builtins.rs b/airupd/src/ace/builtins.rs index c14c165..e25cf6b 100644 --- a/airupd/src/ace/builtins.rs +++ b/airupd/src/ace/builtins.rs @@ -30,18 +30,24 @@ pub fn console_setup(args: Vec) -> JoinHandle { } pub fn console_info(args: Vec) -> JoinHandle { - tracing::info!(target: "console", "{}", merge_args(&args)); - tokio::spawn(async { 0 }) + tokio::spawn(async move { + crate::inform!("{}", merge_args(&args)); + 0 + }) } pub fn console_warn(args: Vec) -> JoinHandle { - tracing::warn!(target: "console", "{}", merge_args(&args)); - tokio::spawn(async { 0 }) + tokio::spawn(async move { + crate::warn!("{}", merge_args(&args)); + 0 + }) } pub fn console_error(args: Vec) -> JoinHandle { - tracing::error!(target: "console", "{}", merge_args(&args)); - tokio::spawn(async { 0 }) + tokio::spawn(async move { + crate::report_error!("{}", merge_args(&args)); + 0 + }) } pub fn noop(_: Vec) -> JoinHandle { diff --git a/airupd/src/log.rs b/airupd/src/log.rs new file mode 100644 index 0000000..1ee38ad --- /dev/null +++ b/airupd/src/log.rs @@ -0,0 +1,138 @@ +//! Airupd logging facility. + +use std::sync::OnceLock; +use tokio::{sync::mpsc, task::AbortHandle}; + +static LOGGER: OnceLock = OnceLock::new(); + +#[macro_export] +macro_rules! inform { + ($($arg:tt)*) => { + $crate::log::logger().inform(format!($($arg)*)).await + }; +} + +#[macro_export] +macro_rules! warn { + ($($arg:tt)*) => { + $crate::log::logger().warn(format!($($arg)*)).await + }; +} + +#[macro_export] +macro_rules! report_error { + ($($arg:tt)*) => { + $crate::log::logger().report_error(format!($($arg)*)).await + }; +} + +/// Builder of `airupd`-flavor tracing configuration. +#[derive(Debug, Clone)] +pub struct Builder { + quiet: bool, + verbose: bool, + color: bool, +} +impl Builder { + /// Creates a new [`Builder`] instance with default settings. + #[inline] + #[must_use] + pub fn new() -> Self { + Self::default() + } + + /// Sets whether console output is disabled for the logger. + #[inline] + pub fn quiet(&mut self, val: bool) -> &mut Self { + self.quiet = val; + self + } + + /// Sets whether console output is verbose for the logger. + #[inline] + pub fn verbose(&mut self, val: bool) -> &mut Self { + self.verbose = val; + self + } + + /// Sets whether colorful console output is enabled for the logger. + #[inline] + pub fn color(&mut self, val: bool) -> &mut Self { + self.color = val; + self + } + + /// Initializes the logger. + #[inline] + pub fn init(&mut self) { + let (tx, rx) = mpsc::channel(16); + let logger_impl = LoggerImpl { rx }; + let background = tokio::spawn(logger_impl.run()).abort_handle(); + LOGGER.set(Logger { tx, background }).unwrap(); + } +} +impl Default for Builder { + fn default() -> Self { + Self { + quiet: false, + verbose: false, + color: true, + } + } +} + +#[derive(Debug)] +pub struct Logger { + tx: mpsc::Sender, + background: AbortHandle, +} +impl Logger { + pub async fn inform(&self, s: String) { + _ = self.tx.send(Request::Inform(s)).await; + } + + pub async fn warn(&self, s: String) { + _ = self.tx.send(Request::Warn(s)).await; + } + + pub async fn report_error(&self, s: String) { + _ = self.tx.send(Request::ReportError(s)).await; + } +} +impl Drop for Logger { + fn drop(&mut self) { + self.background.abort(); + } +} + +pub fn logger() -> &'static Logger { + LOGGER.get().unwrap() +} + +struct LoggerImpl { + rx: mpsc::Receiver, +} +impl LoggerImpl { + async fn run(mut self) { + while let Some(req) = self.rx.recv().await { + match req { + Request::Inform(s) => { + eprintln!("\x1b[32m * \x1b[0m {s}"); + } + Request::Warn(s) => { + eprintln!("\x1b[33m * \x1b[0m {s}"); + } + Request::ReportError(s) => { + eprintln!("\x1b[31m * \x1b[0m {s}"); + } + } + } + } +} + +#[derive(Debug, Clone)] +enum Request { + Inform(String), + Warn(String), + ReportError(String), +} diff --git a/airupd/src/logging.rs b/airupd/src/logging.rs deleted file mode 100644 index 793cbf1..0000000 --- a/airupd/src/logging.rs +++ /dev/null @@ -1,85 +0,0 @@ -//! Airupd-flavored presets for the [`tracing`] framework. - -use tracing::metadata::LevelFilter; -use tracing_subscriber::{filter::filter_fn, prelude::*}; - -/// Builder of `airupd`-flavor tracing configuration. -#[derive(Debug, Clone)] -pub struct Builder { - name: String, - quiet: bool, - verbose: bool, - color: bool, -} -impl Builder { - /// Creates a new [`Builder`] instance with default settings. - #[inline] - #[must_use] - pub fn new() -> Self { - Self::default() - } - - /// Sets the logger's name. - #[inline] - pub fn name>(&mut self, s: S) -> &mut Self { - self.name = s.into(); - self - } - - /// Sets whether console output is disabled for the logger. - #[inline] - pub fn quiet(&mut self, val: bool) -> &mut Self { - self.quiet = val; - self - } - - /// Sets whether console output is verbose for the logger. - #[inline] - pub fn verbose(&mut self, val: bool) -> &mut Self { - self.verbose = val; - self - } - - /// Sets whether colorful console output is enabled for the logger. - #[inline] - pub fn color(&mut self, val: bool) -> &mut Self { - self.color = val; - self - } - - /// Initializes the logger. - #[inline] - pub fn init(&mut self) { - let verbose = self.verbose; - let level_filter = match self.quiet { - true => LevelFilter::ERROR, - false => match verbose { - true => LevelFilter::TRACE, - false => LevelFilter::INFO, - }, - }; - - let stdio_layer = tracing_subscriber::fmt::layer() - .without_time() - .with_ansi(self.color) - .with_file(false) - .with_writer(std::io::stderr) - .with_target(false) - .with_filter(filter_fn(move |metadata| { - verbose || metadata.target().contains("console") - })) - .with_filter(level_filter); - - tracing_subscriber::registry().with(stdio_layer).init(); - } -} -impl Default for Builder { - fn default() -> Self { - Self { - name: "airupd".into(), - quiet: false, - verbose: false, - color: true, - } - } -} diff --git a/airupd/src/main.rs b/airupd/src/main.rs index 5f55fb8..0518757 100644 --- a/airupd/src/main.rs +++ b/airupd/src/main.rs @@ -6,7 +6,7 @@ mod env; mod events; mod extension; mod lifetime; -mod logging; +mod log; mod milestones; mod rpc; mod storage; @@ -20,8 +20,7 @@ async fn main() { airupfx::init().await; let cmdline = self::env::Cmdline::parse(); - logging::Builder::new() - .name("airupd") + log::Builder::new() .quiet(cmdline.quiet) .color(!cmdline.no_color) .verbose(cmdline.verbose) diff --git a/airupd/src/milestones/mod.rs b/airupd/src/milestones/mod.rs index 7e5a741..f64bb92 100644 --- a/airupd/src/milestones/mod.rs +++ b/airupd/src/milestones/mod.rs @@ -83,7 +83,7 @@ async fn enter_milestone(name: String, hist: &mut HashSet) -> Result<(), let def = match app::airupd().storage.milestones.get(&name).await { Ok(x) => x, Err(err) => { - tracing::error!(target: "console", "Failed to enter milestone `{}`: {}", name, err); + crate::report_error!("Failed to enter milestone `{}`: {}", name, err); return Err(err.into()); } }; @@ -91,15 +91,14 @@ async fn enter_milestone(name: String, hist: &mut HashSet) -> Result<(), // Detects if dependency ring exists. If a dependency ring is detected, it's automatically broken, then a warning // event is recorded, and the method immediately returns. if !hist.insert(name.clone()) { - tracing::warn!( - target: "console", + crate::warn!( "Dependency loop detected for milestone `{}`. Breaking loop.", def.display_name() ); return Ok(()); } - tracing::info!(target: "console", "Entering milestone {}", def.display_name()); + crate::inform!("Entering milestone {}", def.display_name()); let begin_timestamp = airupfx::time::timestamp_ms(); // Enters dependency milestones @@ -140,20 +139,20 @@ async fn exec_milestone_async(def: &Milestone) { match item { Item::Cache(service) => { if let Err(err) = app::airupd().cache_service(&service).await { - tracing::error!(target: "console", "Failed to load service {}: {}", service, err); + crate::report_error!("Failed to load service {}: {}", service, err); } } Item::Start(service) => match app::airupd().start_service(&service).await { Ok(_) => { - tracing::info!(target: "console", "Starting {}", display_name(&service).await) + crate::inform!("Starting {}", display_name(&service).await) } Err(err) => { - tracing::error!(target: "console", "Failed to start {}: {}", service, err) + crate::report_error!("Failed to start {}: {}", service, err) } }, Item::Run(cmd) => { if let Err(err) = ace.run(&cmd).await { - tracing::error!(target: "console", "Failed to execute command `{cmd}`: {}", err); + crate::report_error!("Failed to execute command `{cmd}`: {}", err); } } } @@ -166,20 +165,24 @@ async fn exec_milestone_serial(def: &Milestone) { match item { Item::Cache(service) => { if let Err(err) = app::airupd().cache_service(&service).await { - tracing::error!(target: "console", "Failed to load service {}: {}", service, err); + crate::report_error!("Failed to load service {}: {}", service, err); } } Item::Start(service) => match app::airupd().make_service_active(&service).await { Ok(_) => { - tracing::info!(target: "console", "Starting {}", display_name(&service).await) + crate::inform!("Starting {}", display_name(&service).await) } Err(err) => { - tracing::error!(target: "console", "Failed to start {}: {}", display_name(&service).await, err); + crate::report_error!( + "Failed to start {}: {}", + display_name(&service).await, + err + ); } }, Item::Run(cmd) => { if let Err(err) = run_wait(&ace, &cmd).await { - tracing::error!(target: "console", "Failed to execute command `{cmd}`: {}", err); + crate::report_error!("Failed to execute command `{cmd}`: {}", err); } } } @@ -195,7 +198,7 @@ async fn exec_milestone_sync(def: &Milestone) { match item { Item::Cache(service) => { if let Err(err) = app::airupd().cache_service(&service).await { - tracing::error!(target: "console", "Failed to load service {}: {}", service, err); + crate::report_error!("Failed to load service {}: {}", service, err); } } Item::Start(service) => match app::airupd().start_service(&service).await { @@ -203,7 +206,7 @@ async fn exec_milestone_sync(def: &Milestone) { handles.push((service, x)); } Err(err) => { - tracing::error!(target: "console", "Failed to start {}: {}", service, err); + crate::report_error!("Failed to start {}: {}", service, err); } }, Item::Run(cmd) => match ace.run(&cmd).await { @@ -211,7 +214,7 @@ async fn exec_milestone_sync(def: &Milestone) { commands.push((cmd, x)); } Err(err) => { - tracing::error!(target: "console", "Failed to execute command `{cmd}`: {}", err); + crate::report_error!("Failed to execute command `{cmd}`: {}", err); } }, } @@ -220,17 +223,17 @@ async fn exec_milestone_sync(def: &Milestone) { for (name, handle) in handles { match handle.wait().await { Ok(_) | Err(Error::Started) => { - tracing::info!(target: "console", "Starting {}", display_name(&name).await) + crate::inform!("Starting {}", display_name(&name).await) } Err(err) => { - tracing::error!(target: "console", "Failed to start {}: {}", display_name(&name).await, err); + crate::report_error!("Failed to start {}: {}", display_name(&name).await, err); } } } for (cmd, child) in commands { if let Err(err) = child.wait().await { - tracing::error!(target: "console", "Failed to execute command `{cmd}`: {}", err); + crate::report_error!("Failed to execute command `{cmd}`: {}", err); } } } diff --git a/airupd/src/milestones/reboot.rs b/airupd/src/milestones/reboot.rs index db4861d..f49ad95 100644 --- a/airupd/src/milestones/reboot.rs +++ b/airupd/src/milestones/reboot.rs @@ -53,7 +53,7 @@ fn stop_service_task(service: String) -> JoinHandle<()> { error = Some(err); } } else { - tracing::info!(target: "console", "Stopping {}", super::display_name(&service).await); + crate::inform!("Stopping {}", super::display_name(&service).await); } } Err(err) => { @@ -64,8 +64,7 @@ fn stop_service_task(service: String) -> JoinHandle<()> { } }; if let Some(err) = error { - tracing::error!( - target: "console", + crate::report_error!( "Failed to stop {}: {}", super::display_name(&service).await, err diff --git a/airupd/src/rpc/mod.rs b/airupd/src/rpc/mod.rs index 20b70d0..bf4f62b 100644 --- a/airupd/src/rpc/mod.rs +++ b/airupd/src/rpc/mod.rs @@ -102,15 +102,12 @@ impl Session { /// Starts the session task. fn start(mut self) { tokio::spawn(async move { - if let Err(err) = self.run().await { - tracing::debug!("{} disconnected: {}", self.audit_name().await, err); - } + _ = self.run().await; }); } /// Runs the session in place. async fn run(&mut self) -> anyhow::Result<()> { - tracing::debug!("{} established", self.audit_name().await); loop { let req = self.conn.recv_req().await?; if req.method == "debug.disconnect" { @@ -128,23 +125,4 @@ impl Session { self.conn.send(&resp).await?; } } - - /// Returns audit-style name of the IPC session. - async fn audit_name(&self) -> String { - let cred = self.conn.as_ref().peer_cred().ok(); - let uid = cred - .as_ref() - .map(|x| x.uid().to_string()) - .unwrap_or_else(|| "?".into()); - let gid = cred - .as_ref() - .map(|x| x.gid().to_string()) - .unwrap_or_else(|| "?".into()); - let pid = cred - .as_ref() - .and_then(|x| x.pid()) - .map(|x| x.to_string()) - .unwrap_or_else(|| "?".into()); - format!("ipc_session(uid={}, gid={}, pid={})", uid, gid, pid) - } } diff --git a/airupfx/airupfx/Cargo.toml b/airupfx/airupfx/Cargo.toml index 368b386..e8ef468 100644 --- a/airupfx/airupfx/Cargo.toml +++ b/airupfx/airupfx/Cargo.toml @@ -23,7 +23,6 @@ airupfx-signal = { path = "../airupfx-signal" } airupfx-time = { path = "../airupfx-time" } airupfx-macros = { path = "../airupfx-macros" } airupfx-extensions = { path = "../airupfx-extensions" } -tracing = "0.1" [target.'cfg(target_os = "linux")'.dependencies] selinux = { version = "0.4", optional = true } \ No newline at end of file diff --git a/airupfx/airupfx/src/util.rs b/airupfx/airupfx/src/util.rs index e769724..d4ae52a 100644 --- a/airupfx/airupfx/src/util.rs +++ b/airupfx/airupfx/src/util.rs @@ -17,14 +17,14 @@ where match self { Ok(val) => val, Err(err) => { - tracing::error!(target: "console", "{}: {}", why, err); + eprintln!("{why}: {err}"); if crate::process::as_pid1() { loop { if let Err(err) = shell().await { - tracing::error!(target: "console", "Failed to start `/bin/sh`: {err}"); + eprintln!("Failed to start `/bin/sh`: {err}"); } if let Err(err) = crate::process::reload_image() { - tracing::error!(target: "console", "Failed to reload `airupd` process image: {err}"); + eprintln!("Failed to reload `airupd` process image: {err}"); } } } else {