Add a way for outputting JSON-formatted log messages to stdout/stderr (…

…mobilecoinfoundation#2878)

* add a way for outputting JSON logs

* DRY

* move use statement to the right place

common/src/logger/loggers/mod.rs

@@ -1,10 +1,10 @@
 // Copyright (c) 2018-2022 The MobileCoin Foundation
 
-/// Sets chan_size for stdout, gelf, and UDP loggers
-const STDOUT_CHANNEL_SIZE: usize = 100_000;
-const STDERR_CHANNEL_SIZE: usize = 100_000;
-const GELF_CHANNEL_SIZE: usize = 100_000;
-const UDP_CHANNEL_SIZE: usize = 100_000;
+/// Sets chan_size (maximal messages that can get queued up) for all channels
+const CHANNEL_SIZE: usize = 100_000;
+
+/// Marker to insert at the end of a message that has been truncated.
+const TRIM_MARKER: &str = "... <trimmed>";
 
 /// Macros to ease with tests/benches that require a Logger instance.
 pub use mc_util_logger_macros::{bench_with_logger, test_with_logger};
@@ -21,43 +21,37 @@ use sentry_logger::SentryLogger;
 use slog::Drain;
 use slog_gelf::Gelf;
 use slog_json::Json;
+use slog_term::TermDecorator;
 use std::{env, io, sync::Mutex};
 
 /// Custom timestamp function for use with slog-term
 fn custom_timestamp(io: &mut dyn io::Write) -> io::Result<()> {
     write!(io, "{}", Utc::now())
 }
 
-/// Create a basic stdout logger.
-fn create_stdout_logger() -> slog::Fuse<slog_async::Async> {
-    let decorator = slog_term::TermDecorator::new().stdout().build();
+/// Create a basic stdout/stderr logger.
+fn create_std_logger(decorator: TermDecorator) -> slog::Fuse<slog_async::Async> {
     let drain = slog_envlogger::new(
         slog_term::FullFormat::new(decorator)
             .use_custom_timestamp(custom_timestamp)
             .build()
             .fuse(),
     );
     slog_async::Async::new(drain)
-        .thread_name("slog-stdout".into())
-        .chan_size(STDOUT_CHANNEL_SIZE)
+        .thread_name("slog-std".into())
+        .chan_size(CHANNEL_SIZE)
         .build()
         .fuse()
 }
 
+/// Create a basic stdout logger.
+fn create_stdout_logger() -> slog::Fuse<slog_async::Async> {
+    create_std_logger(slog_term::TermDecorator::new().stdout().build())
+}
+
 /// Create a basic stderr logger.
 fn create_stderr_logger() -> slog::Fuse<slog_async::Async> {
-    let decorator = slog_term::TermDecorator::new().stderr().build();
-    let drain = slog_envlogger::new(
-        slog_term::FullFormat::new(decorator)
-            .use_custom_timestamp(custom_timestamp)
-            .build()
-            .fuse(),
-    );
-    slog_async::Async::new(drain)
-        .thread_name("slog-stderr".into())
-        .chan_size(STDERR_CHANNEL_SIZE)
-        .build()
-        .fuse()
+    create_std_logger(slog_term::TermDecorator::new().stderr().build())
 }
 
 /// Create a GELF (https://docs.graylog.org/en/3.0/pages/gelf.html) logger.
@@ -76,17 +70,29 @@ fn create_gelf_logger() -> Option<slog::Fuse<slog_async::Async>> {
 
         slog_async::Async::new(drain)
             .thread_name("slog-gelf".into())
-            .chan_size(GELF_CHANNEL_SIZE)
+            .chan_size(CHANNEL_SIZE)
             .build()
             .fuse()
     })
 }
 
-/// Create a UDP JSON logger.
-fn create_udp_json_logger() -> Option<slog::Fuse<slog_async::Async>> {
-    env::var("MC_LOG_UDP_JSON").ok().map(|remote_host_port| {
-        let drain = Json::new(udp_writer::UdpWriter::new(remote_host_port))
-            .set_newlines(false)
+/// Create a json logger.
+///
+/// # Arguments:
+/// * `writer` - The writer to use for the logger.
+/// * `new_lines` - Whether to add a new line to the end of each log message.
+/// * `max_message_len` - The maximum length of a log message. If exceeded,
+///   message text will be trimmed.
+fn create_json_logger<W: io::Write + Send + 'static>(
+    writer: W,
+    new_lines: bool,
+    cap_message_length: Option<usize>,
+) -> slog::Fuse<slog_async::Async> {
+    let cap_message_length = cap_message_length.unwrap_or(usize::max_value());
+
+    let drain = slog_envlogger::new(
+        Json::new(writer)
+            .set_newlines(new_lines)
             .set_flush(true)
             .add_key_value(o!(
                     "ts" => PushFnValue(move |_, ser| {
@@ -99,25 +105,30 @@ fn create_udp_json_logger() -> Option<slog::Fuse<slog_async::Async>> {
                         record.level().as_usize()
                     }),
                     "message" => PushFnValue(move |record, ser| {
-                        // Cap message at 65000 bytes to increase chances of it fitting in a UDP
-                        // packet.
-                        let mut msg = format!("{}", record.msg());
-                        if msg.len() > 65000 {
-                            msg = format!("{}... <trimmed>", &msg[0..65000]);
+                        let mut msg = record.msg().to_string();
+                        if msg.len() > cap_message_length{
+                            msg = format!("{}{}", &msg[0..cap_message_length - TRIM_MARKER.len()], TRIM_MARKER);
                         }
                         ser.emit(msg)
                     }),
             ))
             .build()
-            .fuse();
-
-        let drain = slog_envlogger::new(drain);
+            .fuse(),
+    );
+    slog_async::Async::new(drain)
+        .thread_name("slog-json".into())
+        .chan_size(CHANNEL_SIZE)
+        .build()
+        .fuse()
+}
 
-        slog_async::Async::new(drain)
-            .thread_name("slog-udp".into())
-            .chan_size(UDP_CHANNEL_SIZE)
-            .build()
-            .fuse()
+/// Create a UDP JSON logger.
+fn create_udp_json_logger() -> Option<slog::Fuse<slog_async::Async>> {
+    env::var("MC_LOG_UDP_JSON").ok().map(|remote_host_port| {
+        let writer = udp_writer::UdpWriter::new(remote_host_port);
+        // Cap message at 65000 bytes to increase chances of it fitting in a UDP
+        // packet.
+        create_json_logger(writer, false, Some(65000))
     })
 }
 
@@ -146,10 +157,14 @@ pub fn create_root_logger() -> Logger {
     };
 
     // Create stdout / stderr sink
-    let std_logger = if env::var("MC_LOG_STDERR") == Ok("1".to_string()) {
-        create_stderr_logger()
-    } else {
-        create_stdout_logger()
+    let std_logger = match (
+        env::var("MC_LOG_JSON").unwrap_or_default().as_ref(),
+        env::var("MC_LOG_STDERR").unwrap_or_default().as_ref(),
+    ) {
+        ("1", "1") => create_json_logger(io::stderr(), true, None),
+        ("1", _) => create_json_logger(io::stdout(), true, None),
+        (_, "1") => create_stderr_logger(),
+        (_, _) => create_stdout_logger(),
     };
 
     // Extra context that always gets added to each log message.