tork_core/logging/
event.rs

1//! The fluent log-event builder.
2
3use std::sync::atomic::{AtomicU8, Ordering};
4use std::sync::Arc;
5
6use serde::Serialize;
7use serde_json::{Map, Value};
8use tracing::Level;
9
10use super::config::ErrorLogDetail;
11
12/// Maximum number of `source()` entries recorded for a logged error, bounding the
13/// size of a single error record.
14const MAX_ERROR_CHAIN: usize = 16;
15const ERROR_DETAIL_TYPE_ONLY: u8 = 0;
16const ERROR_DETAIL_MESSAGE_ONLY: u8 = 1;
17const ERROR_DETAIL_FULL_CHAIN: u8 = 2;
18
19static ERROR_LOG_DETAIL: AtomicU8 = AtomicU8::new(ERROR_DETAIL_TYPE_ONLY);
20
21/// A log record being built. Add fields and an error, then [`emit`](LogEvent::emit).
22///
23/// Created by the level methods on [`Logger`](crate::Logger) (`info`, `warn`, ...).
24/// Nothing is logged until `emit` is called.
25#[must_use = "a LogEvent does nothing until emit() is called"]
26pub struct LogEvent {
27    pub(crate) level: Level,
28    pub(crate) context: Arc<str>,
29    pub(crate) message: String,
30    pub(crate) fields: Map<String, Value>,
31    pub(crate) error: Option<Value>,
32}
33
34impl LogEvent {
35    /// Attaches a structured field. A non-serializable value is skipped.
36    pub fn field<T: Serialize>(mut self, key: &'static str, value: T) -> Self {
37        if let Ok(value) = serde_json::to_value(value) {
38            self.fields.insert(key.to_owned(), value);
39        }
40        self
41    }
42
43    /// Attaches an error: its type name, message, and source chain.
44    ///
45    /// The source chain is bounded to [`MAX_ERROR_CHAIN`] entries so a pathological
46    /// or deeply nested error cannot produce an unbounded log record. Note that an
47    /// error's `Display`/`source` output can carry sensitive data (a database
48    /// driver may include a connection string); keep secrets out of error messages,
49    /// since logged errors are not redacted the way `5xx` client responses are.
50    pub fn error<E: std::error::Error>(mut self, error: &E) -> Self {
51        let mut object = Map::new();
52        object.insert(
53            "type".to_owned(),
54            Value::String(std::any::type_name::<E>().to_owned()),
55        );
56        match error_log_detail() {
57            ErrorLogDetail::TypeOnly => {}
58            ErrorLogDetail::MessageOnly => {
59                object.insert("message".to_owned(), Value::String(error.to_string()));
60            }
61            ErrorLogDetail::FullChain => {
62                object.insert("message".to_owned(), Value::String(error.to_string()));
63
64                let mut chain = Vec::new();
65                let mut source = error.source();
66                while let Some(error) = source {
67                    if chain.len() >= MAX_ERROR_CHAIN {
68                        chain.push(Value::String("... (chain truncated)".to_owned()));
69                        break;
70                    }
71                    chain.push(Value::String(error.to_string()));
72                    source = error.source();
73                }
74                if !chain.is_empty() {
75                    object.insert("chain".to_owned(), Value::Array(chain));
76                }
77            }
78        }
79
80        self.error = Some(Value::Object(object));
81        self
82    }
83
84    /// Emits the record at its level to the active subscriber.
85    pub fn emit(self) {
86        let LogEvent {
87            level,
88            context,
89            message,
90            fields,
91            error,
92        } = self;
93        let fields =
94            serde_json::to_string(&Value::Object(fields)).unwrap_or_else(|_| "{}".to_owned());
95        let error = error.map(|value| serde_json::to_string(&value).unwrap_or_default());
96        let context = context.as_ref();
97
98        // The level must be a static call site, so dispatch to the level-specific
99        // macro; the message and fields are carried as a fixed set of fields that
100        // the Tork formatters recognize and flatten.
101        macro_rules! emit_level {
102            ($level:ident) => {
103                match &error {
104                    Some(error) => tracing::$level!(
105                        tork.context = %context,
106                        tork.fields = %fields,
107                        tork.error = %error,
108                        "{message}"
109                    ),
110                    None => tracing::$level!(
111                        tork.context = %context,
112                        tork.fields = %fields,
113                        "{message}"
114                    ),
115                }
116            };
117        }
118
119        match level {
120            Level::TRACE => emit_level!(trace),
121            Level::DEBUG => emit_level!(debug),
122            Level::INFO => emit_level!(info),
123            Level::WARN => emit_level!(warn),
124            Level::ERROR => emit_level!(error),
125        }
126    }
127}
128
129pub(crate) fn set_error_log_detail(detail: ErrorLogDetail) {
130    let raw = match detail {
131        ErrorLogDetail::TypeOnly => ERROR_DETAIL_TYPE_ONLY,
132        ErrorLogDetail::MessageOnly => ERROR_DETAIL_MESSAGE_ONLY,
133        ErrorLogDetail::FullChain => ERROR_DETAIL_FULL_CHAIN,
134    };
135    ERROR_LOG_DETAIL.store(raw, Ordering::Relaxed);
136}
137
138fn error_log_detail() -> ErrorLogDetail {
139    match ERROR_LOG_DETAIL.load(Ordering::Relaxed) {
140        ERROR_DETAIL_MESSAGE_ONLY => ErrorLogDetail::MessageOnly,
141        ERROR_DETAIL_FULL_CHAIN => ErrorLogDetail::FullChain,
142        _ => ErrorLogDetail::TypeOnly,
143    }
144}
145
146#[cfg(test)]
147mod tests {
148    use super::*;
149    use crate::testing::LogRecorder;
150    use std::sync::Mutex;
151    use tracing_subscriber::layer::SubscriberExt;
152
153    static ERROR_DETAIL_TEST_LOCK: Mutex<()> = Mutex::new(());
154
155    #[derive(Debug)]
156    struct InnerError;
157
158    impl std::fmt::Display for InnerError {
159        fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
160            write!(f, "inner")
161        }
162    }
163
164    impl std::error::Error for InnerError {}
165
166    #[derive(Debug)]
167    struct OuterError;
168
169    impl std::fmt::Display for OuterError {
170        fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
171            write!(f, "outer")
172        }
173    }
174
175    impl std::error::Error for OuterError {
176        fn source(&self) -> Option<&(dyn std::error::Error + 'static)> {
177            Some(&InnerError)
178        }
179    }
180
181    struct BrokenSerialize;
182
183    impl Serialize for BrokenSerialize {
184        fn serialize<S>(&self, _serializer: S) -> std::result::Result<S::Ok, S::Error>
185        where
186            S: serde::Serializer,
187        {
188            Err(serde::ser::Error::custom("nope"))
189        }
190    }
191
192    #[test]
193    fn field_skips_unserializable_values_and_emit_records_error_chain() {
194        let _guard = ERROR_DETAIL_TEST_LOCK.lock().unwrap();
195        set_error_log_detail(ErrorLogDetail::FullChain);
196        let recorder = LogRecorder::new();
197        let subscriber = tracing_subscriber::registry().with(recorder.clone());
198        let event = LogEvent {
199            level: Level::ERROR,
200            context: Arc::<str>::from("Orders"),
201            message: "failed".to_owned(),
202            fields: Map::new(),
203            error: None,
204        }
205        .field("ok", 1)
206        .field("skip", BrokenSerialize)
207        .error(&OuterError);
208
209        tracing::subscriber::with_default(subscriber, move || event.emit());
210
211        let records = recorder.records();
212        assert_eq!(records.len(), 1);
213        assert_eq!(records[0].context, "Orders");
214        assert_eq!(records[0].message, "failed");
215        assert_eq!(records[0].fields["ok"], Value::from(1));
216        set_error_log_detail(ErrorLogDetail::TypeOnly);
217    }
218
219    /// An error whose source is another `Deep` of one less depth, forming a chain.
220    #[derive(Debug)]
221    struct Deep(usize, Option<Box<Deep>>);
222
223    impl std::fmt::Display for Deep {
224        fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
225            write!(f, "level {}", self.0)
226        }
227    }
228
229    impl std::error::Error for Deep {
230        fn source(&self) -> Option<&(dyn std::error::Error + 'static)> {
231            self.1
232                .as_deref()
233                .map(|inner| inner as &(dyn std::error::Error + 'static))
234        }
235    }
236
237    fn deep_chain(depth: usize) -> Deep {
238        let mut error = Deep(0, None);
239        for level in 1..depth {
240            error = Deep(level, Some(Box::new(error)));
241        }
242        error
243    }
244
245    #[test]
246    fn error_chain_is_truncated_at_the_cap() {
247        let _guard = ERROR_DETAIL_TEST_LOCK.lock().unwrap();
248        set_error_log_detail(ErrorLogDetail::FullChain);
249        let event = LogEvent {
250            level: Level::ERROR,
251            context: Arc::<str>::from("X"),
252            message: "boom".to_owned(),
253            fields: Map::new(),
254            error: None,
255        }
256        .error(&deep_chain(100));
257
258        let chain = event.error.as_ref().unwrap()["chain"].as_array().unwrap();
259        // MAX_ERROR_CHAIN entries plus the truncation marker.
260        assert_eq!(chain.len(), MAX_ERROR_CHAIN + 1);
261        assert_eq!(
262            chain.last().unwrap(),
263            &Value::String("... (chain truncated)".to_owned())
264        );
265        set_error_log_detail(ErrorLogDetail::TypeOnly);
266    }
267
268    #[test]
269    fn default_error_detail_is_type_only() {
270        let _guard = ERROR_DETAIL_TEST_LOCK.lock().unwrap();
271        set_error_log_detail(ErrorLogDetail::TypeOnly);
272        let event = LogEvent {
273            level: Level::ERROR,
274            context: Arc::<str>::from("X"),
275            message: "boom".to_owned(),
276            fields: Map::new(),
277            error: None,
278        }
279        .error(&OuterError);
280        let object = event.error.as_ref().unwrap().as_object().unwrap();
281        let ty = object.get("type").unwrap().as_str().unwrap();
282        assert!(ty.ends_with("OuterError"), "{ty}");
283        assert!(object.get("message").is_none());
284        assert!(object.get("chain").is_none());
285    }
286
287    #[test]
288    fn message_only_includes_the_top_level_message_without_the_chain() {
289        let _guard = ERROR_DETAIL_TEST_LOCK.lock().unwrap();
290        set_error_log_detail(ErrorLogDetail::MessageOnly);
291        let event = LogEvent {
292            level: Level::ERROR,
293            context: Arc::<str>::from("X"),
294            message: "boom".to_owned(),
295            fields: Map::new(),
296            error: None,
297        }
298        .error(&OuterError);
299        let object = event.error.as_ref().unwrap().as_object().unwrap();
300        let ty = object.get("type").unwrap().as_str().unwrap();
301        assert!(ty.ends_with("OuterError"), "{ty}");
302        assert_eq!(object.get("message").unwrap(), "outer");
303        assert!(object.get("chain").is_none());
304        set_error_log_detail(ErrorLogDetail::TypeOnly);
305    }
306}
tork_core/logging/event.rs

tork_core/logging/
event.rs
