log_io/format/
human.rs

1//! Human-readable output format.
2//!
3//! A single-line format for reading logs in a terminal:
4//!
5//! ```text
6//! TIMESTAMP LEVEL [target] message key=value key="quoted value"
7//! ```
8//!
9//! Timestamps are RFC 3339 when present. Levels are upper-case and
10//! padded to five columns.
11
12use core::fmt;
13use core::fmt::Write as _;
14
15use super::Format;
16use super::escape::{HumanEscaper, QuoteScan, value_needs_quotes, write_human_escaped};
17use crate::level::Level;
18use crate::record::Record;
19use crate::value::{Value, write_f64, write_hex};
20
21/// Human-readable formatter.
22///
23/// Message and target are written as-is except that control
24/// characters, DEL, C1 controls, U+2028/U+2029 and bidi controls are
25/// escaped (`\n`, `\x1b`, `\u{85}`, ...), so hostile input can neither
26/// break the one-record-per-line layout nor drive the terminal. Values
27/// are quoted when they are empty or contain whitespace, `=`, `"`, `\`
28/// or a special character. Keys are sanitized: whitespace, `=`, `"` and
29/// special characters become `_`.
30///
31/// Backslashes in unquoted text are not escaped, so a message that
32/// literally contains `\n` renders the same as one containing a
33/// newline. The format is meant for people; use JSON or logfmt where
34/// output must be parsed back exactly.
35///
36/// Colour is off by default. [`HumanFormat::color`] turns ANSI colour
37/// on for the level column (and dims the target); the
38/// `LoggerBuilder::stdout_human` / `stderr_human` shortcuts enable it
39/// automatically when the stream is a terminal (see `ColorChoice`, available
40/// with the `std` feature).
41///
42/// # Examples
43///
44#[cfg_attr(all(feature = "human"), doc = "```")]
45#[cfg_attr(not(all(feature = "human")), doc = "```ignore")]
46/// use log_io::format::{Format, HumanFormat};
47/// use log_io::{Field, Level, Metadata, Record};
48///
49/// let fields = [Field::new("port", 8080_u32), Field::new("note", "two words")];
50/// let record = Record::new(Metadata::new(Level::Info, "app"), "ok\x1b[2J", &fields);
51///
52/// let mut out = String::new();
53/// HumanFormat::new().write_record(&record, &mut out)?;
54/// assert_eq!(out, "INFO  [app] ok\\x1b[2J port=8080 note=\"two words\"\n");
55/// # Ok::<(), core::fmt::Error>(())
56/// ```
57#[derive(Debug, Clone, Copy)]
58pub struct HumanFormat {
59    show_target: bool,
60    show_source_location: bool,
61    color: bool,
62}
63
64impl Default for HumanFormat {
65    fn default() -> Self {
66        Self::new()
67    }
68}
69
70impl HumanFormat {
71    /// New formatter: target shown, source location hidden, no colour.
72    #[must_use]
73    pub const fn new() -> Self {
74        Self {
75            show_target: true,
76            show_source_location: false,
77            color: false,
78        }
79    }
80
81    /// Toggle the `[target]` column. The column is always omitted for
82    /// records with an empty target.
83    #[must_use]
84    pub const fn show_target(mut self, enabled: bool) -> Self {
85        self.show_target = enabled;
86        self
87    }
88
89    /// Toggle the ` (file:line)` suffix for records that carry a source
90    /// location.
91    #[must_use]
92    pub const fn show_source_location(mut self, enabled: bool) -> Self {
93        self.show_source_location = enabled;
94        self
95    }
96
97    /// Toggle ANSI colour: the level is coloured (ERROR red, WARN
98    /// yellow, INFO green, DEBUG blue, TRACE magenta) and the target is
99    /// dimmed. Only the formatter emits escape sequences; user text is
100    /// always escaped, so it cannot add its own.
101    #[must_use]
102    pub const fn color(mut self, enabled: bool) -> Self {
103        self.color = enabled;
104        self
105    }
106
107    /// Whether ANSI colour is enabled.
108    #[must_use]
109    pub const fn is_color(&self) -> bool {
110        self.color
111    }
112
113    // Kept out of line: it runs once per record, and inlining it into
114    // every sink's write path made pipeline timings depend on unrelated
115    // code layout (measured swings of 60% between builds).
116    #[inline(never)]
117    fn write_impl<W: fmt::Write + ?Sized>(&self, record: &Record<'_>, w: &mut W) -> fmt::Result {
118        if let Some(ts) = record.metadata.timestamp_unix_nanos {
119            super::rfc3339::write_rfc3339_nanos(ts, w)?;
120            w.write_char(' ')?;
121        }
122        let level = record.metadata.level;
123        if self.color {
124            w.write_str(level_color(level))?;
125            write!(w, "{:<5}", level.as_str_upper())?;
126            w.write_str(RESET)?;
127            w.write_char(' ')?;
128        } else {
129            write!(w, "{:<5} ", level.as_str_upper())?;
130        }
131        if self.show_target && !record.metadata.target.is_empty() {
132            if self.color {
133                w.write_str(DIM)?;
134            }
135            w.write_char('[')?;
136            write_human_escaped(w, record.metadata.target, false)?;
137            w.write_char(']')?;
138            if self.color {
139                w.write_str(RESET)?;
140            }
141            w.write_char(' ')?;
142        }
143        write_human_escaped(w, record.message, false)?;
144        for field in record.all_fields() {
145            w.write_char(' ')?;
146            super::escape::write_sanitized_key(w, field.key)?;
147            w.write_char('=')?;
148            write_value(w, field.value)?;
149        }
150        if self.show_source_location {
151            if let (Some(file), Some(line)) = (record.metadata.file, record.metadata.line) {
152                w.write_str(" (")?;
153                write_human_escaped(w, file, false)?;
154                write!(w, ":{line})")?;
155            }
156        }
157        w.write_char('\n')
158    }
159}
160
161impl Format for HumanFormat {
162    fn write_record(&self, record: &Record<'_>, writer: &mut dyn fmt::Write) -> fmt::Result {
163        self.write_impl(record, writer)
164    }
165
166    #[inline]
167    fn write_record_generic<W: fmt::Write>(
168        &self,
169        record: &Record<'_>,
170        writer: &mut W,
171    ) -> fmt::Result {
172        self.write_impl(record, writer)
173    }
174}
175
176const RESET: &str = "\x1b[0m";
177const DIM: &str = "\x1b[2m";
178
179const fn level_color(level: Level) -> &'static str {
180    match level {
181        Level::Error => "\x1b[31m",
182        Level::Warn => "\x1b[33m",
183        Level::Info => "\x1b[32m",
184        Level::Debug => "\x1b[34m",
185        Level::Trace => "\x1b[35m",
186        Level::Off => "",
187    }
188}
189
190#[inline]
191fn write_str_value<W: fmt::Write + ?Sized>(w: &mut W, s: &str) -> fmt::Result {
192    if value_needs_quotes(s) {
193        w.write_char('"')?;
194        write_human_escaped(w, s, true)?;
195        w.write_char('"')
196    } else {
197        w.write_str(s)
198    }
199}
200
201fn write_value<W: fmt::Write + ?Sized>(w: &mut W, v: Value<'_>) -> fmt::Result {
202    match v {
203        Value::Null => w.write_str("<null>"),
204        Value::Bool(b) => write!(w, "{b}"),
205        Value::I64(n) => write!(w, "{n}"),
206        Value::U64(n) => write!(w, "{n}"),
207        Value::I128(n) => write!(w, "{n}"),
208        Value::U128(n) => write!(w, "{n}"),
209        Value::F64(n) => write_f64(w, n),
210        Value::Str(s) => write_str_value(w, s),
211        Value::Char(c) => {
212            let mut buf = [0_u8; 4];
213            write_str_value(w, c.encode_utf8(&mut buf))
214        }
215        Value::Bytes([]) => w.write_str("\"\""),
216        Value::Bytes(b) => write_hex(w, b),
217        lazy @ (Value::Display(_) | Value::Debug(_) | Value::Error(_)) => {
218            // Rendered twice: once to decide on quoting, once to write.
219            let quoted = QuoteScan::needs_quotes(&lazy);
220            if quoted {
221                w.write_char('"')?;
222            }
223            write!(
224                HumanEscaper {
225                    inner: &mut *w,
226                    quoted,
227                },
228                "{lazy}"
229            )?;
230            if quoted {
231                w.write_char('"')?;
232            }
233            Ok(())
234        }
235    }
236}
237
238/// When to colour [`HumanFormat`] output.
239///
240/// Resolved once, when a sink is built, into a plain on/off setting
241/// for [`HumanFormat::color`].
242///
243/// # Examples
244///
245#[cfg_attr(all(feature = "human"), doc = "```")]
246#[cfg_attr(not(all(feature = "human")), doc = "```ignore")]
247/// use log_io::format::{ColorChoice, HumanFormat};
248///
249/// let fmt = HumanFormat::new().color(ColorChoice::Auto.enabled_for_stderr());
250/// # let _ = fmt;
251/// assert!(ColorChoice::Always.resolve(false));
252/// assert!(!ColorChoice::Never.resolve(true));
253/// ```
254#[cfg(feature = "std")]
255#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
256#[non_exhaustive]
257pub enum ColorChoice {
258    /// Colour when the destination is a terminal, honouring the
259    /// conventional environment variables:
260    ///
261    /// * `NO_COLOR` set to a non-empty value disables colour;
262    /// * `CLICOLOR_FORCE` set to a non-empty value other than `0`
263    ///   enables colour even when not a terminal;
264    /// * `TERM=dumb` disables colour.
265    ///
266    /// On Windows, colour is only enabled automatically inside
267    /// terminals known to interpret ANSI sequences without extra setup
268    /// (Windows Terminal, ConEmu, or any environment that sets `TERM`,
269    /// such as Git Bash or MSYS2). The classic console host needs the
270    /// virtual-terminal mode switched on through the Windows API, which
271    /// this crate does not do because it forbids `unsafe` code; use
272    /// [`ColorChoice::Always`] if your program enables that mode itself.
273    #[default]
274    Auto,
275    /// Always colour.
276    Always,
277    /// Never colour.
278    Never,
279}
280
281#[cfg(feature = "std")]
282impl ColorChoice {
283    /// Resolve against an explicit "is the destination a terminal"
284    /// answer and the process environment.
285    #[must_use]
286    pub fn resolve(self, is_terminal: bool) -> bool {
287        self.resolve_with(is_terminal, cfg!(windows), |key| std::env::var_os(key))
288    }
289
290    /// Resolve for the process's standard output.
291    #[must_use]
292    pub fn enabled_for_stdout(self) -> bool {
293        use std::io::IsTerminal;
294        self.resolve(std::io::stdout().is_terminal())
295    }
296
297    /// Resolve for the process's standard error.
298    #[must_use]
299    pub fn enabled_for_stderr(self) -> bool {
300        use std::io::IsTerminal;
301        self.resolve(std::io::stderr().is_terminal())
302    }
303
304    fn resolve_with(
305        self,
306        is_terminal: bool,
307        windows: bool,
308        env: impl Fn(&str) -> Option<std::ffi::OsString>,
309    ) -> bool {
310        let set = |key: &str| env(key).is_some_and(|v| !v.is_empty());
311        match self {
312            Self::Always => true,
313            Self::Never => false,
314            Self::Auto => {
315                if set("NO_COLOR") {
316                    return false;
317                }
318                if env("CLICOLOR_FORCE").is_some_and(|v| !v.is_empty() && v != "0") {
319                    return true;
320                }
321                if !is_terminal || env("TERM").is_some_and(|t| t == "dumb") {
322                    return false;
323                }
324                if windows {
325                    set("WT_SESSION") || set("TERM") || env("ConEmuANSI").is_some_and(|v| v == "ON")
326                } else {
327                    true
328                }
329            }
330        }
331    }
332}
333
334#[cfg(all(test, feature = "std"))]
335mod tests {
336    use super::*;
337    use crate::record::{Field, Metadata};
338
339    fn fmt_one(fmt: HumanFormat, record: &Record<'_>) -> String {
340        let mut s = String::new();
341        fmt.write_record_generic(record, &mut s).unwrap();
342        let mut d = String::new();
343        fmt.write_record(record, &mut d).unwrap();
344        assert_eq!(s, d);
345        s
346    }
347
348    fn field_human(v: Value<'_>) -> String {
349        let fields = [Field::new("v", v)];
350        let record = Record::new(Metadata::new(Level::Info, "t"), "m", &fields);
351        let out = fmt_one(HumanFormat::new(), &record);
352        let start = out.find(" v=").unwrap() + 3;
353        out[start..out.len() - 1].to_string()
354    }
355
356    #[test]
357    fn test_human_level_is_uppercase_padded() {
358        let record = Record::new(Metadata::new(Level::Info, "app"), "hi", &[]);
359        assert_eq!(fmt_one(HumanFormat::new(), &record), "INFO  [app] hi\n");
360        let record = Record::new(Metadata::new(Level::Error, "app"), "hi", &[]);
361        assert_eq!(fmt_one(HumanFormat::new(), &record), "ERROR [app] hi\n");
362    }
363
364    #[test]
365    fn test_human_empty_target_omits_brackets() {
366        let record = Record::new(Metadata::new(Level::Info, ""), "hi", &[]);
367        assert_eq!(
368            fmt_one(HumanFormat::new(), &record),
369            "INFO  hi
370"
371        );
372    }
373
374    #[test]
375    fn test_human_target_can_be_hidden() {
376        let record = Record::new(Metadata::new(Level::Warn, "app"), "hi", &[]);
377        assert_eq!(
378            fmt_one(HumanFormat::new().show_target(false), &record),
379            "WARN  hi\n"
380        );
381    }
382
383    #[test]
384    fn test_human_source_location_optional() {
385        let metadata = Metadata::new(Level::Info, "app").with_location("src/lib.rs", 42);
386        let record = Record::new(metadata, "ok", &[]);
387        let with = fmt_one(HumanFormat::new().show_source_location(true), &record);
388        let without = fmt_one(HumanFormat::new(), &record);
389        assert_eq!(with, "INFO  [app] ok (src/lib.rs:42)\n");
390        assert_eq!(without, "INFO  [app] ok\n");
391    }
392
393    #[test]
394    fn test_human_timestamp_prepended_when_set() {
395        let metadata = Metadata::new(Level::Info, "app").with_timestamp(1_700_000_000_000_000_000);
396        let record = Record::new(metadata, "ok", &[]);
397        assert_eq!(
398            fmt_one(HumanFormat::new(), &record),
399            "2023-11-14T22:13:20.000000000Z INFO  [app] ok\n"
400        );
401    }
402
403    #[test]
404    fn test_human_values_render_per_variant() {
405        assert_eq!(field_human(Value::Null), "<null>");
406        assert_eq!(field_human(Value::Bool(false)), "false");
407        assert_eq!(field_human(Value::I64(-4)), "-4");
408        assert_eq!(field_human(Value::U64(4)), "4");
409        assert_eq!(field_human(Value::I128(-5)), "-5");
410        assert_eq!(field_human(Value::U128(5)), "5");
411        assert_eq!(field_human(Value::F64(2.0)), "2.0");
412        assert_eq!(field_human(Value::F64(f64::NAN)), "NaN");
413        assert_eq!(field_human(Value::Str("")), "\"\"");
414        assert_eq!(field_human(Value::Str("plain")), "plain");
415        assert_eq!(field_human(Value::Str("two words")), "\"two words\"");
416        assert_eq!(field_human(Value::Str("a\"b")), "\"a\\\"b\"");
417        assert_eq!(field_human(Value::Str("a\\b c")), "\"a\\\\b c\"");
418        assert_eq!(field_human(Value::Str("a=b")), "\"a=b\"");
419        assert_eq!(field_human(Value::Str("x\u{1b}y")), "\"x\\x1by\"");
420        assert_eq!(field_human(Value::Char('\n')), "\"\\n\"");
421        assert_eq!(field_human(Value::Char('z')), "z");
422        assert_eq!(field_human(Value::Bytes(&[])), "\"\"");
423        assert_eq!(field_human(Value::Bytes(&[0xab])), "ab");
424        assert_eq!(field_human(Value::Display(&7)), "7");
425        assert_eq!(field_human(Value::Display(&"a b")), "\"a b\"");
426        assert_eq!(field_human(Value::Debug(&"q")), "\"\\\"q\\\"\"");
427        let e = std::io::Error::other("bad\nthing");
428        assert_eq!(field_human(Value::Error(&e)), "\"bad\\nthing\"");
429    }
430
431    #[test]
432    fn test_human_injection_is_neutralized() {
433        // The audit's R04 reproduction.
434        let fields = [
435            Field::new("c", Value::Char('\n')),
436            Field::new("k\u{1b}[2J", 1_u32),
437        ];
438        let record = Record::new(
439            Metadata::new(Level::Info, "t\u{1b}]0;pwn\u{7}"),
440            "msg \u{1b}[31mRED\u{b}VT\u{2028}LS\u{85}NEL",
441            &fields,
442        );
443        let out = fmt_one(HumanFormat::new(), &record);
444        assert_eq!(out.matches('\n').count(), 1, "{out:?}");
445        assert!(!out.contains('\u{1b}'), "{out:?}");
446        assert!(!out.contains('\u{7}'), "{out:?}");
447        assert!(!out.contains('\u{2028}'), "{out:?}");
448        assert!(!out.contains('\u{85}'), "{out:?}");
449        assert_eq!(
450            out,
451            "INFO  [t\\x1b]0;pwn\\x07] msg \\x1b[31mRED\\x0bVT\\u{2028}LS\\u{85}NEL \
452             c=\"\\n\" k_[2J=1\n"
453        );
454    }
455
456    #[test]
457    fn test_human_color_wraps_level_and_target() {
458        let record = Record::new(Metadata::new(Level::Error, "app"), "x", &[]);
459        let out = fmt_one(HumanFormat::new().color(true), &record);
460        assert_eq!(out, "\x1b[31mERROR\x1b[0m \x1b[2m[app]\x1b[0m x\n");
461        assert!(HumanFormat::new().color(true).is_color());
462        assert!(!HumanFormat::new().is_color());
463        for (level, code) in [
464            (Level::Warn, "\x1b[33m"),
465            (Level::Info, "\x1b[32m"),
466            (Level::Debug, "\x1b[34m"),
467            (Level::Trace, "\x1b[35m"),
468        ] {
469            let record = Record::new(Metadata::new(level, "a"), "x", &[]);
470            let out = fmt_one(HumanFormat::new().color(true).show_target(false), &record);
471            assert!(out.starts_with(code), "{out:?}");
472        }
473    }
474
475    fn env_of(
476        vars: &'static [(&'static str, &'static str)],
477    ) -> impl Fn(&str) -> Option<std::ffi::OsString> {
478        move |key| {
479            vars.iter()
480                .find(|(k, _)| *k == key)
481                .map(|(_, v)| std::ffi::OsString::from(v))
482        }
483    }
484
485    #[test]
486    fn test_color_choice_explicit_choices() {
487        assert!(ColorChoice::Always.resolve_with(false, false, env_of(&[])));
488        assert!(!ColorChoice::Never.resolve_with(true, false, env_of(&[])));
489    }
490
491    #[test]
492    fn test_color_choice_auto_unix_rules() {
493        let auto = ColorChoice::Auto;
494        assert!(auto.resolve_with(true, false, env_of(&[])));
495        assert!(!auto.resolve_with(false, false, env_of(&[])));
496        assert!(!auto.resolve_with(true, false, env_of(&[("NO_COLOR", "1")])));
497        assert!(auto.resolve_with(true, false, env_of(&[("NO_COLOR", "")])));
498        assert!(auto.resolve_with(false, false, env_of(&[("CLICOLOR_FORCE", "1")])));
499        assert!(!auto.resolve_with(false, false, env_of(&[("CLICOLOR_FORCE", "0")])));
500        assert!(!auto.resolve_with(
501            false,
502            false,
503            env_of(&[("CLICOLOR_FORCE", "1"), ("NO_COLOR", "1")])
504        ));
505        assert!(!auto.resolve_with(true, false, env_of(&[("TERM", "dumb")])));
506    }
507
508    #[test]
509    fn test_color_choice_auto_windows_rules() {
510        let auto = ColorChoice::Auto;
511        assert!(!auto.resolve_with(true, true, env_of(&[])));
512        assert!(auto.resolve_with(true, true, env_of(&[("WT_SESSION", "abc")])));
513        assert!(auto.resolve_with(true, true, env_of(&[("TERM", "xterm-256color")])));
514        assert!(auto.resolve_with(true, true, env_of(&[("ConEmuANSI", "ON")])));
515        assert!(!auto.resolve_with(false, true, env_of(&[("WT_SESSION", "abc")])));
516    }
517
518    #[test]
519    fn test_color_choice_default_is_auto() {
520        assert_eq!(ColorChoice::default(), ColorChoice::Auto);
521        // The process-environment entry points honour explicit choices
522        // regardless of the terminal and the environment.
523        assert!(ColorChoice::Always.enabled_for_stdout());
524        assert!(ColorChoice::Always.enabled_for_stderr());
525        assert!(!ColorChoice::Never.enabled_for_stdout());
526        assert!(!ColorChoice::Never.enabled_for_stderr());
527        assert!(ColorChoice::Always.resolve(false));
528        assert!(!ColorChoice::Never.resolve(true));
529    }
530}
log_io/format/human.rs

log_io/format/
human.rs
