arpa_core/log/
encoder.rs

1//! An encoder which writes a JSON object adapted from log4rs.
2//!
3//! Each log event will be written as a JSON object on its own line.
4//!
5//! # Contents
6//!
7//! An example object (note that real output will not be pretty-printed):
8//!
9//! ```json
10//! {
11//!     "time": "2016-03-20T14:22:20.644420340-08:00",
12//!     "message": "the log message",
13//!     "module_path": "foo::bar",
14//!     "file": "foo/bar/mod.rs",
15//!     "line": 100,
16//!     "level": "INFO",
17//!     "target": "foo::bar",
18//!     "thread": "main",
19//!     "thread_id": 123,
20//!     "mdc": {
21//!         "request_id": "123e4567-e89b-12d3-a456-426655440000"
22//!     }
23//!     "node_info": {
24//!         
25//!     }
26//! }
27//! ```
28
29use chrono::{
30    format::{DelayedFormat, Fixed, Item},
31    DateTime, Local,
32};
33use lazy_static::lazy_static;
34use log::{Level, Record};
35use log4rs::encode::{Encode, Write};
36use parking_lot::RwLock;
37use serde::ser::{self, Serialize, SerializeMap};
38use std::{
39    fmt::{self, Debug},
40    option, thread,
41};
42
43lazy_static! {
44    pub static ref CONTEXT_INFO: RwLock<Vec<String>> =
45        RwLock::new(vec!["".to_string(), "".to_string()]);
46}
47
48/// An `Encode`r which writes a JSON object.
49#[derive(Clone, Debug, Default)]
50pub struct JsonEncoder {
51    node_id: String,
52    l1_chain_id: usize,
53    show_context: bool,
54    version: String,
55}
56
57impl JsonEncoder {
58    /// Returns a new `JsonEncoder` with a default configuration.
59    pub fn new(node_id: String, l1_chain_id: usize, version: String) -> Self {
60        JsonEncoder {
61            node_id,
62            l1_chain_id,
63            show_context: false,
64            version,
65        }
66    }
67
68    pub fn context_logging(mut self, show_context: bool) -> Self {
69        self.show_context = show_context;
70        self
71    }
72}
73
74impl JsonEncoder {
75    fn encode_inner(
76        &self,
77        w: &mut dyn Write,
78        time: DateTime<Local>,
79        record: &Record,
80    ) -> anyhow::Result<()> {
81        let thread = thread::current();
82        let node_info = if self.show_context {
83            CONTEXT_INFO.read()[0].clone()
84        } else {
85            "".to_string()
86        };
87        let group_info = if self.show_context {
88            CONTEXT_INFO.read()[1].clone()
89        } else {
90            "".to_string()
91        };
92
93        let message = Message {
94            time: time.format_with_items(Some(Item::Fixed(Fixed::RFC3339)).into_iter()),
95            message: record.args(),
96            level: record.level(),
97            module_path: record.module_path(),
98            file: record.file(),
99            line: record.line(),
100            target: record.target(),
101            thread: thread.name(),
102            thread_id: thread_id::get(),
103            node_id: &self.node_id,
104            l1_chain_id: self.l1_chain_id,
105            mdc: Mdc,
106            node_info: &node_info,
107            group_info: &group_info,
108            version: &self.version,
109        };
110        message.serialize(&mut serde_json::Serializer::new(&mut *w))?;
111        w.write_all("\n".as_bytes())?;
112        Ok(())
113    }
114}
115
116impl Encode for JsonEncoder {
117    fn encode(&self, w: &mut dyn Write, record: &Record) -> anyhow::Result<()> {
118        self.encode_inner(w, Local::now(), record)
119    }
120}
121
122#[derive(serde::Serialize)]
123struct Message<'a> {
124    #[serde(serialize_with = "ser_display")]
125    time: DelayedFormat<option::IntoIter<Item<'a>>>,
126    #[serde(serialize_with = "ser_display")]
127    message: &'a fmt::Arguments<'a>,
128    #[serde(skip_serializing_if = "Option::is_none")]
129    module_path: Option<&'a str>,
130    #[serde(skip_serializing_if = "Option::is_none")]
131    file: Option<&'a str>,
132    #[serde(skip_serializing_if = "Option::is_none")]
133    line: Option<u32>,
134    level: Level,
135    target: &'a str,
136    thread: Option<&'a str>,
137    thread_id: usize,
138    node_id: &'a str,
139    l1_chain_id: usize,
140    mdc: Mdc,
141    node_info: &'a str,
142    group_info: &'a str,
143    version: &'a str,
144}
145
146fn ser_display<T, S>(v: &T, s: S) -> Result<S::Ok, S::Error>
147where
148    T: fmt::Display,
149    S: ser::Serializer,
150{
151    if let Ok(val) = serde_json::from_str::<serde_json::Value>(&format!("{}", v)) {
152        val.serialize(s)
153    } else {
154        s.collect_str(v)
155    }
156}
157
158struct Mdc;
159
160impl ser::Serialize for Mdc {
161    fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
162    where
163        S: ser::Serializer,
164    {
165        let mut map = serializer.serialize_map(None)?;
166
167        let mut err = Ok(());
168        log_mdc::iter(|k, v| {
169            if let Ok(()) = err {
170                err = map.serialize_key(k).and_then(|()| map.serialize_value(v));
171            }
172        });
173        err?;
174
175        map.end()
176    }
177}
178
179#[cfg(test)]
180mod test {
181    use super::*;
182    use crate::log::{build_general_payload, LogType};
183    use log4rs::encode::writer::simple::SimpleWriter;
184
185    #[test]
186    fn default() {
187        let time = DateTime::parse_from_rfc3339("2016-03-20T14:22:20.644420340-08:00")
188            .unwrap()
189            .with_timezone(&Local);
190        let level = Level::Debug;
191        let target = "target";
192        let module_path = "module_path";
193        let file = "file";
194        let line = 100;
195        let message = "message";
196        let thread = "log::encoder::test::default";
197        let node_id = "test";
198        let l1_chain_id = 1;
199        let version = "0.1.0";
200        log_mdc::insert("foo", "bar");
201
202        let encoder = JsonEncoder::new(node_id.to_string(), l1_chain_id, version.to_string());
203
204        let mut buf = vec![];
205        encoder
206            .encode_inner(
207                &mut SimpleWriter(&mut buf),
208                time,
209                &Record::builder()
210                    .level(level)
211                    .target(target)
212                    .module_path(Some(module_path))
213                    .file(Some(file))
214                    .line(Some(line))
215                    .args(format_args!("{}", message))
216                    .build(),
217            )
218            .unwrap();
219
220        let expected = format!(
221            "{{\"time\":\"{}\",\"message\":\"{}\",\"module_path\":\"{}\",\
222             \"file\":\"{}\",\"line\":{},\"level\":\"{}\",\"target\":\"{}\",\
223             \"thread\":\"{}\",\"thread_id\":{},\"node_id\":\"{}\",\"l1_chain_id\":{},\
224             \"mdc\":{{\"foo\":\"bar\"}},\
225             \"node_info\":\"\",\"group_info\":\"\",\"version\":\"{}\"}}",
226            time.to_rfc3339(),
227            message,
228            module_path,
229            file,
230            line,
231            level,
232            target,
233            thread,
234            thread_id::get(),
235            node_id,
236            l1_chain_id,
237            version
238        );
239        assert_eq!(expected, String::from_utf8(buf).unwrap().trim());
240    }
241
242    #[test]
243    fn test_error_log_with_json_payload() {
244        let time = DateTime::parse_from_rfc3339("2016-03-20T14:22:20.644420340-08:00")
245            .unwrap()
246            .with_timezone(&Local);
247        let level = Level::Error;
248        let target = "target";
249        let module_path = "module_path";
250        let file = "file";
251        let line = 100;
252        let message = build_general_payload(
253            LogType::ListenerInterrupted,
254            "Listener interrupted",
255            Some(1),
256        );
257        let thread = "log::encoder::test::test_error_log_with_json_payload";
258        let node_id = "test";
259        let l1_chain_id = 1;
260        let version = "0.1.0";
261        log_mdc::insert("foo", "bar");
262
263        let encoder = JsonEncoder::new(node_id.to_string(), l1_chain_id, version.to_string());
264
265        let mut buf = vec![];
266        encoder
267            .encode_inner(
268                &mut SimpleWriter(&mut buf),
269                time,
270                &Record::builder()
271                    .level(level)
272                    .target(target)
273                    .module_path(Some(module_path))
274                    .file(Some(file))
275                    .line(Some(line))
276                    .args(format_args!("{}", message))
277                    .build(),
278            )
279            .unwrap();
280
281        let expected = format!(
282            "{{\"time\":\"{}\",\"message\":{},\"module_path\":\"{}\",\
283             \"file\":\"{}\",\"line\":{},\"level\":\"{}\",\"target\":\"{}\",\
284             \"thread\":\"{}\",\"thread_id\":{},\"node_id\":\"{}\",\"l1_chain_id\":{},\
285             \"mdc\":{{\"foo\":\"bar\"}},\
286             \"node_info\":\"\",\"group_info\":\"\",\"version\":\"{}\"}}",
287            time.to_rfc3339(),
288            message,
289            module_path,
290            file,
291            line,
292            level,
293            target,
294            thread,
295            thread_id::get(),
296            node_id,
297            l1_chain_id,
298            version
299        );
300        assert_eq!(expected, String::from_utf8(buf).unwrap().trim());
301    }
302}
arpa_core/log/encoder.rs

arpa_core/log/
encoder.rs
