Browse Source

bin/app: replace log with tracing
- replaced android-logger with android-tracing crate
- use tracing-appender to make file-rotate nonblocking
- add a couple of targets to muted_targets

oars 11 months ago
parent
commit
06ac488ccb
6 changed files with 133 additions and 228 deletions
  1. 59 61
      bin/app/Cargo.lock
  2. 4 3
      bin/app/Cargo.toml
  3. 1 1
      bin/app/src/gfx/mod.rs
  4. 1 1
      bin/app/src/gfx/trax.rs
  5. 61 158
      bin/app/src/logger.rs
  6. 7 4
      bin/app/src/main.rs

+ 59 - 61
bin/app/Cargo.lock

@@ -102,21 +102,9 @@ dependencies = [
 
 [[package]]
 name = "android_log-sys"
-version = "0.3.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "84521a3cf562bc62942e294181d9eef17eb38ceb8c68677bc49f144e4c3d4f8d"
-
-[[package]]
-name = "android_logger"
-version = "0.13.3"
+version = "0.2.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c494134f746c14dc653a35a4ea5aca24ac368529da5370ecf41fe0341c35772f"
-dependencies = [
- "android_log-sys",
- "env_logger",
- "log",
- "once_cell",
-]
+checksum = "85965b6739a430150bdd138e2374a98af0c3ee0d030b3bb7fc3bddff58d0102e"
 
 [[package]]
 name = "android_system_properties"
@@ -1313,6 +1301,15 @@ dependencies = [
  "itertools 0.10.5",
 ]
 
+[[package]]
+name = "crossbeam-channel"
+version = "0.5.15"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "82b8f8f868b36967f9606790d1903570de9ceaf870a7bf9fbbd3016d636a2cb2"
+dependencies = [
+ "crossbeam-utils",
+]
+
 [[package]]
 name = "crossbeam-deque"
 version = "0.8.6"
@@ -1435,7 +1432,7 @@ dependencies = [
  "halo2_proofs",
  "httparse",
  "libc",
- "log",
+ "nu-ansi-term 0.46.0",
  "num-bigint",
  "pin-project-lite",
  "rand 0.8.5",
@@ -1444,7 +1441,6 @@ dependencies = [
  "rustls-pemfile",
  "semver",
  "serde",
- "simplelog",
  "sled-overlay",
  "smol",
  "socket2",
@@ -1458,6 +1454,9 @@ dependencies = [
  "tor-hsservice",
  "tor-proto",
  "tor-rtcompat",
+ "tracing",
+ "tracing-appender",
+ "tracing-subscriber",
  "url",
  "x509-parser",
 ]
@@ -1466,7 +1465,6 @@ dependencies = [
 name = "darkfi-app"
 version = "0.1.0"
 dependencies = [
- "android_logger",
  "async-broadcast",
  "async-channel 2.5.0",
  "async-gen",
@@ -1490,7 +1488,6 @@ dependencies = [
  "harfbuzz-sys",
  "image",
  "indoc",
- "log",
  "miniquad",
  "parking_lot 0.12.5",
  "parley",
@@ -1499,12 +1496,15 @@ dependencies = [
  "rand 0.8.5",
  "regex",
  "semver",
- "simplelog",
  "sled-overlay",
  "smol",
  "swash",
  "thiserror 2.0.17",
  "tor-dirmgr",
+ "tracing",
+ "tracing-android",
+ "tracing-appender",
+ "tracing-subscriber",
  "unic-langid",
  "url",
  "zeno",
@@ -2010,16 +2010,6 @@ dependencies = [
  "syn 2.0.108",
 ]
 
-[[package]]
-name = "env_logger"
-version = "0.10.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "4cd405aab171cb85d6735e5c8d9db038c17d3ca007a4d2c25f337935c3d90580"
-dependencies = [
- "log",
- "regex",
-]
-
 [[package]]
 name = "equator"
 version = "0.4.2"
@@ -3622,6 +3612,16 @@ version = "2.0.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "5e0826a989adedc2a244799e823aece04662b66609d96af8dff7ac6df9a8925d"
 
+[[package]]
+name = "nu-ansi-term"
+version = "0.46.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
+dependencies = [
+ "overload",
+ "winapi",
+]
+
 [[package]]
 name = "nu-ansi-term"
 version = "0.50.3"
@@ -3761,15 +3761,6 @@ dependencies = [
  "syn 2.0.108",
 ]
 
-[[package]]
-name = "num_threads"
-version = "0.1.7"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "5c7398b9c8b70908f6371f47ed36737907c87c52af34c268fed0bf0ceb92ead9"
-dependencies = [
- "libc",
-]
-
 [[package]]
 name = "objc-rs"
 version = "0.2.8"
@@ -3889,6 +3880,12 @@ dependencies = [
  "memchr",
 ]
 
+[[package]]
+name = "overload"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
+
 [[package]]
 name = "p256"
 version = "0.13.2"
@@ -5153,17 +5150,6 @@ dependencies = [
  "quote",
 ]
 
-[[package]]
-name = "simplelog"
-version = "0.12.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "16257adbfaef1ee58b1363bdc0664c9b8e1e30aed86049635fb5f147d065a9c0"
-dependencies = [
- "log",
- "termcolor",
- "time",
-]
-
 [[package]]
 name = "sinsemilla"
 version = "0.1.0"
@@ -5547,15 +5533,6 @@ dependencies = [
  "windows-sys 0.61.2",
 ]
 
-[[package]]
-name = "termcolor"
-version = "1.4.1"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "06794f8f6c5c898b3275aebefa6b8a1cb24cd2c6c79397ab15774837a0bc5755"
-dependencies = [
- "winapi-util",
-]
-
 [[package]]
 name = "textwrap"
 version = "0.11.0"
@@ -5636,9 +5613,7 @@ checksum = "91e7d9e3bb61134e77bde20dd4825b97c010155709965fedf0f49bb138e52a9d"
 dependencies = [
  "deranged",
  "itoa",
- "libc",
  "num-conv",
- "num_threads",
  "powerfmt",
  "serde",
  "time-core",
@@ -6784,6 +6759,29 @@ dependencies = [
  "tracing-core",
 ]
 
+[[package]]
+name = "tracing-android"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "12612be8f868a09c0ceae7113ff26afe79d81a24473a393cb9120ece162e86c0"
+dependencies = [
+ "android_log-sys",
+ "tracing",
+ "tracing-subscriber",
+]
+
+[[package]]
+name = "tracing-appender"
+version = "0.2.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf"
+dependencies = [
+ "crossbeam-channel",
+ "thiserror 1.0.69",
+ "time",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "tracing-attributes"
 version = "0.1.30"
@@ -6823,7 +6821,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "2054a14f5307d601f88daf0553e1cbf472acc4f2c51afab632431cdcd72124d5"
 dependencies = [
  "matchers",
- "nu-ansi-term",
+ "nu-ansi-term 0.50.3",
  "once_cell",
  "regex-automata",
  "sharded-slab",

+ 4 - 3
bin/app/Cargo.toml

@@ -19,7 +19,7 @@ freetype-rs = { version = "0.37.0", features = ["bundled"] }
 
 image = "0.25.5"
 qoi = "0.4.1"
-log = { version = "0.4.27", features = ["release_max_level_info"] }
+tracing = "0.1.41"
 glam = "0.29.2"
 #zmq = "0.10.0"
 #async_zmq = "0.4.0"
@@ -46,8 +46,9 @@ chrono = "0.4.41"
 async-gen = "0.2.3"
 async-trait = "0.1.88"
 blake3 = "1.8.2"
-simplelog = "0.12.2"
 clap = { version = "4.5", features = ["derive"] }
+tracing-subscriber = { version = "0.3.19", default-features = false, features = ["fmt"] }
+tracing-appender = "0.2.3"
 # For log files
 file-rotate = "0.7.6"
 parking_lot = { version = "0.12.4", features = ["nightly"] }
@@ -84,7 +85,7 @@ halo2_gadgets = { git="https://github.com/parazyd/halo2", branch="v031" }
 dirs = "5.0.1"
 
 [target.'cfg(target_os = "android")'.dependencies]
-android_logger = "0.13.3"
+tracing-android = "0.2.0"
 # Required by Arti: tor-dirmgr
 tor-dirmgr = { version="0.32.0", features=["static"] }
 

+ 1 - 1
bin/app/src/gfx/mod.rs

@@ -20,7 +20,6 @@ use darkfi_serial::{
     async_trait, AsyncEncodable, AsyncWrite, Decodable, Encodable, FutAsyncWriteExt,
     SerialDecodable, SerialEncodable,
 };
-use log::debug;
 #[cfg(target_os = "android")]
 use miniquad::native::egl;
 use miniquad::{
@@ -40,6 +39,7 @@ use std::{
         Arc,
     },
 };
+use tracing::debug;
 
 pub mod anim;
 use anim::{Frame as AnimFrame, GfxSeqAnim};

+ 1 - 1
bin/app/src/gfx/trax.rs

@@ -17,9 +17,9 @@
  */
 
 use darkfi_serial::Encodable;
-use log::debug;
 use parking_lot::Mutex as SyncMutex;
 use std::{fs::File, sync::OnceLock};
+use tracing::debug;
 
 use super::{BufferId, DebugTag, DrawCall, TextureId, Vertex};
 use crate::{prop::BatchGuardId, EpochIndex};

+ 61 - 158
bin/app/src/logger.rs

@@ -15,17 +15,20 @@
  * You should have received a copy of the GNU Affero General Public License
  * along with this program.  If not, see <https://www.gnu.org/licenses/>.
  */
-
-use log::{LevelFilter, Log, Metadata, Record};
-use simplelog::{CombinedLogger, Config, ConfigBuilder, SharedLogger};
-
+use tracing_appender::non_blocking::WorkerGuard;
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, Layer, Registry};
 #[cfg(feature = "enable-filelog")]
 use {
     file_rotate::{compression::Compression, suffix::AppendCount, ContentLimit, FileRotate},
-    simplelog::WriteLogger,
-    std::{path::PathBuf, thread::sleep, time::Duration},
+    std::path::PathBuf,
 };
 
+#[cfg(target_os = "android")]
+use tracing_subscriber::filter::{LevelFilter, Targets};
+
+#[cfg(any(not(target_os = "android"), feature = "enable-filelog"))]
+use darkfi::util::logger::{EventFormatter, Level, TargetFilter};
+
 // Measured in bytes
 #[cfg(feature = "enable-filelog")]
 const LOGFILE_MAXSIZE: usize = 5_000_000;
@@ -33,6 +36,8 @@ const LOGFILE_MAXSIZE: usize = 5_000_000;
 static MUTED_TARGETS: &[&'static str] = &[
     "sled",
     "rustls",
+    "async_io",
+    "polling",
     "net::channel",
     "net::message_publisher",
     "net::hosts",
@@ -47,7 +52,7 @@ static MUTED_TARGETS: &[&'static str] = &[
     "event_graph::dag_insert()",
     "event_graph::protocol",
 ];
-
+#[cfg(not(target_os = "android"))]
 static ALLOW_TRACE: &[&'static str] = &["ui", "app", "gfx"];
 
 #[cfg(all(target_os = "android", feature = "enable-filelog"))]
@@ -61,175 +66,73 @@ fn logfile_path() -> PathBuf {
     dirs::cache_dir().unwrap().join("darkfi/darkfi-app.log")
 }
 
-#[cfg(target_os = "android")]
-mod android {
-    use super::*;
-    use android_logger::{AndroidLogger, Config as AndroidConfig};
-
-    /// Implements a wrapper around the android logger so it's compatible with simplelog.
-    pub struct AndroidLoggerWrapper {
-        logger: AndroidLogger,
-        level: LevelFilter,
-        config: Config,
-    }
-
-    impl AndroidLoggerWrapper {
-        pub fn new(level: LevelFilter, config: Config) -> Box<Self> {
-            let cfg = AndroidConfig::default().with_max_level(level).with_tag("darkfi");
-            Box::new(Self { logger: AndroidLogger::new(cfg), level, config })
-        }
-    }
-
-    impl Log for AndroidLoggerWrapper {
-        fn enabled(&self, metadata: &Metadata<'_>) -> bool {
-            let target = metadata.target();
-            for allow in ALLOW_TRACE {
-                if target.starts_with(allow) {
-                    return true
-                }
-            }
-            for muted in MUTED_TARGETS {
-                if target.starts_with(muted) {
-                    return false
-                }
-            }
-            if metadata.level() > self.level {
-                return false
-            }
-            self.logger.enabled(metadata)
-        }
-
-        fn log(&self, record: &Record<'_>) {
-            if self.enabled(record.metadata()) {
-                self.logger.log(record)
-            }
-        }
-
-        fn flush(&self) {}
-    }
-
-    impl SharedLogger for AndroidLoggerWrapper {
-        fn level(&self) -> LevelFilter {
-            self.level
-        }
-
-        fn config(&self) -> Option<&Config> {
-            Some(&self.config)
-        }
-
-        fn as_log(self: Box<Self>) -> Box<dyn Log> {
-            Box::new(*self)
-        }
-    }
-}
-
-#[cfg(not(target_os = "android"))]
-mod desktop {
-    use super::*;
-    use simplelog::{ColorChoice, TermLogger, TerminalMode};
-
-    /// Implements a wrapper around the android logger so it's compatible with simplelog.
-    pub struct CustomTermLogger {
-        logger: TermLogger,
-    }
-
-    impl CustomTermLogger {
-        pub fn new(_level: LevelFilter, cfg: Config) -> Box<Self> {
-            let logger =
-                TermLogger::new(LevelFilter::Trace, cfg, TerminalMode::Mixed, ColorChoice::Auto);
-            Box::new(Self { logger: *logger })
-        }
-    }
-
-    impl Log for CustomTermLogger {
-        fn enabled(&self, metadata: &Metadata<'_>) -> bool {
-            let target = metadata.target();
-            for allow in ALLOW_TRACE {
-                if target.starts_with(allow) {
-                    return true
-                }
-            }
-            for muted in MUTED_TARGETS {
-                if target.starts_with(muted) && metadata.level() > LevelFilter::Info {
-                    return false
-                }
-            }
-            if metadata.level() > self.level() {
-                return false
-            }
-            self.logger.enabled(metadata)
-        }
-
-        fn log(&self, record: &Record<'_>) {
-            if self.enabled(record.metadata()) {
-                self.logger.log(record)
-            }
-        }
-
-        fn flush(&self) {
-            self.logger.flush()
-        }
-    }
-
-    impl SharedLogger for CustomTermLogger {
-        fn level(&self) -> LevelFilter {
-            self.logger.level()
-        }
-
-        fn config(&self) -> Option<&Config> {
-            self.logger.config()
-        }
-
-        fn as_log(self: Box<Self>) -> Box<dyn Log> {
-            Box::new(self.logger).as_log()
-        }
-    }
-}
-
-pub fn setup_logging() {
-    // https://gist.github.com/jb-alvarado/6e223936446bb88cd9a93e7028fc2c4f
-    let mut loggers: Vec<Box<dyn SharedLogger>> = vec![];
-
-    let mut cfg = ConfigBuilder::new();
+pub fn setup_logging() -> Option<WorkerGuard> {
+    let mut layers: Vec<(Box<dyn Layer<Registry> + Send + Sync>, Option<WorkerGuard>)> = vec![];
 
     #[cfg(feature = "enable-filelog")]
     {
-        let mut cfg = cfg.clone();
-        cfg.add_filter_ignore_str("sled");
-        cfg.add_filter_ignore_str("rustls");
-        let cfg = cfg.build();
-
-        let log_file = FileRotate::new(
+        let (non_blocking_file_rotate, guard) = tracing_appender::non_blocking(FileRotate::new(
             logfile_path(),
             AppendCount::new(0),
             ContentLimit::BytesSurpassed(LOGFILE_MAXSIZE),
             Compression::None,
             #[cfg(unix)]
             None,
-        );
-        let file_logger = WriteLogger::new(LevelFilter::Trace, cfg, log_file);
-        loggers.push(file_logger);
+        ));
+
+        let file_layer = tracing_subscriber::fmt::Layer::new()
+            .event_format(EventFormatter::new(true, true))
+            .fmt_fields(tracing_subscriber::fmt::format::debug_fn(
+                darkfi::util::logger::file_field_formatter,
+            ))
+            .with_writer(non_blocking_file_rotate)
+            .with_filter(
+                TargetFilter::default()
+                    .ignore_targets(["sled", "rustls", "async_io", "polling"])
+                    .default_level(Level::Trace),
+            );
+
+        layers.push((file_layer.boxed(), Some(guard)));
     }
 
-    let cfg = cfg.build();
-
     #[cfg(target_os = "android")]
     {
-        use android::AndroidLoggerWrapper;
-        let android_logger = AndroidLoggerWrapper::new(LevelFilter::Trace, cfg);
-        loggers.push(android_logger);
+        let logcat_layer =
+            tracing_android::layer("darkfi").expect("tracing_android layer").with_filter(
+                Targets::new()
+                    .with_targets(
+                        crate::logger::MUTED_TARGETS.iter().map(|&t| (t, LevelFilter::OFF)),
+                    )
+                    .with_default(LevelFilter::TRACE),
+            );
+
+        layers.push((logcat_layer.boxed(), None));
     }
 
     #[cfg(not(target_os = "android"))]
     {
-        use desktop::CustomTermLogger;
+        let terminal_layer = tracing_subscriber::fmt::Layer::new()
+            .event_format(EventFormatter::new(true, true))
+            .fmt_fields(tracing_subscriber::fmt::format::debug_fn(
+                darkfi::util::logger::terminal_field_formatter,
+            ))
+            .with_writer(std::io::stdout)
+            .with_filter(
+                TargetFilter::default()
+                    .targets_level(ALLOW_TRACE, Level::Trace)
+                    .targets_level(MUTED_TARGETS, Level::Info)
+                    .default_level(Level::Debug),
+            );
+
+        layers.push((terminal_layer.boxed(), None));
+    }
 
-        // For ANSI colors in the terminal
-        colored::control::set_override(true);
+    let file_logging_guard = layers.iter_mut().find_map(|l| l.1.take());
 
-        let term_logger = CustomTermLogger::new(LevelFilter::Debug, cfg);
-        loggers.push(term_logger);
-    }
+    Registry::default()
+        .with(layers.into_iter().map(|l| l.0).collect::<Vec<_>>())
+        .try_init()
+        .expect("logger");
 
-    CombinedLogger::init(loggers).expect("logger");
+    file_logging_guard
 }

+ 7 - 4
bin/app/src/main.rs

@@ -25,9 +25,7 @@ use darkfi::system::CondVar;
 use std::sync::{Arc, OnceLock};
 
 #[macro_use]
-extern crate log;
-#[allow(unused_imports)]
-use log::LevelFilter;
+extern crate tracing;
 
 #[derive(Debug)]
 pub enum AndroidSuggestEvent {
@@ -118,6 +116,10 @@ struct God {
     method_recv: async_channel::Receiver<(gfx::EpochIndex, gfx::GraphicsMethod)>,
     /// Publisher to send input and window events to subscribers.
     event_pub: gfx::GraphicsEventPublisherPtr,
+
+    /// A WorkerGuard for file logging used to ensure buffered logs are flushed
+    /// to their output in the case of abrupt terminations of a process.
+    _file_logging_guard: Option<tracing_appender::non_blocking::WorkerGuard>,
 }
 
 impl God {
@@ -126,7 +128,7 @@ impl God {
         std::panic::set_hook(Box::new(panic_hook));
 
         text2::init_txt_ctx();
-        logger::setup_logging();
+        let file_logging_guard = logger::setup_logging();
 
         info!(target: "main", "Creating the app");
 
@@ -211,6 +213,7 @@ impl God {
             render_api,
             method_recv,
             event_pub,
+            _file_logging_guard: file_logging_guard,
         }
     }