diff --git a/Cargo.lock b/Cargo.lock index 6036a11..08e0fb6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -306,6 +306,8 @@ dependencies = [ "tempfile", "test_bin", "tokio", + "tracing", + "tracing-subscriber", ] [[package]] @@ -1156,9 +1158,9 @@ dependencies = [ [[package]] name = "tracing" -version = "0.1.40" +version = "0.1.41" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c3523ab5a71916ccf420eebdf5521fcef02141234bbc0b8a49f2fdc4544364ef" +checksum = "784e0ac535deb450455cbfa28a6f0df145ea1bb7ae51b821cf5e7927fdcfbdd0" dependencies = [ "log", "pin-project-lite", @@ -1168,9 +1170,9 @@ dependencies = [ [[package]] name = "tracing-attributes" -version = "0.1.27" +version = "0.1.28" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" +checksum = "395ae124c09f9e6918a2310af6038fba074bcf474ac352496d5910dd59a2226d" dependencies = [ "proc-macro2", "quote", @@ -1179,9 +1181,9 @@ dependencies = [ [[package]] name = "tracing-core" -version = "0.1.32" +version = "0.1.33" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" +checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c" dependencies = [ "once_cell", "valuable", @@ -1200,9 +1202,9 @@ dependencies = [ [[package]] name = "tracing-subscriber" -version = "0.3.18" +version = "0.3.19" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" dependencies = [ "matchers", "nu-ansi-term", diff --git a/Cargo.toml b/Cargo.toml index 6a9954c..8bb651a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -45,6 +45,8 @@ tokio = "1.40.0" # still uses it. And sharded-slab is used by tracing-subscriber, which is # used by domain, which is used by us. _unused_lazy_static = { package = "lazy_static", version = "1.0.2" } +tracing = "0.1.41" +tracing-subscriber = "0.3.19" [dev-dependencies] test_bin = "0.4.0" diff --git a/src/commands/notify.rs b/src/commands/notify.rs index f080b43..0a6a135 100644 --- a/src/commands/notify.rs +++ b/src/commands/notify.rs @@ -10,10 +10,10 @@ use domain::rdata::Soa; use domain::tsig::Key; use domain::utils::base16; use lexopt::Arg; +use tracing::warn; use crate::env::Env; use crate::error::Error; -use crate::log::warning; use crate::parse::TSigInfo; use crate::Args; @@ -224,20 +224,17 @@ impl Notify { } let Ok(name) = Name::>::from_str(server) else { - warning!(env, "invalid domain name \"{server}\", skipping."); + warn!("invalid domain name \"{server}\", skipping."); continue; }; let Ok(hosts) = resolver.lookup_host(&name).await else { - warning!(env, "could not resolve host \"{name}\", skipping."); + warn!("could not resolve host \"{name}\", skipping."); continue; }; if hosts.is_empty() { - warning!( - env, - "skipping bad address: {name}: Name or service not known" - ); + warn!("skipping bad address: {name}: Name or service not known"); continue; } @@ -582,4 +579,23 @@ mod tests { assert_eq!(res.exit_code, 0); assert!(res.stderr.contains("Name or service not known")); } + + #[test] + fn invalid_domain_name() { + let rpl = format!( + " + CONFIG_END + + SCENARIO_BEGIN + + SCENARIO_END + " + ); + + let cmd = FakeCmd::new(["dnst", "notify", "-z", "nlnetlabs.test", ""]) + .stelline(rpl.as_bytes(), "notify.rpl"); + + let res = cmd.run(); + assert!(res.stderr.contains("invalid domain name")); + } } diff --git a/src/env/fake.rs b/src/env/fake.rs index 7f99232..5bacfde 100644 --- a/src/env/fake.rs +++ b/src/env/fake.rs @@ -60,16 +60,16 @@ impl Env for FakeEnv { self.cmd.cmd.iter().map(Into::into) } - fn stdout(&self) -> Stream { + fn stdout(&self) -> Stream { Stream { - writer: self.stdout.clone(), + writer: Mutex::new(self.stdout.clone()), is_terminal: false, } } - fn stderr(&self) -> Stream { + fn stderr(&self) -> Stream { Stream { - writer: self.stderr.clone(), + writer: Mutex::new(self.stderr.clone()), is_terminal: false, } } @@ -192,27 +192,32 @@ impl FakeCmd { impl FakeEnv { pub fn get_stdout(&self) -> String { - self.stdout.0.lock().unwrap().clone() + String::from_utf8(self.stdout.0.lock().unwrap().clone()).unwrap() } pub fn get_stderr(&self) -> String { - self.stderr.0.lock().unwrap().clone() + String::from_utf8(self.stderr.0.lock().unwrap().clone()).unwrap() } } /// A type to used to mock stdout and stderr #[derive(Clone, Default)] -pub struct FakeStream(Arc>); +pub struct FakeStream(Arc>>); -impl fmt::Write for FakeStream { - fn write_str(&mut self, s: &str) -> fmt::Result { - self.0.lock().unwrap().push_str(s); +impl io::Write for FakeStream { + fn write(&mut self, buf: &[u8]) -> io::Result { + self.0.lock().unwrap().extend_from_slice(buf); + Ok(buf.len()) + } + + fn flush(&mut self) -> io::Result<()> { + // do nothing Ok(()) } } impl fmt::Display for FakeStream { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - f.write_str(self.0.lock().unwrap().as_ref()) + f.write_str(std::str::from_utf8(&self.0.lock().unwrap()).unwrap()) } } diff --git a/src/env/mod.rs b/src/env/mod.rs index fb4b1cd..12c6844 100644 --- a/src/env/mod.rs +++ b/src/env/mod.rs @@ -1,8 +1,10 @@ use std::borrow::Cow; use std::ffi::OsString; -use std::fmt; use std::net::SocketAddr; +use std::ops::DerefMut; use std::path::Path; +use std::sync::Mutex; +use std::{fmt, io}; mod real; @@ -12,6 +14,7 @@ pub mod fake; use domain::net::client::protocol::{AsyncConnect, AsyncDgramRecv, AsyncDgramSend}; use domain::resolv::{stub::conf::ResolvConf, StubResolver}; pub use real::RealEnv; +use tracing_subscriber::fmt::MakeWriter; pub trait Env { /// Get an iterator over the command line arguments passed to the program @@ -22,12 +25,12 @@ pub trait Env { /// Get a reference to stdout /// /// Equivalent to [`std::io::stdout`] - fn stdout(&self) -> Stream; + fn stdout(&self) -> Stream; /// Get a reference to stderr /// /// Equivalent to [`std::io::stderr`] - fn stderr(&self) -> Stream; + fn stderr(&self) -> Stream; // /// Get a reference to stdin // fn stdin(&self) -> impl io::Read; @@ -59,19 +62,42 @@ pub trait Env { /// [`std::io::Write`]. Additionally, this `write_fmt` does not return a /// result. This means that we can use the [`write!`] and [`writeln`] macros /// without handling errors. -pub struct Stream { - writer: T, +pub struct Stream { + writer: Mutex, is_terminal: bool, } -impl Stream { +impl<'writer, T: io::Write + 'writer> MakeWriter<'writer> for Stream { + type Writer = &'writer Self; + + fn make_writer(&'writer self) -> Self::Writer { + &self + } +} + +impl io::Write for &Stream { + fn write(&mut self, buf: &[u8]) -> io::Result { + self.writer.lock().unwrap().deref_mut().write(buf) + } + + fn flush(&mut self) -> io::Result<()> { + self.writer.lock().unwrap().deref_mut().flush() + } +} + +impl Stream { pub fn write_fmt(&mut self, args: fmt::Arguments<'_>) { // This unwrap is not _really_ safe, but we are using this as stdout. // The `println` macro also ignores errors and `push_str` of the // fake stream also does not return an error. If this fails, it means // we can't write to stdout anymore so a graceful exit will be very // hard anyway. - self.writer.write_fmt(args).unwrap(); + self.writer + .lock() + .unwrap() + .deref_mut() + .write_fmt(args) + .unwrap(); } pub fn is_terminal(&self) -> bool { @@ -92,11 +118,11 @@ impl Env for &E { (**self).args_os() } - fn stdout(&self) -> Stream { + fn stdout(&self) -> Stream { (**self).stdout() } - fn stderr(&self) -> Stream { + fn stderr(&self) -> Stream { (**self).stderr() } diff --git a/src/env/real.rs b/src/env/real.rs index ff97f50..bbd230e 100644 --- a/src/env/real.rs +++ b/src/env/real.rs @@ -1,7 +1,7 @@ use std::ffi::OsString; -use std::fmt; use std::io::{self, IsTerminal}; use std::path::Path; +use std::sync::Mutex; use domain::net::client::protocol::{AsyncConnect, AsyncDgramRecv, AsyncDgramSend, UdpConnect}; use domain::resolv::stub::conf::ResolvConf; @@ -18,19 +18,19 @@ impl Env for RealEnv { std::env::args_os() } - fn stdout(&self) -> Stream { + fn stdout(&self) -> Stream { let stdout = io::stdout(); Stream { is_terminal: stdout.is_terminal(), - writer: FmtWriter(io::stdout()), + writer: Mutex::new(stdout), } } - fn stderr(&self) -> Stream { + fn stderr(&self) -> Stream { let stderr = io::stderr(); Stream { is_terminal: stderr.is_terminal(), - writer: FmtWriter(io::stdout()), + writer: Mutex::new(stderr), } } @@ -53,15 +53,3 @@ impl Env for RealEnv { StubResolver::from_conf(config) } } - -struct FmtWriter(T); - -impl fmt::Write for FmtWriter { - fn write_str(&mut self, s: &str) -> std::fmt::Result { - self.0.write_all(s.as_bytes()).map_err(|_| fmt::Error) - } - - fn write_fmt(&mut self, args: fmt::Arguments<'_>) -> fmt::Result { - self.0.write_fmt(args).map_err(|_| fmt::Error) - } -} diff --git a/src/error.rs b/src/error.rs index cdf50bc..2bdec3a 100644 --- a/src/error.rs +++ b/src/error.rs @@ -1,10 +1,10 @@ use std::fmt; -use std::{error, io}; +use std::io; use domain::base::wire::ParseError; +use tracing::error; use crate::env::Env; -use crate::log::error; //------------ Error --------------------------------------------------------- @@ -58,8 +58,6 @@ impl Error { /// Pretty-print this error. pub fn pretty_print(&self, env: impl Env) { - let mut err = env.stderr(); - let msg = match &self.0.primary { // Clap errors are already styled. We don't want our own pretty // styling around that and context does not make sense for command @@ -73,7 +71,8 @@ impl Error { PrimaryError::Other(error) => error, }; - error!(env, "{msg}"); + error!("{msg}"); + let mut err = env.stderr(); for context in &self.0.context { writeln!(err, "... while {context}"); } @@ -155,7 +154,7 @@ impl fmt::Debug for Error { //--- Error -impl error::Error for Error {} +impl std::error::Error for Error {} //------------ Macros -------------------------------------------------------- diff --git a/src/lib.rs b/src/lib.rs index 1c83b77..ee1e5b0 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -10,6 +10,7 @@ use commands::update::Update; use commands::LdnsCommand; use env::Env; use error::Error; +use log::LogFormatter; pub use self::args::Args; @@ -90,12 +91,23 @@ fn parse_args(env: impl Env) -> Result { } pub fn run(env: impl Env) -> u8 { - let res = parse_args(&env).and_then(|args| args.execute(&env)); - match res { - Ok(()) => 0, - Err(err) => { - err.pretty_print(&env); - err.exit_code() + let stderr = env.stderr(); + let subscriber = tracing_subscriber::FmtSubscriber::builder() + .with_ansi(stderr.is_terminal()) + .with_writer(stderr) + .event_format(LogFormatter { + program: env.args_os().next().unwrap().to_string_lossy().to_string(), + }) + .finish(); + + tracing::subscriber::with_default(subscriber, || { + let res = parse_args(&env).and_then(|args| args.execute(&env)); + match res { + Ok(()) => 0, + Err(err) => { + err.pretty_print(&env); + err.exit_code() + } } - } + }) } diff --git a/src/log.rs b/src/log.rs index b47579c..c988b91 100644 --- a/src/log.rs +++ b/src/log.rs @@ -1,54 +1,56 @@ -use std::fmt::Display; +use std::fmt; -use crate::env::Env; +use tracing::{Event, Level, Subscriber}; +use tracing_subscriber::{ + fmt::{format, FmtContext, FormatEvent, FormatFields}, + registry::LookupSpan, +}; mod color { - pub const BLUE: u8 = 34; - pub const YELLOW: u8 = 33; pub const RED: u8 = 31; + pub const GREEN: u8 = 32; + pub const YELLOW: u8 = 33; + pub const BLUE: u8 = 34; + pub const PURPLE: u8 = 35; } -#[derive(Clone, Copy, Debug, PartialEq, Eq)] -pub enum LogLevel { - Info, - Warning, - Error, +pub struct LogFormatter { + pub program: String, } -impl LogLevel { - fn color(self) -> u8 { - match self { - Self::Info => color::BLUE, - Self::Warning => color::YELLOW, - Self::Error => color::RED, +impl FormatEvent for LogFormatter +where + S: Subscriber + for<'a> LookupSpan<'a>, + N: for<'a> FormatFields<'a> + 'static, +{ + fn format_event( + &self, + ctx: &FmtContext<'_, S, N>, + mut writer: format::Writer<'_>, + event: &Event<'_>, + ) -> fmt::Result { + // Format values from the event's's metadata: + let metadata = event.metadata(); + + write!(&mut writer, "[{}] ", &self.program)?; + + let level = *metadata.level(); + if writer.has_ansi_escapes() { + let color = match level { + Level::ERROR => color::RED, + Level::WARN => color::YELLOW, + Level::INFO => color::BLUE, + Level::DEBUG => color::GREEN, + Level::TRACE => color::PURPLE, + }; + write!(&mut writer, "\x1B[{color}m{level}\x1B[0m: ",)?; + } else { + write!(&mut writer, "{level}: ")?; } - } - fn text(self) -> &'static str { - match self { - LogLevel::Info => "INFO", - LogLevel::Warning => "WARNING", - LogLevel::Error => "ERROR", - } - } -} - -impl Display for LogLevel { - fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - f.write_str(self.text()) - } -} - -struct Logger(&'static Env); - -pub fn log(env: impl Env, level: LogLevel, text: impl Display) { - let mut err = env.stderr(); - let prog = std::env::args().next().unwrap(); - - if err.is_terminal() { - let color = level.color(); - writeln!(err, "[{prog}] \x1B[{color}m{level}\x1B[0m: {text}"); - } else { - writeln!(err, "[{prog}] {level}: {text}"); + // Write fields on the event + ctx.field_format().format_fields(writer.by_ref(), event)?; + + writeln!(writer) } }