// Copyright 2022 The ChromiumOS Authors // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. //! Facilities for sending log message to syslog. //! //! Every function exported by this module is thread-safe. Each function will silently fail until //! `syslog::init()` is called and returns `Ok`. //! //! This implements and sets logger up for logging facade exposed by the [`log` //! crate][log-crate-url]. //! //! # Examples //! //! ``` //! use log::{error, warn}; //! use base::syslog; //! //! if let Err(e) = syslog::init() { //! println!("failed to initiailize syslog: {}", e); //! return; //! } //! warn!("this is your {} warning", "final"); //! error!("something went horribly wrong: {}", "out of RAMs"); //! ``` //! //! ``` //! use log::{error, warn}; //! use base::syslog::{init_with, LogConfig, fmt}; //! use std::io::Write; //! //! let mut cfg = LogConfig::default(); //! cfg.log_args.stderr = true; //! cfg.log_args.filter = String::from("info,base=debug,base::syslog=error,serial_console=false"); //! //! init_with(cfg).unwrap(); //! error!("something went horribly wrong: {}", "out of RAMs"); //! ``` //! //! //! [log-crate-url]: https://docs.rs/log/ use std::fmt::Display; use std::io; use std::io::Write; use std::sync::MutexGuard; use chrono::Utc; pub use env_logger::fmt; pub use env_logger::{self}; pub use log::*; use once_cell::sync::Lazy; use remain::sorted; use serde::Deserialize; use serde::Serialize; use sync::Mutex; use thiserror::Error as ThisError; use crate::descriptor::AsRawDescriptor; use crate::platform::syslog::PlatformSyslog; use crate::platform::RawDescriptor; /// The priority (i.e. severity) of a syslog message. /// /// See syslog man pages for information on their semantics. #[derive(Copy, Clone, Debug, PartialEq, Eq, Serialize, Deserialize)] pub enum Priority { Emergency = 0, Alert = 1, Critical = 2, Error = 3, Warning = 4, Notice = 5, Info = 6, Debug = 7, } impl Display for Priority { fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result { use self::Priority::*; let string = match self { Emergency => "EMERGENCY", Alert => "ALERT", Critical => "CRITICAL", Error => "ERROR", Warning => "WARNING", Notice => "NOTICE", Info => "INFO", Debug => "DEBUG", }; write!(f, "{}", string) } } impl From for Priority { fn from(level: log::Level) -> Self { match level { log::Level::Error => Priority::Error, log::Level::Warn => Priority::Warning, log::Level::Info => Priority::Info, log::Level::Debug => Priority::Debug, log::Level::Trace => Priority::Debug, } } } impl TryFrom<&str> for Priority { type Error = &'static str; fn try_from(value: &str) -> Result>::Error> { match value { "0" | "EMERGENCY" => Ok(Priority::Emergency), "1" | "ALERT" => Ok(Priority::Alert), "2" | "CRITICAL" => Ok(Priority::Critical), "3" | "ERROR" => Ok(Priority::Error), "4" | "WARNING" => Ok(Priority::Warning), "5" | "NOTICE" => Ok(Priority::Notice), "6" | "INFO" => Ok(Priority::Info), "7" | "DEBUG" => Ok(Priority::Debug), _ => Err("Priority can only be parsed from 0-7 and given variant names"), } } } /// The facility of a syslog message. /// /// See syslog man pages for information on their semantics. #[derive(Copy, Clone, serde::Deserialize, serde::Serialize)] pub enum Facility { Kernel = 0, User = 1 << 3, Mail = 2 << 3, Daemon = 3 << 3, Auth = 4 << 3, Syslog = 5 << 3, Lpr = 6 << 3, News = 7 << 3, Uucp = 8 << 3, Local0 = 16 << 3, Local1 = 17 << 3, Local2 = 18 << 3, Local3 = 19 << 3, Local4 = 20 << 3, Local5 = 21 << 3, Local6 = 22 << 3, Local7 = 23 << 3, } /// Errors returned by `syslog::init()`. #[sorted] #[derive(ThisError, Debug)] pub enum Error { /// Error while attempting to connect socket. #[error("failed to connect socket: {0}")] Connect(io::Error), /// There was an error using `open` to get the lowest file descriptor. #[error("failed to get lowest file descriptor: {0}")] GetLowestFd(io::Error), /// The guess of libc's file descriptor for the syslog connection was invalid. #[error("guess of fd for syslog connection was invalid")] InvalidFd, /// Initialization was never attempted. #[error("initialization was never attempted")] NeverInitialized, /// Initialization has previously failed and can not be retried. #[error("initialization previously failed and cannot be retried")] Poisoned, /// Error while creating socket. #[error("failed to create socket: {0}")] Socket(io::Error), } pub(crate) trait Syslog { fn new( proc_name: String, facility: Facility, ) -> Result<(Option>, Option), Error>; } pub struct State { /// Record filter filter: env_logger::filter::Filter, /// All the loggers we have loggers: Vec>, /// Raw Descriptors to preserve descriptors: Vec, /// True if we have just been initialized with safe startup defaults (stderr logging), false /// after detailed initialization has occurred. early_init: bool, } /// The logger that is provided to the `log` crate. Wraps our State struct so that we can /// reconfigure logging sinks on the fly. struct LoggingFacade {} impl Log for LoggingFacade { fn enabled(&self, metadata: &log::Metadata) -> bool { STATE.lock().enabled(metadata) } fn log(&self, record: &log::Record) { STATE.lock().log(record) } fn flush(&self) { STATE.lock().flush() } } #[derive(Clone, serde::Deserialize, serde::Serialize)] pub struct LogArgs { /// A filter for log messages. Please see /// module level documentation and [`env_logger` crate](https://docs.rs/env_logger) /// /// Example: `off`, `trace`, `trace,crosvm=error,base::syslog=debug` pub filter: String, /// If set to true will duplicate output to stderr pub stderr: bool, /// TAG to use for syslog output pub proc_name: String, /// Enable/disable platform's "syslog" pub syslog: bool, /// Facility to use for syslog output pub syslog_facility: Facility, } impl Default for LogArgs { fn default() -> Self { Self { filter: String::from("info"), stderr: true, proc_name: String::from("crosvm"), syslog: true, syslog_facility: Facility::User, } } } #[derive(Default)] pub struct LogConfig { /// Logging configuration arguments. pub log_args: LogArgs, /// If specified will output to given Sink pub pipe: Option>, /// descriptor to preserve on forks (intended to be used with pipe) pub pipe_fd: Option, /// A formatter to use with the pipe. (Syslog has hardcoded format) /// see module level documentation and [`env_logger` crate](https://docs.rs/env_logger) pub pipe_formatter: Option< Box) -> std::io::Result<()> + Sync + Send>, >, } impl State { pub fn new(cfg: LogConfig) -> Result { let mut loggers: Vec> = vec![]; let mut descriptors = vec![]; let mut builder = env_logger::filter::Builder::new(); builder.parse(&cfg.log_args.filter); let filter = builder.build(); let create_formatted_builder = || { let mut builder = env_logger::Builder::new(); // Output log lines w/ local ISO 8601 timestamps. builder.format(|buf, record| { writeln!( buf, "[{} {:5} {}] {}", Utc::now().format("%Y-%m-%dT%H:%M:%S%.9f%:z"), record.level(), record.module_path().unwrap_or(""), record.args() ) }); builder }; if cfg.log_args.stderr { let mut builder = create_formatted_builder(); builder.filter_level(log::LevelFilter::Trace); builder.target(env_logger::Target::Stderr); loggers.push(Box::new(builder.build())); descriptors.push(std::io::stderr().as_raw_descriptor()); } if let Some(fd) = cfg.pipe_fd { descriptors.push(fd); } if let Some(file) = cfg.pipe { let mut builder = create_formatted_builder(); builder.filter_level(log::LevelFilter::Trace); builder.target(env_logger::Target::Pipe(Box::new(file))); // https://github.com/env-logger-rs/env_logger/issues/208 builder.is_test(true); if let Some(format) = cfg.pipe_formatter { builder.format(format); } loggers.push(Box::new(builder.build())); } if cfg.log_args.syslog { match PlatformSyslog::new(cfg.log_args.proc_name, cfg.log_args.syslog_facility) { Ok((mut logger, fd)) => { if let Some(fd) = fd { descriptors.push(fd); } if let Some(logger) = logger.take() { loggers.push(logger); } } Err(e) => { // The default log configuration used in early_init() enables syslog, so we // don't want to terminate the program if syslog can't be initialized. Warn the // user but continue running. eprintln!("syslog init failed: {}", e); } } } Ok(State { filter, loggers, descriptors, early_init: false, }) } } impl Default for State { fn default() -> Self { Self::new(Default::default()).unwrap() } } static STATE: Lazy> = Lazy::new(|| { let mut state = State::new(LogConfig::default()).expect("failed to configure minimal logging"); state.early_init = true; Mutex::new(state) }); static LOGGING_FACADE: LoggingFacade = LoggingFacade {}; static EARLY_INIT_CALLED: Mutex = Mutex::new(false); /// Initialize the syslog connection and internal variables. /// /// This should only be called once per process before any other threads have been spawned or any /// signal handlers have been registered. Every call made after the first will panic. /// /// Use `init_with_filter` to initialize with filtering pub fn init() -> Result<(), Error> { init_with(Default::default()) } /// Initialize the syslog connection and internal variables. /// /// This should only be called once per process before any other threads have been spawned or any /// signal handlers have been registered. Every call made after the first will /// panic. /// /// Arguments: /// * filter: See for example filter /// specifications /// * stderr: If set will output to stderr (in addition) /// * file: If set will output to this file (in addition) /// * proc_name: proc name for Syslog implementation /// * syslog_facility: syslog facility /// * file_formatter: custom formatter for file output. See env_logger docs pub fn init_with(cfg: LogConfig) -> Result<(), Error> { let mut state = STATE.lock(); if !state.early_init { panic!("double-init of the logging system is not permitted."); } *state = State::new(cfg)?; // This has no effect if the logging facade was already set. apply_logging_state(&LOGGING_FACADE); Ok(()) } /// Performs early (as in, moment of process start) logging initialization. Any logging prior to /// this call will be SILENTLY discarded. Calling more than once per process will panic. pub fn early_init() { let mut early_init_called = EARLY_INIT_CALLED.lock(); if !*early_init_called { apply_logging_state(&LOGGING_FACADE); *early_init_called = true; } else { panic!("double early init of the logging system is not permitted."); } } /// Test only function that ensures logging has been configured. Since tests /// share module state, we need a way to make sure it has been initialized /// with *some* configuration. pub fn test_only_ensure_inited() -> Result<(), Error> { let mut early_init_called = EARLY_INIT_CALLED.lock(); if !*early_init_called { apply_logging_state(&LOGGING_FACADE); *early_init_called = true; } Ok(()) } fn apply_logging_state(facade: &'static LoggingFacade) { let _ = log::set_logger(facade); log::set_max_level(log::LevelFilter::Trace); } /// Retrieves the file descriptors owned by the global syslogger. /// /// Does nothing if syslog was never initialized. If their are any file descriptors, they will be /// pushed into `fds`. /// /// Note that the `stderr` file descriptor is never added, as it is not owned by syslog. pub fn push_descriptors(fds: &mut Vec) { let state = STATE.lock(); fds.extend(state.descriptors.iter()); } impl Log for State { fn enabled(&self, metadata: &log::Metadata) -> bool { self.filter.enabled(metadata) } fn log(&self, record: &log::Record) { if self.filter.matches(record) { for logger in self.loggers.iter() { logger.log(record) } } } fn flush(&self) { for logger in self.loggers.iter() { logger.flush() } } } // Struct that implements io::Write to be used for writing directly to the syslog pub struct Syslogger<'a> { buf: Vec, level: log::Level, get_state_fn: Box MutexGuard<'a, State> + Send + 'a>, } impl<'a> Syslogger<'a> { pub fn new(level: log::Level) -> Syslogger<'a> { Syslogger { buf: Vec::new(), level, get_state_fn: Box::new(|| STATE.lock()), } } pub fn test_only_from_state MutexGuard<'a, State> + Send>( level: log::Level, get_state_fn: F, ) -> Syslogger<'a> { Syslogger { buf: Vec::new(), level, get_state_fn: Box::new(get_state_fn), } } } impl<'a> io::Write for Syslogger<'a> { fn write(&mut self, buf: &[u8]) -> io::Result { let state = (self.get_state_fn)(); self.buf.extend_from_slice(buf); if let Some(last_newline_idx) = self.buf.iter().rposition(|&x| x == b'\n') { for line in (self.buf[..last_newline_idx]).split(|&x| x == b'\n') { // Also drop CR+LF line endings. let send_line = match line.split_last() { Some((b'\r', trimmed)) => trimmed, _ => line, }; // Match is to explicitly limit lifetime of args // https://github.com/rust-lang/rust/issues/92698 // https://github.com/rust-lang/rust/issues/15023 #[allow(clippy::match_single_binding)] match format_args!("{}", String::from_utf8_lossy(send_line)) { args => { let mut record_builder = log::Record::builder(); record_builder.level(self.level); record_builder.target("syslogger"); record_builder.args(args); let record = record_builder.build(); state.log(&record); } } } self.buf.drain(..=last_newline_idx); } Ok(buf.len()) } fn flush(&mut self) -> io::Result<()> { STATE.lock().flush(); Ok(()) } }