diff --git a/Cargo.lock b/Cargo.lock index bd5cf4a7..474ff2ca 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -331,6 +331,12 @@ dependencies = [ "cipher", ] +[[package]] +name = "camino" +version = "1.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c59e92b5a388f549b863a7bea62612c09f24c8393560709a54558a9abdfb3b9c" + [[package]] name = "cc" version = "1.0.83" @@ -551,9 +557,9 @@ checksum = "7e962a19be5cfc3f3bf6dd8f61eb50107f356ad6270fbb3ed41476571db78be5" [[package]] name = "defmt" -version = "0.3.5" +version = "0.3.6" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a8a2d011b2fee29fb7d659b83c43fce9a2cb4df453e16d441a51448e448f3f98" +checksum = "3939552907426de152b3c2c6f51ed53f98f448babd26f28694c95f5906194595" dependencies = [ "bitflags 1.3.2", "defmt-macros", @@ -561,9 +567,9 @@ dependencies = [ [[package]] name = "defmt-macros" -version = "0.3.6" +version = "0.3.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "54f0216f6c5acb5ae1a47050a6645024e6edafc2ee32d421955eccfef12ef92e" +checksum = "18bdc7a7b92ac413e19e95240e75d3a73a8d8e78aa24a594c22cbb4d44b4bbda" dependencies = [ "defmt-parser", "proc-macro-error", @@ -574,9 +580,9 @@ dependencies = [ [[package]] name = "defmt-parser" -version = "0.3.3" +version = "0.3.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "269924c02afd7f94bc4cecbfa5c379f6ffcf9766b3408fe63d22c728654eccd0" +checksum = "ff4a5fefe330e8d7f31b16a318f9ce81000d8e35e69b93eae154d16d2278f70f" dependencies = [ "thiserror", ] @@ -1567,6 +1573,12 @@ version = "0.4.13" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "01cda141df6706de531b6c46c3a33ecca755538219bd484262fa09410c13539c" +[[package]] +name = "literally" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f0d2be3f5a0d4d5c983d1f8ecc2a87676a0875a14feb9eebf0675f7c3e2f3c35" + [[package]] name = "lock_api" version = "0.4.11" @@ -1611,7 +1623,7 @@ dependencies = [ "serde", "serde-value", "serde_json", - "serde_yaml", + "serde_yaml 0.8.26", "thiserror", "thread-id", "typemap-ors", @@ -1745,6 +1757,16 @@ dependencies = [ "windows-sys 0.48.0", ] +[[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 = "num-traits" version = "0.2.17" @@ -1764,6 +1786,15 @@ dependencies = [ "libc", ] +[[package]] +name = "num_threads" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2819ce041d2ee131036f4fc9d6ae7ae125a3a40e97ba64d04fe799ad9dabbb44" +dependencies = [ + "libc", +] + [[package]] name = "object" version = "0.32.2" @@ -1854,6 +1885,12 @@ dependencies = [ "num-traits", ] +[[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" @@ -1898,6 +1935,24 @@ dependencies = [ "windows-targets 0.48.5", ] +[[package]] +name = "path-absolutize" +version = "3.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e4af381fe79fa195b4909485d99f73a80792331df0625188e707854f0b3383f5" +dependencies = [ + "path-dedot", +] + +[[package]] +name = "path-dedot" +version = "3.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "07ba0ad7e047712414213ff67533e6dd477af0a4e1d14fb52343e53d30ea9397" +dependencies = [ + "once_cell", +] + [[package]] name = "percent-encoding" version = "2.3.1" @@ -2481,6 +2536,12 @@ dependencies = [ "untrusted 0.9.0", ] +[[package]] +name = "rustversion" +version = "1.0.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7ffc183a10b4478d04cbbbfc96d0873219d962dd5accaff2ffbd4ceb7df837f4" + [[package]] name = "ryu" version = "1.0.16" @@ -2632,6 +2693,19 @@ dependencies = [ "yaml-rust", ] +[[package]] +name = "serde_yaml" +version = "0.9.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "adf8a49373e98a4c5f0ceb5d05aa7c648d75f63774981ed95b7c7443bbd50c6e" +dependencies = [ + "indexmap 2.2.2", + "itoa", + "ryu", + "serde", + "unsafe-libyaml", +] + [[package]] name = "sha1" version = "0.10.6" @@ -2748,12 +2822,15 @@ dependencies = [ "rpassword", "rpmalloc", "serde", + "serde_yaml 0.9.31", "shadowsocks-service", "snmalloc-rs", "sysexits", "tcmalloc", "thiserror", "tokio", + "trace4rs", + "tracing", "windows-service", "xdg", ] @@ -2802,6 +2879,15 @@ dependencies = [ "windows-sys 0.52.0", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "signal-hook-registry" version = "1.4.1" @@ -2850,6 +2936,17 @@ version = "1.13.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e6ecd384b10a64542d77071bd64bd7b231f4ed5940fba55e98c3de13824cf3d7" +[[package]] +name = "smart-default" +version = "0.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "133659a15339456eeeb07572eb02a91c91e9815e9cbc89566944d2c8d3efdbf6" +dependencies = [ + "proc-macro2", + "quote", + "syn 1.0.109", +] + [[package]] name = "smoltcp" version = "0.11.0" @@ -3058,6 +3155,45 @@ dependencies = [ "winapi", ] +[[package]] +name = "thread_local" +version = "1.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3fdd6f064ccff2d6567adcb3873ca630700f00b5ad3f060c25b5dcfd9a4ce152" +dependencies = [ + "cfg-if", + "once_cell", +] + +[[package]] +name = "time" +version = "0.3.20" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cd0cbfecb4d19b5ea75bb31ad904eb5b9fa13f21079c3b92017ebdf4999a5890" +dependencies = [ + "itoa", + "libc", + "num_threads", + "serde", + "time-core", + "time-macros", +] + +[[package]] +name = "time-core" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2e153e1f1acaef8acc537e68b44906d2db6436e2b35ac2c6b42640fff91f00fd" + +[[package]] +name = "time-macros" +version = "0.2.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fd80a657e71da814b8e5d60d3374fc6d35045062245d80224748ae522dd76f36" +dependencies = [ + "time-core", +] + [[package]] name = "tinyvec" version = "1.6.0" @@ -3171,6 +3307,53 @@ version = "0.3.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b6bc1c9ce2b5135ac7f93c72918fc37feb872bdc6a5533a8b85eb4b86bfdae52" +[[package]] +name = "trace4rs" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "79478dd8f523a9acec48b5e71ad56dc0f3b0dcaf703da29961d31a6bdd713bf0" +dependencies = [ + "camino", + "literally", + "log", + "once_cell", + "parking_lot", + "path-absolutize", + "regex", + "rustversion", + "thiserror", + "time", + "trace4rs-config", + "trace4rs-fmtorp", + "tracing", + "tracing-log 0.1.4", + "tracing-subscriber", + "utc-offset", +] + +[[package]] +name = "trace4rs-config" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "54a8eca7b495cb7659cb081820b3f410b42b9edaecb28b0d7861cff6606fc882" +dependencies = [ + "literally", + "serde", + "smart-default", + "thiserror", + "tracing", +] + +[[package]] +name = "trace4rs-fmtorp" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d3bc666374e9f4d6962ba6bbf1f9d5f6a56d4a8c08c6d07985684b9078e8bf0e" +dependencies = [ + "thiserror", + "tracing-subscriber", +] + [[package]] name = "tracing" version = "0.1.40" @@ -3201,6 +3384,44 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f751112709b4e791d8ce53e32c4ed2d353565a795ce84da2285393f41557bdf2" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +dependencies = [ + "nu-ansi-term", + "sharded-slab", + "smallvec", + "thread_local", + "time", + "tracing-core", + "tracing-log 0.2.0", ] [[package]] @@ -3288,6 +3509,12 @@ dependencies = [ "destructure_traitobject", ] +[[package]] +name = "unsafe-libyaml" +version = "0.2.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ab4c90930b95a82d00dc9e9ac071b4991924390d46cbd0dfe566148667605e4b" + [[package]] name = "untrusted" version = "0.7.1" @@ -3312,12 +3539,30 @@ dependencies = [ "serde", ] +[[package]] +name = "utc-offset" +version = "0.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d7f5187fd6893d08fecb6cdcb09badfbd5a187bf947fc12abc36c7bcb88dcd51" +dependencies = [ + "once_cell", + "parking_lot", + "thiserror", + "time", +] + [[package]] name = "utf8parse" version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "711b9620af191e0cdc7468a8d14e709c3dcdb115b36f838e601583af800a370a" +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "vcpkg" version = "0.2.15" diff --git a/Cargo.toml b/Cargo.toml index b25c5078..fafcbfe3 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -96,7 +96,7 @@ dns-over-https = ["shadowsocks-service/dns-over-https"] dns-over-h3 = ["shadowsocks-service/dns-over-h3"] # Enable logging output -logging = ["log4rs"] +logging = ["log4rs", "trace4rs", "tracing", "serde_yaml"] # Enable DNS-relay local-dns = ["local", "shadowsocks-service/local-dns"] @@ -164,10 +164,14 @@ replay-attack-detect = [ [dependencies] log = "0.4" log4rs = { version = "1.2", optional = true } +trace4rs = { version = "0.5", optional = true, features = ["serde"] } +tracing = { version = "0.1", optional = true } + serde = { version = "1.0", features = ["derive"] } json5 = "0.4" thiserror = "1.0" base64 = "0.21" +serde_yaml = { version = "0.9", optional = true } clap = { version = "4.4", features = ["wrap_help", "suggestions"] } cfg-if = "1" diff --git a/src/logging/log4rs.rs b/src/logging/log4rs.rs new file mode 100644 index 00000000..d153cc30 --- /dev/null +++ b/src/logging/log4rs.rs @@ -0,0 +1,69 @@ +//! Logging facilities with log4rs + +use std::path::Path; + +use log::LevelFilter; +use log4rs::{ + append::console::{ConsoleAppender, Target}, + config::{Appender, Config, Logger, Root}, + encode::pattern::PatternEncoder, +}; + +use crate::config::LogConfig; + +/// Initialize logger ([log4rs](https://crates.io/crates/log4rs)) from yaml configuration file +pub fn init_with_file

(path: P) +where + P: AsRef, +{ + log4rs::init_file(path, Default::default()).expect("init logging with file"); +} + +/// Initialize logger with provided configuration +pub fn init_with_config(bin_name: &str, config: &LogConfig) { + let debug_level = config.level; + let without_time = config.format.without_time; + + let mut pattern = String::new(); + if !without_time { + pattern += "{d} "; + } + pattern += "{h({l}):<5} "; + if debug_level >= 1 { + pattern += "[{P}:{I}] [{M}] "; + } + pattern += "{m}{n}"; + + let logging_builder = Config::builder().appender( + Appender::builder().build( + "console", + Box::new( + ConsoleAppender::builder() + .encoder(Box::new(PatternEncoder::new(&pattern))) + .target(Target::Stderr) + .build(), + ), + ), + ); + + let (l1, l2) = match debug_level { + 0 => (LevelFilter::Info, LevelFilter::Off), + 1 => (LevelFilter::Debug, LevelFilter::Off), + 2 => (LevelFilter::Trace, LevelFilter::Off), + 3 => (LevelFilter::Trace, LevelFilter::Debug), + _ => (LevelFilter::Off, LevelFilter::Trace), + }; + + let config = match debug_level { + 0..=3 => logging_builder + .logger(Logger::builder().build(bin_name, l1)) + .logger(Logger::builder().build("shadowsocks_rust", l1)) + .logger(Logger::builder().build("shadowsocks", l1)) + .logger(Logger::builder().build("shadowsocks_service", l1)), + _ => logging_builder, + } + .build(Root::builder().appender("console").build(l2)) + .expect("logging"); + + log4rs::init_config(config).expect("logging"); +} diff --git a/src/logging/mod.rs b/src/logging/mod.rs index 3973e569..cbf6b9f7 100644 --- a/src/logging/mod.rs +++ b/src/logging/mod.rs @@ -2,70 +2,27 @@ use std::path::Path; -use log::LevelFilter; -use log4rs::{ - append::console::{ConsoleAppender, Target}, - config::{Appender, Config, Logger, Root}, - encode::pattern::PatternEncoder, -}; - use crate::config::LogConfig; -/// Initialize logger ([log4rs](https://crates.io/crates/log4rs)) from yaml configuration file +mod log4rs; +mod tracing; + +/// Initialize logger ([log4rs](https://crates.io/crates/log4rs), [trace4rs](https://crates.io/crates/trace4rs)) from yaml configuration file pub fn init_with_file

(path: P) where P: AsRef, { - log4rs::init_file(path, Default::default()).expect("init logging with file"); + log4rs::init_with_file(path); + // FIXME: 2024-02-04 Temporary disable. + // trace4rs configuration file doesn't share exactly the same value with log4rs. + // + // tracing::init_with_file(path); } -/// Initialize logger with default configuration +/// Initialize logger with provided configuration pub fn init_with_config(bin_name: &str, config: &LogConfig) { - let debug_level = config.level; - let without_time = config.format.without_time; - - let mut pattern = String::new(); - if !without_time { - pattern += "{d} "; - } - pattern += "{h({l}):<5} "; - if debug_level >= 1 { - pattern += "[{P}:{I}] [{M}] "; - } - pattern += "{m}{n}"; - - let logging_builder = Config::builder().appender( - Appender::builder().build( - "console", - Box::new( - ConsoleAppender::builder() - .encoder(Box::new(PatternEncoder::new(&pattern))) - .target(Target::Stderr) - .build(), - ), - ), - ); - - let (l1, l2) = match debug_level { - 0 => (LevelFilter::Info, LevelFilter::Off), - 1 => (LevelFilter::Debug, LevelFilter::Off), - 2 => (LevelFilter::Trace, LevelFilter::Off), - 3 => (LevelFilter::Trace, LevelFilter::Debug), - _ => (LevelFilter::Off, LevelFilter::Trace), - }; - - let config = match debug_level { - 0..=3 => logging_builder - .logger(Logger::builder().build(bin_name, l1)) - .logger(Logger::builder().build("shadowsocks_rust", l1)) - .logger(Logger::builder().build("shadowsocks", l1)) - .logger(Logger::builder().build("shadowsocks_service", l1)), - _ => logging_builder, - } - .build(Root::builder().appender("console").build(l2)) - .expect("logging"); - - log4rs::init_config(config).expect("logging"); + log4rs::init_with_config(bin_name, config); + tracing::init_with_config(bin_name, config); } /// Init a default logger diff --git a/src/logging/tracing.rs b/src/logging/tracing.rs new file mode 100644 index 00000000..866a7f4a --- /dev/null +++ b/src/logging/tracing.rs @@ -0,0 +1,113 @@ +//! Logging facilities with tracing + +use std::collections::HashMap; +use std::path::Path; +use std::{collections::HashSet, fs::File}; + +use trace4rs::config::{Appender as ConfigAppender, AppenderId, Format, LevelFilter, Target}; +use trace4rs::{config::Logger, Config, Handle}; + +use crate::config::LogConfig; + +#[allow(dead_code)] +/// Initialize logger ([log4rs](https://crates.io/crates/log4rs)) from yaml configuration file +pub fn init_with_file

(path: P) +where + P: AsRef, +{ + // log4rs uses YAML as configuration format. + let mut fp = match File::open(path.as_ref()) { + Ok(fp) => fp, + Err(err) => { + panic!("failed to open file {}, error: {}", path.as_ref().display(), err); + } + }; + + let config: Config = match serde_yaml::from_reader(&mut fp) { + Ok(c) => c, + Err(err) => { + panic!("failed to read file {}, error: {}", path.as_ref().display(), err); + } + }; + + let handle = match Handle::try_from(&config) { + Ok(h) => h, + Err(err) => { + panic!( + "failed to initialize trace4rs Handle, config file: {}, error: {}", + path.as_ref().display(), + err + ); + } + }; + + match tracing::subscriber::set_global_default(handle.subscriber()) { + Ok(..) => {} + Err(err) => { + panic!( + "failed to initialize tracing subscriber, config file: {}, error: {}", + path.as_ref().display(), + err + ); + } + } +} + +/// Initialize logger with provided configuration +pub fn init_with_config(bin_name: &str, config: &LogConfig) { + let debug_level = config.level; + let without_time = config.format.without_time; + + let mut pattern = String::new(); + if !without_time { + pattern += "{T} "; + } + pattern += "{l} [{t}] {m} {f}"; + + let (l1, l2) = match debug_level { + 0 => (LevelFilter::INFO, LevelFilter::OFF), + 1 => (LevelFilter::DEBUG, LevelFilter::OFF), + 2 => (LevelFilter::TRACE, LevelFilter::OFF), + 3 => (LevelFilter::TRACE, LevelFilter::DEBUG), + _ => (LevelFilter::OFF, LevelFilter::TRACE), + }; + + let default_logger = Logger { + appenders: HashSet::from([AppenderId("console".to_owned())]), + level: l2, + format: Format::Custom(pattern.clone()), + }; + + let mut loggers = HashMap::new(); + if debug_level <= 3 { + let l1_logger = Logger { + appenders: HashSet::from([AppenderId("console".to_owned())]), + level: l1, + format: Format::Custom(pattern), + }; + loggers.insert(Target(bin_name.to_owned()), l1_logger.clone()); + loggers.insert(Target("shadowsocks_rust".to_owned()), l1_logger.clone()); + loggers.insert(Target("shadowsocks".to_owned()), l1_logger.clone()); + loggers.insert(Target("shadowsocks_service".to_owned()), l1_logger); + } + + let config = Config { + default: default_logger, + appenders: HashMap::from([(AppenderId("console".to_owned()), ConfigAppender::console())]), + loggers, + }; + + let handle = match Handle::try_from(&config) { + Ok(h) => h, + Err(err) => { + panic!("failed to initialize trace4rs Handle, error: {}", err); + } + }; + + match tracing::subscriber::set_global_default(handle.subscriber()) { + Ok(..) => {} + Err(err) => { + panic!("failed to initialize tracing subscriber, error: {}", err); + } + } +}