caesium/
lib.rs

1#![doc = include_str!("../README.md")]
2
3use std::time::{Duration, Instant};
4
5use thiserror::Error;
6
7mod format;
8
9// ---------------------------------------------------------------------------
10// Errors
11// ---------------------------------------------------------------------------
12
13/// Errors returned by [`LoggerBuilder::init`].
14///
15/// This crate uses [`thiserror`] for ergonomic error handling. All errors implement
16/// [`std::error::Error`], [`std::fmt::Debug`], and [`std::fmt::Display`].
17///
18/// [`thiserror`]: https://docs.rs/thiserror
19#[derive(Debug, Error)]
20#[non_exhaustive]
21pub enum LoggerError {
22    /// The global logger was already initialized, whether by an earlier call
23    /// to [`LoggerBuilder::init`] or by another crate.
24    #[error("a global logger is already initialized")]
25    AlreadyInitialized,
26}
27
28// ---------------------------------------------------------------------------
29// Builder
30// ---------------------------------------------------------------------------
31
32/// When lines are colored with their level's color. Passed to
33/// [`LoggerBuilder::color`].
34#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, Default)]
35pub enum ColorChoice {
36    /// Never colors lines, even when stderr is a terminal.
37    Never,
38    /// Colors lines only when stderr supports color, as detected by
39    /// `env_logger`: when stderr is a terminal, following the `NO_COLOR`,
40    /// `CLICOLOR` and `CLICOLOR_FORCE` conventions. The default.
41    #[default]
42    Auto,
43    /// Always colors lines, even when stderr is redirected to a file or a
44    /// pipe.
45    Always,
46}
47
48impl ColorChoice {
49    /// The `env_logger` write style that applies this choice. Kept private
50    /// so `env_logger`'s types stay out of the public API.
51    fn write_style(self) -> env_logger::WriteStyle {
52        match self {
53            Self::Never => env_logger::WriteStyle::Never,
54            Self::Auto => env_logger::WriteStyle::Auto,
55            Self::Always => env_logger::WriteStyle::Always,
56        }
57    }
58}
59
60/// Configures and initializes the global logger, which writes elapsed time,
61/// colored with each level's color when stderr supports it, on top of
62/// [`env_logger`].
63///
64/// `LoggerBuilder` uses a fluent builder pattern. Construct it via [`new`],
65/// configure it with [`level`], [`color`] and [`source_location`], then
66/// initialize it with [`init`]. Each line is written to stderr as described in
67/// [Format](crate#format).
68///
69/// # Example
70///
71/// ```rust
72/// use caesium::{info, LoggerBuilder, LevelFilter};
73///
74/// LoggerBuilder::new()
75///     .level(LevelFilter::Debug)
76///     .init()
77///     .expect("failed to init logger");
78///
79/// info!("Application started");
80/// ```
81///
82/// [`env_logger`]: https://docs.rs/env_logger
83/// [`new`]: LoggerBuilder::new
84/// [`level`]: LoggerBuilder::level
85/// [`color`]: LoggerBuilder::color
86/// [`source_location`]: LoggerBuilder::source_location
87/// [`init`]: LoggerBuilder::init
88#[derive(Debug)]
89#[must_use = "call .init() to enable logging"]
90pub struct LoggerBuilder {
91    level: LevelFilter,
92    format: format::LineFormat,
93}
94
95impl Default for LoggerBuilder {
96    fn default() -> Self {
97        Self::new()
98    }
99}
100
101impl LoggerBuilder {
102    /// Creates a builder with the default level of [`LevelFilter::Info`],
103    /// color set to [`ColorChoice::Auto`] and source location shown.
104    pub fn new() -> Self {
105        Self {
106            level: LevelFilter::Info,
107            format: format::LineFormat::default(),
108        }
109    }
110
111    /// Sets the minimum log level. Returns `self` for chaining.
112    pub fn level(mut self, level: LevelFilter) -> Self {
113        self.level = level;
114        self
115    }
116
117    /// Sets when lines are colored with their level's color. Defaults to
118    /// [`ColorChoice::Auto`]. Returns `self` for chaining.
119    pub fn color(mut self, choice: ColorChoice) -> Self {
120        self.format.color = choice;
121        self
122    }
123
124    /// Shows or hides the source location (`file:line`) on each line. Shown
125    /// by default. Returns `self` for chaining.
126    pub fn source_location(mut self, source_location: bool) -> Self {
127        self.format.source_location = source_location;
128        self
129    }
130
131    /// Initializes the global logger, which writes lines as described in
132    /// [Format](crate#format). Elapsed time on each line is measured from the
133    /// moment this method runs.
134    ///
135    /// # Errors
136    ///
137    /// Only one global logger can exist per process. If one is already
138    /// initialized, whether by an earlier call to this method or by another
139    /// crate, this returns [`LoggerError::AlreadyInitialized`] and changes
140    /// nothing.
141    pub fn init(&self) -> Result<(), LoggerError> {
142        let start = Instant::now();
143        self.env_builder(move || start.elapsed())
144            .try_init()
145            .map_err(|_| LoggerError::AlreadyInitialized)
146    }
147
148    /// Returns the `env_logger` builder that [`init`] initializes globally,
149    /// configured to write to stderr with the level filter and the line
150    /// formatter. `elapsed` returns the elapsed time shown on each line.
151    ///
152    /// Kept separate from [`init`] so tests can redirect it to a pipe, fix the
153    /// elapsed time and exercise the whole pipeline without touching the
154    /// global logger.
155    ///
156    /// [`init`]: LoggerBuilder::init
157    fn env_builder(
158        &self,
159        elapsed: impl Fn() -> Duration + Send + Sync + 'static,
160    ) -> env_logger::Builder {
161        let formatter = format::LineFormatter::new(self.format, elapsed);
162
163        let mut builder = env_logger::Builder::new();
164        builder.target(env_logger::Target::Stderr);
165        builder.filter_level(self.level);
166        builder.write_style(self.format.color.write_style());
167        builder.format(move |buf, record| formatter.format(buf, record));
168        builder
169    }
170}
171
172// ---------------------------------------------------------------------------
173// Re-exports
174// ---------------------------------------------------------------------------
175
176// The crate docs (README "Usage") explain why these are re-exported; a doc
177// comment here would be prepended to `LevelFilter`'s own page.
178pub use log::LevelFilter;
179pub use log::{debug, error, info, trace, warn};
180
181// ---------------------------------------------------------------------------
182// Tests
183// ---------------------------------------------------------------------------
184
185#[cfg(test)]
186mod tests {
187    use super::*;
188    use env_logger::Target;
189    use log::{Level, Log, Record};
190    use std::io::Write;
191    use std::sync::{Arc, Mutex};
192
193    /// A cloneable in-memory sink handed to `env_logger` as a pipe target.
194    #[derive(Clone, Default)]
195    struct Capture(Arc<Mutex<Vec<u8>>>);
196
197    impl Capture {
198        fn contents(&self) -> String {
199            String::from_utf8(self.0.lock().unwrap().clone()).unwrap()
200        }
201    }
202
203    impl Write for Capture {
204        fn write(&mut self, data: &[u8]) -> std::io::Result<usize> {
205            self.0.lock().unwrap().write(data)
206        }
207
208        fn flush(&mut self) -> std::io::Result<()> {
209            Ok(())
210        }
211    }
212
213    /// Builds the same pipeline `init` initializes, but writing to a capture
214    /// buffer instead of becoming the global logger, with every line showing
215    /// `elapsed`.
216    fn piped(builder: &LoggerBuilder, elapsed: Duration) -> (env_logger::Logger, Capture) {
217        let capture = Capture::default();
218        let env_logger = builder
219            .env_builder(move || elapsed)
220            .target(Target::Pipe(Box::new(capture.clone())))
221            .build();
222        (env_logger, capture)
223    }
224
225    fn emit(log: &impl Log, level: Level, message: &str) {
226        log.log(
227            &Record::builder()
228                .level(level)
229                .target("my_crate")
230                .file(Some("src/lib.rs"))
231                .line(Some(42))
232                .args(format_args!("{message}"))
233                .build(),
234        );
235    }
236
237    fn lines(capture: &Capture) -> Vec<String> {
238        capture.contents().lines().map(str::to_owned).collect()
239    }
240
241    #[test]
242    fn test_default_level_filters_below_info() {
243        let (log, capture) = piped(&LoggerBuilder::new(), Duration::ZERO);
244
245        emit(&log, Level::Trace, "dropped");
246        emit(&log, Level::Debug, "dropped");
247        emit(&log, Level::Info, "kept");
248        emit(&log, Level::Error, "kept too");
249
250        assert_eq!(
251            lines(&capture),
252            [
253                "[00:00:00.000 |  INFO | my_crate | src/lib.rs:42 ] kept",
254                "[00:00:00.000 | ERROR | my_crate | src/lib.rs:42 ] kept too",
255            ]
256        );
257    }
258
259    #[test]
260    fn test_explicit_level_is_applied() {
261        let builder = LoggerBuilder::new().level(LevelFilter::Warn);
262        let (log, capture) = piped(&builder, Duration::ZERO);
263
264        emit(&log, Level::Info, "dropped");
265        emit(&log, Level::Warn, "kept");
266
267        assert_eq!(
268            lines(&capture),
269            ["[00:00:00.000 |  WARN | my_crate | src/lib.rs:42 ] kept"]
270        );
271    }
272
273    #[test]
274    fn test_trace_level_emits_everything() {
275        let builder = LoggerBuilder::new().level(LevelFilter::Trace);
276        let (log, capture) = piped(&builder, Duration::ZERO);
277
278        emit(&log, Level::Trace, "finest");
279
280        assert_eq!(
281            lines(&capture),
282            ["[00:00:00.000 | TRACE | my_crate | src/lib.rs:42 ] finest"]
283        );
284    }
285
286    #[test]
287    fn test_source_location_off_omits_the_segment() {
288        let builder = LoggerBuilder::new().source_location(false);
289        let (log, capture) = piped(&builder, Duration::ZERO);
290
291        emit(&log, Level::Info, "short");
292
293        assert_eq!(
294            lines(&capture),
295            ["[00:00:00.000 |  INFO | my_crate ] short"]
296        );
297    }
298
299    #[test]
300    fn test_elapsed_time_comes_from_the_clock() {
301        let (log, capture) = piped(&LoggerBuilder::new(), Duration::from_millis(125_120));
302
303        emit(&log, Level::Info, "later");
304
305        assert_eq!(
306            lines(&capture),
307            ["[00:02:05.120 |  INFO | my_crate | src/lib.rs:42 ] later"]
308        );
309    }
310
311    /// Whether `text` holds ANSI color codes.
312    fn is_colored(text: &str) -> bool {
313        text.contains('\x1b')
314    }
315
316    #[test]
317    fn test_color_always_colors_a_line_that_is_not_going_to_a_terminal() {
318        // A pipe is never a terminal, so only a forced choice colors it.
319        let builder = LoggerBuilder::new().color(ColorChoice::Always);
320        let (log, capture) = piped(&builder, Duration::ZERO);
321
322        emit(&log, Level::Error, "colored");
323
324        let output = capture.contents();
325        assert!(is_colored(&output), "expected color, got {output:?}");
326        assert!(output.contains("[00:00:00.000 | ERROR | my_crate | src/lib.rs:42 ] colored"));
327    }
328
329    #[test]
330    fn test_color_auto_leaves_a_line_that_is_not_going_to_a_terminal_plain() {
331        let (log, capture) = piped(&LoggerBuilder::new(), Duration::ZERO);
332
333        emit(&log, Level::Error, "plain");
334
335        let output = capture.contents();
336        assert!(!is_colored(&output), "unexpected color in {output:?}");
337    }
338
339    /// Set in the child process started by `run_child`, to the value
340    /// `CHILD_COLORS` gives for its color choice.
341    const STDERR_CHILD: &str = "CAESIUM_STDERR_CHILD";
342
343    /// Every color choice a child process can be given, `None` leaving it
344    /// unset, with the `STDERR_CHILD` value that carries it.
345    const CHILD_COLORS: [(Option<ColorChoice>, &str); 4] = [
346        (None, "unset"),
347        (Some(ColorChoice::Never), "never"),
348        (Some(ColorChoice::Auto), "auto"),
349        (Some(ColorChoice::Always), "always"),
350    ];
351
352    /// Runs only inside the child process started by `run_child`: initializes
353    /// the real global logger with the color choice carried by `STDERR_CHILD`
354    /// and logs one record. Does nothing if run by hand with `--ignored`.
355    #[test]
356    #[ignore = "helper run by test_init_writes_lines_to_stderr_not_stdout and the color tests"]
357    fn stderr_child() {
358        let Some(value) = std::env::var_os(STDERR_CHILD) else {
359            return;
360        };
361        let (color, _) = CHILD_COLORS
362            .into_iter()
363            .find(|(_, name)| value == *name)
364            .unwrap_or_else(|| panic!("unknown color choice {value:?}"));
365        let mut builder = LoggerBuilder::new().source_location(false);
366        if let Some(color) = color {
367            builder = builder.color(color);
368        }
369        builder.init().unwrap();
370        info!("to stderr");
371    }
372
373    /// The streams of a child process that initialized the real global logger
374    /// and logged one record.
375    struct ChildOutput {
376        stdout: String,
377        stderr: String,
378    }
379
380    impl ChildOutput {
381        /// The line the child logged, as written to stderr with any color.
382        fn stderr_line(&self) -> &str {
383            self.stderr
384                .lines()
385                .find(|line| line.contains("to stderr"))
386                .unwrap_or_else(|| panic!("line missing from stderr: {:?}", self.stderr))
387        }
388
389        fn is_colored(&self) -> bool {
390            is_colored(self.stderr_line())
391        }
392    }
393
394    /// Reruns this test binary with only `stderr_child`, so `init` sets up the
395    /// global logger of a fresh process whose streams we can read.
396    ///
397    /// `color` is the child's color choice, `None` to leave it unset. The
398    /// child's stderr is a pipe, never a terminal; `env` adds variables on top
399    /// of a parent environment cleared of every variable that can turn color
400    /// on or off for a pipe, so `CLICOLOR_FORCE` stands in for a terminal that
401    /// supports color.
402    fn run_child(color: Option<ColorChoice>, env: &[(&str, &str)]) -> ChildOutput {
403        let (_, value) = CHILD_COLORS
404            .into_iter()
405            .find(|(choice, _)| *choice == color)
406            .expect("every color choice is in CHILD_COLORS");
407        let output = std::process::Command::new(std::env::current_exe().unwrap())
408            .args(["tests::stderr_child", "--exact", "--ignored", "--nocapture"])
409            .env_remove("NO_COLOR")
410            .env_remove("CLICOLOR")
411            .env_remove("CLICOLOR_FORCE")
412            .env(STDERR_CHILD, value)
413            .envs(env.iter().copied())
414            .output()
415            .unwrap();
416        assert!(output.status.success(), "child failed: {output:?}");
417        ChildOutput {
418            stdout: String::from_utf8(output.stdout).unwrap(),
419            stderr: String::from_utf8(output.stderr).unwrap(),
420        }
421    }
422
423    #[test]
424    fn test_init_writes_lines_to_stderr_not_stdout() {
425        let output = run_child(None, &[]);
426
427        // libtest writes its own report to stdout, so check for the line
428        // itself rather than an empty stdout.
429        assert!(
430            output
431                .stderr_line()
432                .ends_with("|  INFO | caesium::tests ] to stderr"),
433            "{:?}",
434            output.stderr
435        );
436        assert!(
437            !output.stdout.contains("to stderr"),
438            "line written to stdout: {:?}",
439            output.stdout
440        );
441    }
442
443    #[test]
444    fn test_color_auto_colors_lines_when_stderr_supports_color() {
445        let output = run_child(Some(ColorChoice::Auto), &[("CLICOLOR_FORCE", "1")]);
446
447        assert!(output.is_colored(), "{:?}", output.stderr);
448    }
449
450    #[test]
451    fn test_color_auto_leaves_lines_plain_when_stderr_does_not_support_color() {
452        let output = run_child(Some(ColorChoice::Auto), &[]);
453
454        assert!(!output.is_colored(), "{:?}", output.stderr);
455    }
456
457    #[test]
458    fn test_color_auto_respects_no_color() {
459        let output = run_child(
460            Some(ColorChoice::Auto),
461            &[("CLICOLOR_FORCE", "1"), ("NO_COLOR", "1")],
462        );
463
464        assert!(!output.is_colored(), "{:?}", output.stderr);
465    }
466
467    #[test]
468    fn test_color_never_leaves_lines_plain_even_when_stderr_supports_color() {
469        let output = run_child(Some(ColorChoice::Never), &[("CLICOLOR_FORCE", "1")]);
470
471        assert!(!output.is_colored(), "{:?}", output.stderr);
472    }
473
474    #[test]
475    fn test_color_defaults_to_auto() {
476        let output = run_child(None, &[("CLICOLOR_FORCE", "1")]);
477
478        assert!(output.is_colored(), "{:?}", output.stderr);
479    }
480
481    #[test]
482    fn test_init_fails_once_a_logger_is_initialized() {
483        let builder = LoggerBuilder::new();
484
485        // The first call may fail if a parallel test initialized a logger
486        // first; either way, a global logger exists afterwards.
487        let _ = builder.init();
488        let second = builder.init();
489
490        assert!(
491            matches!(second, Err(LoggerError::AlreadyInitialized)),
492            "expected AlreadyInitialized, got {second:?}"
493        );
494    }
495
496    #[test]
497    fn test_already_initialized_has_a_message_and_no_source() {
498        let error = LoggerError::AlreadyInitialized;
499
500        assert_eq!(error.to_string(), "a global logger is already initialized");
501        assert!(std::error::Error::source(&error).is_none());
502    }
503
504    #[test]
505    fn test_builder_implements_debug() {
506        let debug = format!("{:?}", LoggerBuilder::new());
507
508        assert!(debug.starts_with("LoggerBuilder"), "got {debug:?}");
509    }
510}
caesium/lib.rs

caesium/
lib.rs
