evergreen/osrf/
logging.rs

1//! OpenSRF Syslog
2use crate::date;
3use crate::osrf::conf;
4use crate::util;
5use log;
6use std::cell::RefCell;
7use std::fs;
8use std::io::Write;
9use std::os::unix::net::UnixDatagram;
10use std::process;
11use std::time::{SystemTime, UNIX_EPOCH};
12use syslog;
13
14const SYSLOG_UNIX_PATH: &str = "/dev/log";
15
16// Thread-local version of the current log trace
17thread_local! {
18    static THREAD_LOCAL_LOG_TRACE: RefCell<String> = RefCell::new(Logger::build_log_trace());
19}
20
21/// Main logging structure
22///
23/// NOTE this logs directly to the syslog UNIX path instead of going through
24/// the syslog crate.  This approach gives us much more control.
25pub struct Logger {
26    logfile: conf::LogFile,
27    loglevel: log::LevelFilter,
28    facility: syslog::Facility,
29    activity_facility: syslog::Facility,
30    writer: Option<UnixDatagram>,
31    application: String,
32}
33
34impl Logger {
35    pub fn new(options: &conf::LogOptions) -> Result<Self, String> {
36        let file = match options.log_file() {
37            Some(f) => f,
38            None => return Err("log_file option required".to_string()),
39        };
40
41        let level = match options.log_level() {
42            Some(l) => l,
43            None => &log::LevelFilter::Info,
44        };
45
46        let facility = match options.syslog_facility() {
47            Some(f) => f,
48            None => syslog::Facility::LOG_LOCAL0,
49        };
50
51        let act_facility = options
52            .activity_log_facility()
53            .unwrap_or(syslog::Facility::LOG_LOCAL1);
54
55        Ok(Logger {
56            logfile: file.clone(),
57            loglevel: *level,
58            facility,
59            activity_facility: act_facility,
60            writer: None,
61            application: Logger::find_app_name(),
62        })
63    }
64
65    fn find_app_name() -> String {
66        if let Ok(p) = std::env::current_exe() {
67            if let Some(f) = p.file_name() {
68                if let Some(n) = f.to_str() {
69                    return n.to_string();
70                }
71            }
72        }
73
74        eprintln!("Cannot determine executable name.  See set_application()");
75        "opensrf".to_string()
76    }
77
78    pub fn set_application(&mut self, app: &str) {
79        self.application = app.to_string();
80    }
81
82    pub fn set_loglevel(&mut self, loglevel: log::LevelFilter) {
83        self.loglevel = loglevel
84    }
85
86    pub fn set_facility(&mut self, facility: syslog::Facility) {
87        self.facility = facility;
88    }
89
90    /// Setup our global log handler.
91    ///
92    /// Attempts to connect to syslog unix socket if possible.
93    pub fn init(mut self) -> Result<(), String> {
94        match self.logfile {
95            conf::LogFile::Syslog => {
96                self.writer = match Logger::writer() {
97                    Ok(w) => Some(w),
98                    Err(e) => {
99                        eprintln!("Cannot init Logger: {e}");
100                        return Err(format!("Cannot init Logger: {e}"));
101                    }
102                }
103            }
104            conf::LogFile::Filename(ref name) => {
105                if let Err(e) = fs::File::options().create(true).append(true).open(name) {
106                    let err = format!("Cannot open file for writing: {name} {e}");
107                    eprintln!("{err}");
108                    return Err(err);
109                }
110            }
111            conf::LogFile::Stdout => {}
112        }
113
114        log::set_max_level(self.loglevel);
115
116        if let Err(e) = log::set_boxed_logger(Box::new(self)) {
117            eprintln!("Cannot init Logger: {e}");
118            return Err(format!("Cannot init Logger: {e}"));
119        }
120
121        Ok(())
122    }
123
124    /// Encode the facility and severity as the syslog priority.
125    ///
126    /// Essentially copied from the syslog crate.
127    fn encode_priority(&self, severity: syslog::Severity) -> syslog::Priority {
128        self.facility as u8 | severity as u8
129    }
130
131    pub fn writer() -> Result<UnixDatagram, String> {
132        match UnixDatagram::unbound() {
133            Ok(socket) => match socket.connect(SYSLOG_UNIX_PATH) {
134                Ok(()) => Ok(socket),
135                Err(e) => Err(format!("Cannot connect to unix socket: {e}")),
136            },
137            Err(e) => Err(format!("Cannot connect to unix socket: {e}")),
138        }
139    }
140
141    /// Create a log trace string from the current time and thread id.
142    fn build_log_trace() -> String {
143        let t = SystemTime::now()
144            .duration_since(UNIX_EPOCH)
145            .expect("SystemTime before UNIX EPOCH!");
146
147        format!("{}-{:0>5}", t.as_millis(), util::thread_id())
148    }
149
150    /// Generate and set a thread-local log trace string.
151    pub fn mk_log_trace() {
152        let t = Logger::build_log_trace();
153        Logger::set_log_trace(t);
154    }
155
156    /// Set the thread-local log trace string, typically from
157    /// a log trace found in an opensrf message.
158    pub fn set_log_trace(trace: impl Into<String>) {
159        let trace = trace.into();
160        THREAD_LOCAL_LOG_TRACE.with(|tr| *tr.borrow_mut() = trace);
161    }
162
163    /// Returns a clone of the current log trace.
164    ///
165    /// Cloning required here.
166    pub fn get_log_trace() -> String {
167        let mut trace: Option<String> = None;
168        THREAD_LOCAL_LOG_TRACE.with(|tr| trace = Some((*tr.borrow()).to_string()));
169        trace.unwrap()
170    }
171}
172
173impl log::Log for Logger {
174    fn enabled(&self, metadata: &log::Metadata) -> bool {
175        metadata.level().to_level_filter() <= self.loglevel
176    }
177
178    fn log(&self, record: &log::Record) {
179        if !self.enabled(record.metadata()) {
180            return;
181        }
182
183        let mut levelname = record.level().to_string();
184        let target = if !record.target().is_empty() {
185            record.target()
186        } else {
187            record.module_path().unwrap_or_default()
188        };
189
190        // HACK to avoid logging content from the rustyline crate, which
191        // is quite chatty.  If this list grows, consider alternative
192        // approaches to specifying which module's logs we want to
193        // handle.
194        if target.starts_with("rustyline") {
195            return;
196        }
197
198        let mut logmsg = record.args().to_string();
199
200        // This is a hack to support ACTIVITY logging via the existing
201        // log::* macros.  Ideally we could use e.g. Notice instead.
202        // https://github.com/rust-lang/log/issues/334
203        let severity = if format!("{}", record.args()).starts_with("ACT:") {
204            // Remove the ACT: tag since it will also be present in the
205            // syslog level.
206            logmsg = logmsg[4..].to_string();
207            levelname = String::from("ACT");
208            let facility = self.activity_facility;
209            facility as u8 | syslog::Severity::LOG_INFO as u8
210        } else {
211            self.encode_priority(match levelname.as_str() {
212                "DEBUG" | "TRACE" => syslog::Severity::LOG_DEBUG,
213                "INFO" => syslog::Severity::LOG_INFO,
214                "WARN" => syslog::Severity::LOG_WARNING,
215                _ => syslog::Severity::LOG_ERR,
216            })
217        };
218
219        let mut message = format!(
220            "{}{} [{}:{}:{}:{}",
221            match self.writer.is_some() {
222                true => format!("<{}>", severity),
223                _ => date::now().format("%F %T%.3f").to_string() + " ",
224            },
225            &self.application,
226            levelname,
227            process::id(),
228            target,
229            record.line().unwrap_or_default()
230        );
231
232        // Add the thread-local log trace
233        THREAD_LOCAL_LOG_TRACE.with(|tr| message += &format!(":{}] ", *tr.borrow()));
234
235        message += &logmsg;
236
237        if let Some(ref w) = self.writer {
238            if w.send(message.as_bytes()).is_ok() {
239                return;
240            }
241        } else if let conf::LogFile::Filename(ref name) = self.logfile {
242            if let Ok(mut file) = fs::File::options().create(true).append(true).open(name) {
243                message += "\n";
244                if file.write_all(message.as_bytes()).is_ok() {
245                    return;
246                }
247            }
248        }
249
250        // If all else fails, print the log message.
251        // We also end up here if our log file is "stdout"
252        println!("{message}");
253    }
254
255    fn flush(&self) {}
256}