log4rs/encode/pattern/
mod.rs

1//! A simple pattern-based encoder.
2//!
3//! Requires the `pattern_encoder` feature.
4//!
5//! The pattern syntax is similar to Rust's string formatting syntax. It
6//! consists of raw text interspersed with format arguments. The grammar is:
7//!
8//! ```not_rust
9//! format_string := <text> [ format <text> ] *
10//! format := '{' formatter [ ':' format_spec ] '}'
11//! formatter := [ name ] [ '(' argument ')' ] *
12//! name := identifier
13//! argument := format_string
14//!
15//! format_spec := [ [ fill ] align ] [left_truncate] [ min_width ] [ '.' max_width ]
16//! fill := character
17//! align := '<' | '>'
18//! min_width := number
19//! max_width := number
20//! left_truncate := '-'
21//! ```
22//!
23//! # Special characters
24//!
25//! The `{`, `}`, `(`, `)`, and `\` characters are part of the pattern syntax;
26//! they must be escaped to appear in output. Like with Rust's string
27//! formatting syntax, type the character twice to escape it. That is, `{{`
28//! will be rendered as `{` in output and `))` will be rendered as `)`.
29//!
30//! In addition, these characters may also be escaped by prefixing them with a
31//! `\` character. That is, `\{` will be rendered as `{`.
32//!
33//! # Formatters
34//!
35//! A formatter inserts a dynamic portion of text into the pattern. It may be
36//! text derived from a log event or from some other context like the current
37//! time. Formatters may be passed arguments consisting of parenthesized format
38//! strings.
39//!
40//! The following formatters are currently supported. Unless otherwise stated,
41//! a formatter does not accept any argument.
42//!
43//! * `d`, `date` - The current time. By default, the ISO 8601 format is used.
44//!     A custom format may be provided in the syntax accepted by `chrono`.
45//!     The timezone defaults to local, but can be specified explicitly by
46//!     passing a second argument of `utc` for UTC or `local` for local time.
47//!     * `{d}` - `2016-03-20T14:22:20.644420340-08:00`
48//!     * `{d(%Y-%m-%d %H:%M:%S)}` - `2016-03-20 14:22:20`
49//!     * `{d(%Y-%m-%d %H:%M:%S %Z)(utc)}` - `2016-03-20 22:22:20 UTC`
50//! * `f`, `file` - The source file that the log message came from, or `???` if
51//!     not provided.
52//! * `h`, `highlight` - Styles its argument according to the log level. The
53//!     style is intense red for errors, red for warnings, blue for info, and
54//!     the default style for all other levels.
55//!     * `{h(the level is {l})}` -
56//!         <code style="color: red; font-weight: bold">the level is ERROR</code>
57//! * `D`, `debug` - Outputs its arguments ONLY in debug build.
58//! * `R`, `release` - Outputs its arguments ONLY in release build.
59//! * `l`, `level` - The log level.
60//! * `L`, `line` - The line that the log message came from, or `???` if not
61//!     provided.
62//! * `m`, `message` - The log message.
63//! * `M`, `module` - The module that the log message came from, or `???` if not
64//!     provided.
65//! * `P`, `pid` - The current process id.
66//! * `i`, `tid` - The current system-wide unique thread ID.
67//! * `n` - A platform-specific newline.
68//! * `t`, `target` - The target of the log message.
69//! * `T`, `thread` - The name of the current thread.
70//! * `I`, `thread_id` - The pthread ID of the current thread.
71//! * `X`, `mdc` - A value from the [MDC][MDC]. The first argument specifies
72//!     the key, and the second argument specifies the default value if the
73//!     key is not present in the MDC. The second argument is optional, and
74//!     defaults to the empty string.
75//!     * `{X(user_id)}` - `123e4567-e89b-12d3-a456-426655440000`
76//!     * `{X(nonexistent_key)(no mapping)}` - `no mapping`
77//! * `K`, `key_value` - A value from a [log::kv][log_kv] structured logging
78//!     record attributes. The first argument specifies the key, and the second
79//!     argument specifies the default value if the key is not present in the
80//!     log record's attributes. The second argument is optional, and defaults
81//!     to the empty string. This formatter requires the `log_kv` feature to be
82//!     enabled.
83//!     * `{K(user_id)}` - `123e4567-e89b-12d3-a456-426655440000`
84//!     * `{K(nonexistent_key)(no mapping)}` - `no mapping`
85//! * An "unnamed" formatter simply formats its argument, applying the format
86//!     specification.
87//!     * `{({l} {m})}` - `INFO hello`
88//!
89//! # Format Specification
90//!
91//! The format specification determines how the output of a formatter is
92//! adjusted before being returned.
93//!
94//! ## Fill/Alignment
95//!
96//! The fill and alignment values are used in conjunction with a minimum width
97//! value (see below) to control the behavior when a formatter's output is less
98//! than the minimum. While the default behavior is to pad the output to the
99//! right with space characters (i.e. left align it), the fill value specifies
100//! the character used, and the alignment value is one of:
101//!
102//! * `<` - Left align by appending the fill character to the formatter output
103//! * `>` - Right align by prepending the fill character to the formatter
104//!     output.
105//!
106//! ## Width
107//!
108//! By default, the full contents of a formatter's output will be inserted into
109//! the pattern output, but both the minimum and maximum lengths can be
110//! configured. Any output over the maximum length will be truncated, and
111//! output under the minimum length will be padded (see above).
112//!
113//! Truncation will cut the right end of the contents, unless left truncation
114//! is specified (with a minus sign). Left/right truncation and left/right
115//! alignment are specified independently.
116//!
117//! # Examples
118//!
119//! The default pattern is `{d} {l} {t} - {m}{n}` which produces output like
120//! `2016-03-20T22:22:20.644420340+00:00 INFO module::path - this is a log
121//! message`.
122//!
123//! The pattern `{m:>10.15}` will right-align the log message to a minimum of
124//! 10 bytes, filling in with space characters, and truncate output after 15
125//! bytes. The message `hello` will therefore be displayed as
126//! <code>     hello</code>, while the message `hello there, world!` will be
127//! displayed as `hello there, wo`.
128//!
129//! The pattern `{({l} {m}):15.15}` will output the log level and message
130//! limited to exactly 15 bytes, padding with space characters on the right if
131//! necessary. The message `hello` and log level `INFO` will be displayed as
132//! <code>INFO hello     </code>, while the message `hello, world!` and log
133//! level `DEBUG` will be truncated to `DEBUG hello, wo`.
134//!
135//! The pattern `{({l} {m}):-15.15}` will behave as above, except the truncation
136//! will be from the left. For example, at `DEBUG` level, and a message of
137//! `hello, world!`, the output will be: `G hello, world!`
138//!
139//! [MDC]: https://crates.io/crates/log-mdc
140//! [log_kv]: https://docs.rs/log/latest/log/kv/index.html
141
142use chrono::{Local, Utc};
143use derive_more::Debug;
144use log::{Level, Record};
145use std::{default::Default, io, mem, process, thread};
146use unicode_segmentation::{GraphemeCursor, UnicodeSegmentation};
147
148use crate::encode::{
149    self,
150    pattern::parser::{Alignment, Parameters, Parser, Piece},
151    Color, Encode, Style, NEWLINE,
152};
153
154#[cfg(feature = "config_parsing")]
155use crate::config::{Deserialize, Deserializers};
156
157use self::parser::Formatter;
158
159mod parser;
160
161thread_local!(
162    /// Thread-locally cached thread ID.
163    static TID: usize = thread_id::get()
164);
165
166/// The pattern encoder's configuration.
167#[cfg(feature = "config_parsing")]
168#[derive(Clone, Eq, PartialEq, Hash, Debug, Default, serde::Deserialize)]
169#[serde(deny_unknown_fields)]
170pub struct PatternEncoderConfig {
171    pattern: Option<String>,
172}
173
174#[derive(Clone, Eq, PartialEq, Hash, Debug)]
175enum Chunk {
176    Text(String),
177    Formatted {
178        chunk: FormattedChunk,
179        params: Parameters,
180    },
181    Error(String),
182}
183
184impl Chunk {
185    fn encode(&self, w: &mut dyn encode::Write, record: &Record) -> io::Result<()> {
186        match *self {
187            Chunk::Text(ref s) => w.write_all(s.as_bytes()),
188            Chunk::Formatted {
189                ref chunk,
190                ref params,
191            } => match (params.min_width, params.max_width) {
192                (None, None) => chunk.encode(w, record),
193                _ => {
194                    let mut w = StringBasedWriter::new(w, params);
195                    chunk.encode(&mut w, record)?;
196                    w.chunk_end()
197                }
198            },
199            Chunk::Error(ref s) => write!(w, "{{ERROR: {}}}", s),
200        }
201    }
202}
203
204impl<'a> From<Piece<'a>> for Chunk {
205    fn from(piece: Piece<'a>) -> Chunk {
206        match piece {
207            Piece::Text(text) => Chunk::Text(text.to_owned()),
208            Piece::Argument {
209                mut formatter,
210                parameters,
211            } => match formatter.name {
212                "d" | "date" => {
213                    if formatter.args.len() > 2 {
214                        return Chunk::Error("expected at most two arguments".to_owned());
215                    }
216
217                    let format = match formatter.args.first() {
218                        Some(arg) => {
219                            let mut format = String::new();
220                            for piece in arg {
221                                match *piece {
222                                    Piece::Text(text) => format.push_str(text),
223                                    Piece::Argument { .. } => {
224                                        format.push_str("{ERROR: unexpected formatter}");
225                                    }
226                                    Piece::Error(ref err) => {
227                                        format.push_str("{ERROR: ");
228                                        format.push_str(err);
229                                        format.push('}');
230                                    }
231                                }
232                            }
233                            format
234                        }
235                        None => "%+".to_owned(),
236                    };
237
238                    let timezone = match formatter.args.get(1) {
239                        Some(arg) => {
240                            if let Some(arg) = arg.first() {
241                                match *arg {
242                                    Piece::Text("utc") => Timezone::Utc,
243                                    Piece::Text("local") => Timezone::Local,
244                                    Piece::Text(z) => {
245                                        return Chunk::Error(format!("invalid timezone `{}`", z));
246                                    }
247                                    _ => return Chunk::Error("invalid timezone".to_owned()),
248                                }
249                            } else {
250                                return Chunk::Error("invalid timezone".to_owned());
251                            }
252                        }
253                        None => Timezone::Local,
254                    };
255
256                    Chunk::Formatted {
257                        chunk: FormattedChunk::Time(format, timezone),
258                        params: parameters,
259                    }
260                }
261                "h" | "highlight" => {
262                    if formatter.args.len() != 1 {
263                        return Chunk::Error("expected exactly one argument".to_owned());
264                    }
265
266                    let chunks = formatter
267                        .args
268                        .pop()
269                        .unwrap()
270                        .into_iter()
271                        .map(From::from)
272                        .collect();
273                    Chunk::Formatted {
274                        chunk: FormattedChunk::Highlight(chunks),
275                        params: parameters,
276                    }
277                }
278                "D" | "debug" => {
279                    if formatter.args.len() != 1 {
280                        return Chunk::Error("expected exactly one argument".to_owned());
281                    }
282
283                    let chunks = formatter
284                        .args
285                        .pop()
286                        .unwrap()
287                        .into_iter()
288                        .map(From::from)
289                        .collect();
290                    Chunk::Formatted {
291                        chunk: FormattedChunk::Debug(chunks),
292                        params: parameters,
293                    }
294                }
295                "R" | "release" => {
296                    if formatter.args.len() != 1 {
297                        return Chunk::Error("expected exactly one argument".to_owned());
298                    }
299
300                    let chunks = formatter
301                        .args
302                        .pop()
303                        .unwrap()
304                        .into_iter()
305                        .map(From::from)
306                        .collect();
307                    Chunk::Formatted {
308                        chunk: FormattedChunk::Release(chunks),
309                        params: parameters,
310                    }
311                }
312                "l" | "level" => no_args(&formatter.args, parameters, FormattedChunk::Level),
313                "m" | "message" => no_args(&formatter.args, parameters, FormattedChunk::Message),
314                "M" | "module" => no_args(&formatter.args, parameters, FormattedChunk::Module),
315                "n" => no_args(&formatter.args, parameters, FormattedChunk::Newline),
316                "f" | "file" => no_args(&formatter.args, parameters, FormattedChunk::File),
317                "L" | "line" => no_args(&formatter.args, parameters, FormattedChunk::Line),
318                "T" | "thread" => no_args(&formatter.args, parameters, FormattedChunk::Thread),
319                "I" | "thread_id" => no_args(&formatter.args, parameters, FormattedChunk::ThreadId),
320                "P" | "pid" => no_args(&formatter.args, parameters, FormattedChunk::ProcessId),
321                "i" | "tid" => no_args(&formatter.args, parameters, FormattedChunk::SystemThreadId),
322                "t" | "target" => no_args(&formatter.args, parameters, FormattedChunk::Target),
323                "X" | "mdc" => match kv_parsing(&formatter) {
324                    Err(e) => Chunk::Error(format!("MDC: {e}")),
325                    Ok((key, default)) => Chunk::Formatted {
326                        chunk: FormattedChunk::Mdc(key, default),
327                        params: parameters,
328                    },
329                },
330                #[cfg(feature = "log_kv")]
331                "K" | "key_value" => match kv_parsing(&formatter) {
332                    Err(e) => Chunk::Error(format!("key_value: {e}")),
333                    Ok((key, default)) => Chunk::Formatted {
334                        chunk: FormattedChunk::Kv(key, default),
335                        params: parameters,
336                    },
337                },
338                #[cfg(not(feature = "log_kv"))]
339                "K" | "key_value" => Chunk::Error(
340                    "The log_kv feature is required to parse the key_value argument".to_owned(),
341                ),
342                "" => {
343                    if formatter.args.len() != 1 {
344                        return Chunk::Error("expected exactly one argument".to_owned());
345                    }
346
347                    let chunks = formatter
348                        .args
349                        .pop()
350                        .unwrap()
351                        .into_iter()
352                        .map(From::from)
353                        .collect();
354                    Chunk::Formatted {
355                        chunk: FormattedChunk::Align(chunks),
356                        params: parameters,
357                    }
358                }
359                name => Chunk::Error(format!("unknown formatter `{}`", name)),
360            },
361            Piece::Error(err) => Chunk::Error(err),
362        }
363    }
364}
365
366enum StringOrStyle {
367    String { glen: usize, s: String }, //glen means length in graphemes
368    Style(Style),
369}
370
371struct StringBasedWriter<'writer, 'params> {
372    buf: Vec<u8>,
373    strings_and_styles: Vec<StringOrStyle>,
374    w: &'writer mut dyn encode::Write,
375    params: &'params Parameters,
376}
377
378impl encode::Write for StringBasedWriter<'_, '_> {
379    fn set_style(&mut self, style: &Style) -> io::Result<()> {
380        self.push_string();
381        self.strings_and_styles
382            .push(StringOrStyle::Style(style.clone()));
383        Ok(())
384    }
385}
386
387impl io::Write for StringBasedWriter<'_, '_> {
388    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
389        self.buf.extend_from_slice(buf);
390        Ok(buf.len())
391    }
392
393    fn flush(&mut self) -> io::Result<()> {
394        Ok(())
395    }
396}
397
398impl<'writer, 'params> StringBasedWriter<'writer, 'params> {
399    fn new(w: &'writer mut dyn encode::Write, params: &'params Parameters) -> Self {
400        StringBasedWriter {
401            buf: Vec::new(),
402            strings_and_styles: Vec::new(),
403            w,
404            params,
405        }
406    }
407
408    fn push_string(&mut self) {
409        if !self.buf.is_empty() {
410            let old_buf = mem::take(&mut self.buf);
411            let s = String::from_utf8_lossy(&old_buf[..]).into_owned();
412            let glen = s.graphemes(true).count();
413            self.strings_and_styles
414                .push(StringOrStyle::String { glen, s });
415        }
416    }
417
418    fn chunk_end(&mut self) -> io::Result<()> {
419        self.push_string();
420        let total_width = self.compute_width();
421        let mut done = false;
422        if let Some(max_width) = self.params.max_width {
423            if total_width > max_width {
424                if self.params.right_truncate {
425                    self.output_right_truncate(max_width)?;
426                } else {
427                    self.output_left_truncate(total_width, max_width)?;
428                }
429                done = true;
430            }
431        }
432        if let Some(min_width) = self.params.min_width {
433            if total_width < min_width {
434                if self.params.align == Alignment::Left {
435                    self.output_everything()?;
436                    self.output_padding(min_width - total_width)?;
437                } else {
438                    self.output_padding(min_width - total_width)?;
439                    self.output_everything()?;
440                }
441                done = true;
442            }
443        }
444        if !done {
445            // between min and max length
446            self.output_everything()?;
447        }
448        Ok(())
449    }
450
451    fn compute_width(&self) -> usize {
452        let mut size = 0;
453        for x in &self.strings_and_styles {
454            if let StringOrStyle::String { glen, s: _ } = x {
455                size += glen;
456            }
457        }
458        size
459    }
460
461    fn output_left_truncate(&mut self, total_width: usize, max_width: usize) -> io::Result<()> {
462        let mut to_cut = total_width - max_width;
463        for x in &self.strings_and_styles {
464            match x {
465                StringOrStyle::String { glen, s } => {
466                    if to_cut == 0 {
467                        self.w.write_all(s.as_bytes())?;
468                    } else if *glen <= to_cut {
469                        to_cut -= glen;
470                    } else {
471                        let start = Self::boundary_or(s, to_cut, 0);
472                        self.w.write_all(&s.as_bytes()[start..])?;
473                        to_cut = 0;
474                    }
475                }
476                StringOrStyle::Style(s) => self.w.set_style(s)?,
477            }
478        }
479        Ok(())
480    }
481
482    fn boundary_or(s: &str, count: usize, or: usize) -> usize {
483        let mut cursor = GraphemeCursor::new(0, s.len(), true);
484        let mut start = 0;
485        for _i in 0..count {
486            let r = cursor.next_boundary(s, 0);
487            if let Ok(Some(x)) = r {
488                start = x;
489            } else {
490                // this should never happen, as we sanitize with to_utf8_lossy
491                // but we don't assume so: we'll use the default, which will conservatively
492                // output everything instead of trying to cut
493                start = or;
494                break;
495            }
496        }
497        start
498    }
499
500    fn output_right_truncate(&mut self, mut max_width: usize) -> io::Result<()> {
501        for x in &self.strings_and_styles {
502            match x {
503                StringOrStyle::String { glen, s } => {
504                    if *glen <= max_width {
505                        self.w.write_all(s.as_bytes())?;
506                        max_width -= glen;
507                    } else {
508                        let end = Self::boundary_or(s, max_width, s.len());
509                        self.w.write_all(&s.as_bytes()[0..end])?;
510                        max_width = 0;
511                    }
512                    if max_width == 0 {
513                        break;
514                    }
515                }
516                StringOrStyle::Style(s) => self.w.set_style(s)?,
517            }
518        }
519        Ok(())
520    }
521
522    fn output_everything(&mut self) -> io::Result<()> {
523        for x in &self.strings_and_styles {
524            match x {
525                StringOrStyle::String { glen: _, s } => self.w.write_all(s.as_bytes())?,
526                StringOrStyle::Style(s) => self.w.set_style(s)?,
527            }
528        }
529        Ok(())
530    }
531
532    fn output_padding(&mut self, len: usize) -> io::Result<()> {
533        for _i in 0..len {
534            write!(self.w, "{}", self.params.fill)?;
535        }
536        Ok(())
537    }
538}
539
540fn no_args(arg: &[Vec<Piece>], params: Parameters, chunk: FormattedChunk) -> Chunk {
541    if arg.is_empty() {
542        Chunk::Formatted { chunk, params }
543    } else {
544        Chunk::Error("unexpected arguments".to_owned())
545    }
546}
547
548fn kv_parsing<'a>(formatter: &'a Formatter) -> Result<(String, String), &'a str> {
549    if formatter.args.len() > 2 {
550        return Err("expected at most two arguments");
551    }
552
553    let key = match formatter.args.first() {
554        Some(arg) => {
555            if let Some(arg) = arg.first() {
556                match arg {
557                    Piece::Text(key) => key.to_owned(),
558                    Piece::Error(ref e) => return Err(e),
559                    _ => return Err("invalid key"),
560                }
561            } else {
562                return Err("invalid key");
563            }
564        }
565        None => return Err("missing key"),
566    };
567
568    let default = match formatter.args.get(1) {
569        Some(arg) => {
570            if let Some(arg) = arg.first() {
571                match arg {
572                    Piece::Text(key) => key.to_owned(),
573                    Piece::Error(ref e) => return Err(e),
574                    _ => return Err("invalid default"),
575                }
576            } else {
577                return Err("invalid default");
578            }
579        }
580        None => "",
581    };
582    Ok((key.into(), default.into()))
583}
584
585#[derive(Clone, Eq, PartialEq, Hash, Debug)]
586enum Timezone {
587    Utc,
588    Local,
589}
590
591#[derive(Clone, Eq, PartialEq, Hash, Debug)]
592enum FormattedChunk {
593    Time(String, Timezone),
594    Level,
595    Message,
596    Module,
597    File,
598    Line,
599    Thread,
600    ThreadId,
601    ProcessId,
602    SystemThreadId,
603    Target,
604    Newline,
605    Align(Vec<Chunk>),
606    Highlight(Vec<Chunk>),
607    Debug(Vec<Chunk>),
608    Release(Vec<Chunk>),
609    Mdc(String, String),
610    #[cfg(feature = "log_kv")]
611    Kv(String, String),
612}
613
614impl FormattedChunk {
615    fn encode(&self, w: &mut dyn encode::Write, record: &Record) -> io::Result<()> {
616        match *self {
617            FormattedChunk::Time(ref fmt, Timezone::Utc) => write!(w, "{}", Utc::now().format(fmt)),
618            FormattedChunk::Time(ref fmt, Timezone::Local) => {
619                write!(w, "{}", Local::now().format(fmt))
620            }
621            FormattedChunk::Level => write!(w, "{}", record.level()),
622            FormattedChunk::Message => w.write_fmt(*record.args()),
623            FormattedChunk::Module => w.write_all(record.module_path().unwrap_or("???").as_bytes()),
624            FormattedChunk::File => w.write_all(record.file().unwrap_or("???").as_bytes()),
625            FormattedChunk::Line => match record.line() {
626                Some(line) => write!(w, "{}", line),
627                None => w.write_all(b"???"),
628            },
629            FormattedChunk::Thread => {
630                w.write_all(thread::current().name().unwrap_or("unnamed").as_bytes())
631            }
632            FormattedChunk::ThreadId => w.write_all(thread_id::get().to_string().as_bytes()),
633            FormattedChunk::ProcessId => w.write_all(process::id().to_string().as_bytes()),
634            FormattedChunk::SystemThreadId => {
635                TID.with(|tid| w.write_all(tid.to_string().as_bytes()))
636            }
637            FormattedChunk::Target => w.write_all(record.target().as_bytes()),
638            FormattedChunk::Newline => w.write_all(NEWLINE.as_bytes()),
639            FormattedChunk::Align(ref chunks) => {
640                for chunk in chunks {
641                    chunk.encode(w, record)?;
642                }
643                Ok(())
644            }
645            FormattedChunk::Highlight(ref chunks) => {
646                match record.level() {
647                    Level::Error => {
648                        w.set_style(Style::new().text(Color::Red).intense(true))?;
649                    }
650                    Level::Warn => w.set_style(Style::new().text(Color::Yellow))?,
651                    Level::Info => w.set_style(Style::new().text(Color::Green))?,
652                    Level::Trace => w.set_style(Style::new().text(Color::Cyan))?,
653                    _ => {}
654                }
655                for chunk in chunks {
656                    chunk.encode(w, record)?;
657                }
658                match record.level() {
659                    Level::Error | Level::Warn | Level::Info | Level::Trace => {
660                        w.set_style(&Style::new())?
661                    }
662                    _ => {}
663                }
664                Ok(())
665            }
666            FormattedChunk::Debug(ref chunks) => {
667                if cfg!(debug_assertions) {
668                    for chunk in chunks {
669                        chunk.encode(w, record)?;
670                    }
671                }
672                Ok(())
673            }
674            FormattedChunk::Release(ref chunks) => {
675                if !cfg!(debug_assertions) {
676                    for chunk in chunks {
677                        chunk.encode(w, record)?;
678                    }
679                }
680                Ok(())
681            }
682            FormattedChunk::Mdc(ref key, ref default) => {
683                log_mdc::get(key, |v| write!(w, "{}", v.unwrap_or(default)))
684            }
685            #[cfg(feature = "log_kv")]
686            FormattedChunk::Kv(ref key, ref default) => {
687                use log::kv::ToKey;
688                if let Some(v) = record.key_values().get(key.to_key()) {
689                    write!(w, "{v}")
690                } else {
691                    write!(w, "{default}")
692                }
693            }
694        }
695    }
696}
697
698/// An `Encode`r configured via a format string.
699#[derive(Clone, Eq, Debug, PartialEq, Hash)]
700pub struct PatternEncoder {
701    #[debug(skip)]
702    chunks: Vec<Chunk>,
703    pattern: String,
704}
705
706/// Returns a `PatternEncoder` using the default pattern of `{d} {l} {t} - {m}{n}`.
707impl Default for PatternEncoder {
708    fn default() -> PatternEncoder {
709        PatternEncoder::new("{d} {l} {t} - {m}{n}")
710    }
711}
712
713impl Encode for PatternEncoder {
714    fn encode(&self, w: &mut dyn encode::Write, record: &Record) -> anyhow::Result<()> {
715        for chunk in &self.chunks {
716            chunk.encode(w, record)?;
717        }
718        Ok(())
719    }
720}
721
722impl PatternEncoder {
723    /// Creates a `PatternEncoder` from a pattern string.
724    ///
725    /// The pattern string syntax is documented in the `pattern` module.
726    pub fn new(pattern: &str) -> PatternEncoder {
727        PatternEncoder {
728            chunks: Parser::new(pattern).map(From::from).collect(),
729            pattern: pattern.to_owned(),
730        }
731    }
732}
733
734/// A deserializer for the `PatternEncoder`.
735///
736/// # Configuration
737///
738/// ```yaml
739/// kind: pattern
740///
741/// # The pattern to follow when formatting logs. Defaults to
742/// # "{d} {l} {t} - {m}{n}".
743/// pattern: "{d} {l} {t} - {m}{n}"
744/// ```
745#[cfg(feature = "config_parsing")]
746#[derive(Copy, Clone, Eq, PartialEq, Hash, Debug)]
747pub struct PatternEncoderDeserializer;
748
749#[cfg(feature = "config_parsing")]
750impl Deserialize for PatternEncoderDeserializer {
751    type Trait = dyn Encode;
752
753    type Config = PatternEncoderConfig;
754
755    fn deserialize(
756        &self,
757        config: PatternEncoderConfig,
758        _: &Deserializers,
759    ) -> anyhow::Result<Box<dyn Encode>> {
760        let encoder = match config.pattern {
761            Some(pattern) => PatternEncoder::new(&pattern),
762            None => PatternEncoder::default(),
763        };
764        Ok(Box::new(encoder))
765    }
766}
767
768#[cfg(test)]
769mod tests {
770    #[cfg(feature = "simple_writer")]
771    use log::{Level, Record};
772    #[cfg(feature = "simple_writer")]
773    use std::process;
774    #[cfg(feature = "simple_writer")]
775    use std::thread;
776
777    #[cfg(feature = "log_kv")]
778    use super::Parser;
779    use super::{Chunk, PatternEncoder};
780    #[cfg(feature = "simple_writer")]
781    use crate::encode::writer::simple::SimpleWriter;
782    #[cfg(feature = "simple_writer")]
783    use crate::encode::Encode;
784
785    fn error_free(encoder: &PatternEncoder) -> bool {
786        encoder.chunks.iter().all(|c| match *c {
787            Chunk::Error(_) => false,
788            _ => true,
789        })
790    }
791
792    #[test]
793    fn invalid_formatter() {
794        assert!(!error_free(&PatternEncoder::new("{x}")));
795    }
796
797    #[test]
798    fn unclosed_delimiter() {
799        assert!(!error_free(&PatternEncoder::new("{d(%Y-%m-%d)")));
800    }
801
802    #[test]
803    #[cfg(feature = "simple_writer")]
804    fn log() {
805        let pw = PatternEncoder::new("{l} {m} at {M} in {f}:{L}");
806        let mut buf = vec![];
807        pw.encode(
808            &mut SimpleWriter(&mut buf),
809            &Record::builder()
810                .level(Level::Debug)
811                .args(format_args!("the message"))
812                .module_path(Some("path"))
813                .file(Some("file"))
814                .line(Some(132))
815                .build(),
816        )
817        .unwrap();
818
819        assert_eq!(buf, &b"DEBUG the message at path in file:132"[..]);
820    }
821
822    #[test]
823    #[cfg(feature = "simple_writer")]
824    fn unnamed_thread() {
825        thread::spawn(|| {
826            let pw = PatternEncoder::new("{T}");
827            let mut buf = vec![];
828            pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
829                .unwrap();
830            assert_eq!(buf, b"unnamed");
831        })
832        .join()
833        .unwrap();
834    }
835
836    #[test]
837    #[cfg(feature = "simple_writer")]
838    fn named_thread() {
839        thread::Builder::new()
840            .name("foobar".to_string())
841            .spawn(|| {
842                let pw = PatternEncoder::new("{T}");
843                let mut buf = vec![];
844                pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
845                    .unwrap();
846                assert_eq!(buf, b"foobar");
847            })
848            .unwrap()
849            .join()
850            .unwrap();
851    }
852
853    #[test]
854    #[cfg(feature = "simple_writer")]
855    fn thread_id_field() {
856        thread::spawn(|| {
857            let pw = PatternEncoder::new("{I}");
858            let mut buf = vec![];
859            pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
860                .unwrap();
861            assert_eq!(buf, thread_id::get().to_string().as_bytes());
862        })
863        .join()
864        .unwrap();
865    }
866
867    #[test]
868    #[cfg(feature = "simple_writer")]
869    fn process_id() {
870        let pw = PatternEncoder::new("{P}");
871        let mut buf = vec![];
872
873        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
874            .unwrap();
875
876        assert_eq!(buf, process::id().to_string().as_bytes());
877    }
878
879    #[test]
880    #[cfg(feature = "simple_writer")]
881    fn system_thread_id() {
882        let pw = PatternEncoder::new("{i}");
883        let mut buf = vec![];
884
885        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
886            .unwrap();
887
888        assert_eq!(buf, thread_id::get().to_string().as_bytes());
889    }
890
891    #[test]
892    #[cfg(feature = "simple_writer")]
893    fn default_okay() {
894        assert!(error_free(&PatternEncoder::default()));
895    }
896
897    #[test]
898    #[cfg(feature = "simple_writer")]
899    fn left_align() {
900        let pw = PatternEncoder::new("{m:~<5.6}");
901
902        let mut buf = vec![];
903        pw.encode(
904            &mut SimpleWriter(&mut buf),
905            &Record::builder().args(format_args!("foo")).build(),
906        )
907        .unwrap();
908        assert_eq!(buf, b"foo~~");
909
910        buf.clear();
911        pw.encode(
912            &mut SimpleWriter(&mut buf),
913            &Record::builder().args(format_args!("foobar!")).build(),
914        )
915        .unwrap();
916        assert_eq!(buf, b"foobar");
917    }
918
919    #[test]
920    #[cfg(feature = "simple_writer")]
921    fn right_align() {
922        let pw = PatternEncoder::new("{m:~>5.6}");
923
924        let mut buf = vec![];
925        pw.encode(
926            &mut SimpleWriter(&mut buf),
927            &Record::builder().args(format_args!("foo")).build(),
928        )
929        .unwrap();
930        assert_eq!(buf, b"~~foo");
931
932        buf.clear();
933        pw.encode(
934            &mut SimpleWriter(&mut buf),
935            &Record::builder().args(format_args!("foobar!")).build(),
936        )
937        .unwrap();
938        assert_eq!(buf, b"foobar");
939    }
940
941    #[cfg(feature = "simple_writer")]
942    fn assert_info_message(pattern: &str, msg: &str, expected: &[u8]) {
943        let pw = PatternEncoder::new(pattern);
944
945        let mut buf = vec![];
946        pw.encode(
947            &mut SimpleWriter(&mut buf),
948            &Record::builder()
949                .level(Level::Info)
950                .args(format_args!("{}", msg))
951                .build(),
952        )
953        .unwrap();
954        assert_eq!(buf, expected);
955    }
956
957    #[test]
958    #[cfg(feature = "simple_writer")]
959    fn left_align_formatter() {
960        assert_info_message("{({l} {m}):15}", "foobar!", b"INFO foobar!   ");
961        assert_info_message("{({l} {m}):7}", "foobar!", b"INFO foobar!");
962    }
963
964    #[test]
965    #[cfg(feature = "simple_writer")]
966    fn right_truncate_formatter() {
967        assert_info_message("{({l} {m}):7.7}", "foobar!", b"INFO fo");
968        assert_info_message("{({l} {m}):12.12}", "foobar!", b"INFO foobar!");
969        assert_info_message("{({l} {m}):7.14}", "foobar!", b"INFO foobar!");
970    }
971
972    #[test]
973    #[cfg(feature = "simple_writer")]
974    fn left_truncate_formatter() {
975        assert_info_message("{({l} {m}):-9.9}", "foobar!", b"O foobar!");
976        assert_info_message("{({l} {m}):-12.12}", "foobar!", b"INFO foobar!");
977        assert_info_message("{({l} {m}):-7.14}", "foobar!", b"INFO foobar!");
978    }
979
980    #[test]
981    #[cfg(feature = "simple_writer")]
982    fn right_align_formatter() {
983        assert_info_message("{({l} {m}):>15}", "foobar!", b"   INFO foobar!");
984        assert_info_message("{({l} {m}):>12}", "foobar!", b"INFO foobar!");
985        assert_info_message("{({l} {m}):>7}", "foobar!", b"INFO foobar!");
986    }
987
988    #[test]
989    #[cfg(feature = "simple_writer")]
990    fn right_align_formatter_hard_unicode() {
991        assert_info_message(
992            "{({l} {m}):>15}",
993            "\u{01f5}\u{0067}\u{0301}",
994            "        INFO \u{01f5}\u{0067}\u{0301}".as_bytes(),
995        );
996    }
997
998    #[test]
999    #[cfg(feature = "simple_writer")]
1000    fn zalgo_text() {
1001        let zalgo = "m\u{0301}\u{0302}o\u{0303}\u{0304}\u{0305}\u{0306}re testing l\u{113}ss \u{1F1F7}\u{1F1F8}\u{1F1EE}\u{1F1F4} CVE-2021-30860";
1002        assert_info_message(
1003            "{({l} {m}):10.10}",
1004            zalgo,
1005            "INFO m\u{0301}\u{0302}o\u{0303}\u{0304}\u{0305}\u{0306}re ".as_bytes(),
1006        );
1007        assert_info_message(
1008            "{({l} {m}):24.24}",
1009            zalgo,
1010            "INFO m\u{0301}\u{0302}o\u{0303}\u{0304}\u{0305}\u{0306}re testing l\u{113}ss \u{1F1F7}\u{1F1F8}".as_bytes(),
1011        );
1012        assert_info_message(
1013            "{({l} {m}):-24.24}",
1014            zalgo,
1015            "g l\u{113}ss \u{1F1F7}\u{1F1F8}\u{1F1EE}\u{1F1F4} CVE-2021-30860".as_bytes(),
1016        );
1017    }
1018
1019    #[test]
1020    fn custom_date_format() {
1021        assert!(error_free(&PatternEncoder::new(
1022            "{d(%Y-%m-%d %H:%M:%S)} {m}{n}"
1023        )));
1024    }
1025
1026    #[test]
1027    fn timezones() {
1028        assert!(error_free(&PatternEncoder::new("{d(%+)(utc)}")));
1029        assert!(error_free(&PatternEncoder::new("{d(%+)(local)}")));
1030        assert!(!error_free(&PatternEncoder::new("{d(%+)(foo)}")));
1031    }
1032
1033    #[test]
1034    fn unescaped_parens() {
1035        assert!(!error_free(&PatternEncoder::new("(hi)")));
1036    }
1037
1038    #[test]
1039    #[cfg(feature = "simple_writer")]
1040    fn escaped_chars() {
1041        let pw = PatternEncoder::new("{{{m}(())}}");
1042
1043        let mut buf = vec![];
1044        pw.encode(
1045            &mut SimpleWriter(&mut buf),
1046            &Record::builder().args(format_args!("foobar!")).build(),
1047        )
1048        .unwrap();
1049        assert_eq!(buf, b"{foobar!()}");
1050    }
1051
1052    #[test]
1053    #[cfg(feature = "simple_writer")]
1054    fn quote_braces_with_backslash() {
1055        let pw = PatternEncoder::new(r"\{\({l}\)\}\\");
1056
1057        let mut buf = vec![];
1058        pw.encode(
1059            &mut SimpleWriter(&mut buf),
1060            &Record::builder().level(Level::Info).build(),
1061        )
1062        .unwrap();
1063        assert_eq!(buf, br"{(INFO)}\");
1064    }
1065
1066    #[test]
1067    #[cfg(feature = "simple_writer")]
1068    fn mdc() {
1069        let pw = PatternEncoder::new("{X(user_id)}");
1070        log_mdc::insert("user_id", "mdc value");
1071
1072        let mut buf = vec![];
1073        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
1074            .unwrap();
1075
1076        assert_eq!(buf, b"mdc value");
1077    }
1078
1079    #[test]
1080    #[cfg(feature = "simple_writer")]
1081    fn mdc_missing_default() {
1082        let pw = PatternEncoder::new("{X(user_id)}");
1083
1084        let mut buf = vec![];
1085        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
1086            .unwrap();
1087
1088        assert_eq!(buf, b"");
1089    }
1090
1091    #[test]
1092    #[cfg(feature = "simple_writer")]
1093    fn mdc_missing_custom() {
1094        let pw = PatternEncoder::new("{X(user_id)(missing value)}");
1095
1096        let mut buf = vec![];
1097        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
1098            .unwrap();
1099
1100        assert_eq!(buf, b"missing value");
1101    }
1102
1103    #[test]
1104    #[cfg(all(feature = "simple_writer", feature = "log_kv"))]
1105    fn test_kv() {
1106        let pw = PatternEncoder::new("{K(user_id)}");
1107        let kv = [("user_id", "kv value")];
1108
1109        let mut buf = vec![];
1110        pw.encode(
1111            &mut SimpleWriter(&mut buf),
1112            &Record::builder().key_values(&kv).build(),
1113        )
1114        .unwrap();
1115
1116        assert_eq!(buf, b"kv value");
1117    }
1118
1119    #[test]
1120    #[cfg(all(feature = "simple_writer", feature = "log_kv"))]
1121    fn test_kv_missing_default() {
1122        let pw = PatternEncoder::new("{K(user_id)}");
1123
1124        let mut buf = vec![];
1125        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
1126            .unwrap();
1127
1128        assert_eq!(buf, b"");
1129    }
1130
1131    #[test]
1132    #[cfg(all(feature = "simple_writer", feature = "log_kv"))]
1133    fn test_kv_missing_custom() {
1134        let pw = PatternEncoder::new("{K(user_id)(missing value)}");
1135
1136        let mut buf = vec![];
1137        pw.encode(&mut SimpleWriter(&mut buf), &Record::builder().build())
1138            .unwrap();
1139
1140        assert_eq!(buf, b"missing value");
1141    }
1142
1143    #[test]
1144    #[cfg(feature = "log_kv")]
1145    fn test_kv_from_piece_to_chunk() {
1146        let tests = vec![
1147            (
1148                "[{K(user_id)(foobar)(test):<5.5}]",
1149                "expected at most two arguments",
1150            ),
1151            ("[{K({l user_id):<5.5}]", "expected '}'"),
1152            ("[{K({l} user_id):<5.5}]", "key_value: invalid key"),
1153            ("[{K:<5.5}]", "key_value: missing key"),
1154            ("[{K(user_id)({l):<5.5}]", "expected '}'"),
1155            ("[{K(user_id)({l}):<5.5}]", "key_value: invalid default"),
1156            ("[{K(user_id)():<5.5} {M}]", "key_value: invalid default"),
1157        ];
1158
1159        for (pattern, error_msg) in tests {
1160            let chunks: Vec<Chunk> = Parser::new(pattern).map(From::from).collect();
1161            match chunks.get(1).unwrap() {
1162                Chunk::Error(err) => assert!(err.contains(error_msg)),
1163                _ => panic!(),
1164            }
1165        }
1166    }
1167
1168    #[test]
1169    #[cfg(feature = "simple_writer")]
1170    fn debug_release() {
1171        let debug_pat = "{D({l})}";
1172        let release_pat = "{R({l})}";
1173
1174        let debug_encoder = PatternEncoder::new(debug_pat);
1175        let release_encoder = PatternEncoder::new(release_pat);
1176        let mut debug_buf = vec![];
1177        let mut release_buf = vec![];
1178
1179        debug_encoder
1180            .encode(
1181                &mut SimpleWriter(&mut debug_buf),
1182                &Record::builder().level(Level::Info).build(),
1183            )
1184            .unwrap();
1185        release_encoder
1186            .encode(
1187                &mut SimpleWriter(&mut release_buf),
1188                &Record::builder().level(Level::Info).build(),
1189            )
1190            .unwrap();
1191
1192        if cfg!(debug_assertions) {
1193            assert_eq!(debug_buf, b"INFO");
1194            assert!(release_buf.is_empty());
1195        } else {
1196            assert_eq!(release_buf, b"INFO");
1197            assert!(debug_buf.is_empty());
1198        }
1199    }
1200}