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, render_once, 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 once: the quoting decision and the output come
219            // from the same text.
220            render_once(&lazy, |text| match text {
221                Some(text) => write_str_value(w, text),
222                // Too long for the no-std stack buffer: always quoted,
223                // streamed through the escaper.
224                None => {
225                    w.write_char('"')?;
226                    write!(
227                        HumanEscaper {
228                            inner: &mut *w,
229                            quoted: true,
230                        },
231                        "{lazy}"
232                    )?;
233                    w.write_char('"')
234                }
235            })
236        }
237    }
238}
239
240/// When to colour [`HumanFormat`] output.
241///
242/// Resolved once, when a sink is built, into a plain on/off setting
243/// for [`HumanFormat::color`].
244///
245/// # Examples
246///
247#[cfg_attr(all(feature = "human"), doc = "```")]
248#[cfg_attr(not(all(feature = "human")), doc = "```ignore")]
249/// use log_io::format::{ColorChoice, HumanFormat};
250///
251/// let fmt = HumanFormat::new().color(ColorChoice::Auto.enabled_for_stderr());
252/// # let _ = fmt;
253/// assert!(ColorChoice::Always.resolve(false));
254/// assert!(!ColorChoice::Never.resolve(true));
255/// ```
256#[cfg(feature = "std")]
257#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
258#[non_exhaustive]
259pub enum ColorChoice {
260    /// Colour when the destination is a terminal, honouring the
261    /// conventional environment variables:
262    ///
263    /// * `NO_COLOR` set to a non-empty value disables colour;
264    /// * `CLICOLOR_FORCE` set to a non-empty value other than `0`
265    ///   enables colour even when not a terminal;
266    /// * `TERM=dumb` disables colour.
267    ///
268    /// On Windows, colour is only enabled automatically inside
269    /// terminals known to interpret ANSI sequences without extra setup
270    /// (Windows Terminal, ConEmu, or any environment that sets `TERM`,
271    /// such as Git Bash or MSYS2). The classic console host needs the
272    /// virtual-terminal mode switched on through the Windows API, which
273    /// this crate does not do because it forbids `unsafe` code; use
274    /// [`ColorChoice::Always`] if your program enables that mode itself.
275    #[default]
276    Auto,
277    /// Always colour.
278    Always,
279    /// Never colour.
280    Never,
281}
282
283#[cfg(feature = "std")]
284impl ColorChoice {
285    /// Resolve against an explicit "is the destination a terminal"
286    /// answer and the process environment.
287    #[must_use]
288    pub fn resolve(self, is_terminal: bool) -> bool {
289        self.resolve_with(is_terminal, cfg!(windows), |key| std::env::var_os(key))
290    }
291
292    /// Resolve for the process's standard output.
293    #[must_use]
294    pub fn enabled_for_stdout(self) -> bool {
295        use std::io::IsTerminal;
296        self.resolve(std::io::stdout().is_terminal())
297    }
298
299    /// Resolve for the process's standard error.
300    #[must_use]
301    pub fn enabled_for_stderr(self) -> bool {
302        use std::io::IsTerminal;
303        self.resolve(std::io::stderr().is_terminal())
304    }
305
306    fn resolve_with(
307        self,
308        is_terminal: bool,
309        windows: bool,
310        env: impl Fn(&str) -> Option<std::ffi::OsString>,
311    ) -> bool {
312        let set = |key: &str| env(key).is_some_and(|v| !v.is_empty());
313        match self {
314            Self::Always => true,
315            Self::Never => false,
316            Self::Auto => {
317                if set("NO_COLOR") {
318                    return false;
319                }
320                if env("CLICOLOR_FORCE").is_some_and(|v| !v.is_empty() && v != "0") {
321                    return true;
322                }
323                if !is_terminal || env("TERM").is_some_and(|t| t == "dumb") {
324                    return false;
325                }
326                if windows {
327                    set("WT_SESSION") || set("TERM") || env("ConEmuANSI").is_some_and(|v| v == "ON")
328                } else {
329                    true
330                }
331            }
332        }
333    }
334}
335
336#[cfg(all(test, feature = "std"))]
337mod tests {
338    use super::*;
339    use crate::record::{Field, Metadata};
340
341    fn fmt_one(fmt: HumanFormat, record: &Record<'_>) -> String {
342        let mut s = String::new();
343        fmt.write_record_generic(record, &mut s).unwrap();
344        let mut d = String::new();
345        fmt.write_record(record, &mut d).unwrap();
346        assert_eq!(s, d);
347        s
348    }
349
350    fn field_human(v: Value<'_>) -> String {
351        let fields = [Field::new("v", v)];
352        let record = Record::new(Metadata::new(Level::Info, "t"), "m", &fields);
353        let out = fmt_one(HumanFormat::new(), &record);
354        let start = out.find(" v=").unwrap() + 3;
355        out[start..out.len() - 1].to_string()
356    }
357
358    #[test]
359    fn test_human_level_is_uppercase_padded() {
360        let record = Record::new(Metadata::new(Level::Info, "app"), "hi", &[]);
361        assert_eq!(fmt_one(HumanFormat::new(), &record), "INFO  [app] hi\n");
362        let record = Record::new(Metadata::new(Level::Error, "app"), "hi", &[]);
363        assert_eq!(fmt_one(HumanFormat::new(), &record), "ERROR [app] hi\n");
364    }
365
366    #[test]
367    fn test_human_empty_target_omits_brackets() {
368        let record = Record::new(Metadata::new(Level::Info, ""), "hi", &[]);
369        assert_eq!(
370            fmt_one(HumanFormat::new(), &record),
371            "INFO  hi
372"
373        );
374    }
375
376    #[test]
377    fn test_human_target_can_be_hidden() {
378        let record = Record::new(Metadata::new(Level::Warn, "app"), "hi", &[]);
379        assert_eq!(
380            fmt_one(HumanFormat::new().show_target(false), &record),
381            "WARN  hi\n"
382        );
383    }
384
385    #[test]
386    fn test_human_source_location_optional() {
387        let metadata = Metadata::new(Level::Info, "app").with_location("src/lib.rs", 42);
388        let record = Record::new(metadata, "ok", &[]);
389        let with = fmt_one(HumanFormat::new().show_source_location(true), &record);
390        let without = fmt_one(HumanFormat::new(), &record);
391        assert_eq!(with, "INFO  [app] ok (src/lib.rs:42)\n");
392        assert_eq!(without, "INFO  [app] ok\n");
393    }
394
395    #[test]
396    fn test_human_timestamp_prepended_when_set() {
397        let metadata = Metadata::new(Level::Info, "app").with_timestamp(1_700_000_000_000_000_000);
398        let record = Record::new(metadata, "ok", &[]);
399        assert_eq!(
400            fmt_one(HumanFormat::new(), &record),
401            "2023-11-14T22:13:20.000000000Z INFO  [app] ok\n"
402        );
403    }
404
405    #[test]
406    fn test_human_values_render_per_variant() {
407        assert_eq!(field_human(Value::Null), "<null>");
408        assert_eq!(field_human(Value::Bool(false)), "false");
409        assert_eq!(field_human(Value::I64(-4)), "-4");
410        assert_eq!(field_human(Value::U64(4)), "4");
411        assert_eq!(field_human(Value::I128(-5)), "-5");
412        assert_eq!(field_human(Value::U128(5)), "5");
413        assert_eq!(field_human(Value::F64(2.0)), "2.0");
414        assert_eq!(field_human(Value::F64(f64::NAN)), "NaN");
415        assert_eq!(field_human(Value::Str("")), "\"\"");
416        assert_eq!(field_human(Value::Str("plain")), "plain");
417        assert_eq!(field_human(Value::Str("two words")), "\"two words\"");
418        assert_eq!(field_human(Value::Str("a\"b")), "\"a\\\"b\"");
419        assert_eq!(field_human(Value::Str("a\\b c")), "\"a\\\\b c\"");
420        assert_eq!(field_human(Value::Str("a=b")), "\"a=b\"");
421        assert_eq!(field_human(Value::Str("x\u{1b}y")), "\"x\\x1by\"");
422        assert_eq!(field_human(Value::Char('\n')), "\"\\n\"");
423        assert_eq!(field_human(Value::Char('z')), "z");
424        assert_eq!(field_human(Value::Bytes(&[])), "\"\"");
425        assert_eq!(field_human(Value::Bytes(&[0xab])), "ab");
426        assert_eq!(field_human(Value::Display(&7)), "7");
427        assert_eq!(field_human(Value::Display(&"a b")), "\"a b\"");
428        assert_eq!(field_human(Value::Debug(&"q")), "\"\\\"q\\\"\"");
429        let e = std::io::Error::other("bad\nthing");
430        assert_eq!(field_human(Value::Error(&e)), "\"bad\\nthing\"");
431    }
432
433    #[test]
434    fn test_human_injection_is_neutralized() {
435        // The audit's R04 reproduction.
436        let fields = [
437            Field::new("c", Value::Char('\n')),
438            Field::new("k\u{1b}[2J", 1_u32),
439        ];
440        let record = Record::new(
441            Metadata::new(Level::Info, "t\u{1b}]0;pwn\u{7}"),
442            "msg \u{1b}[31mRED\u{b}VT\u{2028}LS\u{85}NEL",
443            &fields,
444        );
445        let out = fmt_one(HumanFormat::new(), &record);
446        assert_eq!(out.matches('\n').count(), 1, "{out:?}");
447        assert!(!out.contains('\u{1b}'), "{out:?}");
448        assert!(!out.contains('\u{7}'), "{out:?}");
449        assert!(!out.contains('\u{2028}'), "{out:?}");
450        assert!(!out.contains('\u{85}'), "{out:?}");
451        assert_eq!(
452            out,
453            "INFO  [t\\x1b]0;pwn\\x07] msg \\x1b[31mRED\\x0bVT\\u{2028}LS\\u{85}NEL \
454             c=\"\\n\" k_[2J=1\n"
455        );
456    }
457
458    #[test]
459    fn test_human_color_wraps_level_and_target() {
460        let record = Record::new(Metadata::new(Level::Error, "app"), "x", &[]);
461        let out = fmt_one(HumanFormat::new().color(true), &record);
462        assert_eq!(out, "\x1b[31mERROR\x1b[0m \x1b[2m[app]\x1b[0m x\n");
463        assert!(HumanFormat::new().color(true).is_color());
464        assert!(!HumanFormat::new().is_color());
465        for (level, code) in [
466            (Level::Warn, "\x1b[33m"),
467            (Level::Info, "\x1b[32m"),
468            (Level::Debug, "\x1b[34m"),
469            (Level::Trace, "\x1b[35m"),
470        ] {
471            let record = Record::new(Metadata::new(level, "a"), "x", &[]);
472            let out = fmt_one(HumanFormat::new().color(true).show_target(false), &record);
473            assert!(out.starts_with(code), "{out:?}");
474        }
475    }
476
477    fn env_of(
478        vars: &'static [(&'static str, &'static str)],
479    ) -> impl Fn(&str) -> Option<std::ffi::OsString> {
480        move |key| {
481            vars.iter()
482                .find(|(k, _)| *k == key)
483                .map(|(_, v)| std::ffi::OsString::from(v))
484        }
485    }
486
487    #[test]
488    fn test_color_choice_explicit_choices() {
489        assert!(ColorChoice::Always.resolve_with(false, false, env_of(&[])));
490        assert!(!ColorChoice::Never.resolve_with(true, false, env_of(&[])));
491    }
492
493    #[test]
494    fn test_color_choice_auto_unix_rules() {
495        let auto = ColorChoice::Auto;
496        assert!(auto.resolve_with(true, false, env_of(&[])));
497        assert!(!auto.resolve_with(false, false, env_of(&[])));
498        assert!(!auto.resolve_with(true, false, env_of(&[("NO_COLOR", "1")])));
499        assert!(auto.resolve_with(true, false, env_of(&[("NO_COLOR", "")])));
500        assert!(auto.resolve_with(false, false, env_of(&[("CLICOLOR_FORCE", "1")])));
501        assert!(!auto.resolve_with(false, false, env_of(&[("CLICOLOR_FORCE", "0")])));
502        assert!(!auto.resolve_with(
503            false,
504            false,
505            env_of(&[("CLICOLOR_FORCE", "1"), ("NO_COLOR", "1")])
506        ));
507        assert!(!auto.resolve_with(true, false, env_of(&[("TERM", "dumb")])));
508    }
509
510    #[test]
511    fn test_color_choice_auto_windows_rules() {
512        let auto = ColorChoice::Auto;
513        assert!(!auto.resolve_with(true, true, env_of(&[])));
514        assert!(auto.resolve_with(true, true, env_of(&[("WT_SESSION", "abc")])));
515        assert!(auto.resolve_with(true, true, env_of(&[("TERM", "xterm-256color")])));
516        assert!(auto.resolve_with(true, true, env_of(&[("ConEmuANSI", "ON")])));
517        assert!(!auto.resolve_with(false, true, env_of(&[("WT_SESSION", "abc")])));
518    }
519
520    #[test]
521    fn test_color_choice_default_is_auto() {
522        assert_eq!(ColorChoice::default(), ColorChoice::Auto);
523        // The process-environment entry points honour explicit choices
524        // regardless of the terminal and the environment.
525        assert!(ColorChoice::Always.enabled_for_stdout());
526        assert!(ColorChoice::Always.enabled_for_stderr());
527        assert!(!ColorChoice::Never.enabled_for_stdout());
528        assert!(!ColorChoice::Never.enabled_for_stderr());
529        assert!(ColorChoice::Always.resolve(false));
530        assert!(!ColorChoice::Never.resolve(true));
531    }
532}
log_io/format/human.rs

log_io/format/
human.rs
