feat: Added JSON logging (#32)

Author: mitsuhiko

Cargo.lock

@@ -15,6 +15,7 @@ with_ssl = ["semaphore-server/with_ssl"]
 
 [profile.release]
 lto = true
+debug = true
 
 [dependencies]
 clap = { version = "2.31.2", default-features = false, features = ["wrap_help"] }
@@ -24,12 +25,16 @@ tokio-core = "0.1.17"
 futures = "0.1.21"
 parking_lot = "0.5.5"
 ctrlc = { version = "3.1.1", features = ["termination"] }
-log = "0.4.2"
+log = { version = "0.4.2", features = ["serde"] }
 sentry = "0.5.4"
 dialoguer = "0.1.0"
 uuid = "0.6.5"
 console = "0.6.1"
 env_logger = "0.5.10"
+chrono = "0.4.3"
+serde_derive = "1.0.66"
+serde = "1.0.66"
+serde_json = "1.0.20"
 
 [dependencies.semaphore-aorta]
 path = "aorta"

Cargo.toml

@@ -124,6 +124,20 @@ pub struct MinimalConfig {
     pub relay: Relay,
 }
 
+/// Controls the log format
+#[derive(Serialize, Deserialize, Debug, Copy, Clone, PartialEq)]
+#[serde(rename_all = "lowercase")]
+pub enum LogFormat {
+    /// Auto detect (pretty for tty, simplified for other)
+    Auto,
+    /// With colors
+    Pretty,
+    /// Simplified log output
+    Simplified,
+    /// Dump out JSON lines
+    Json,
+}
+
 /// Controls the logging system.
 #[derive(Serialize, Deserialize, Debug)]
 #[serde(default)]
@@ -132,6 +146,8 @@ struct Logging {
     level: log::LevelFilter,
     /// If set to true this emits log messages for failed event payloads.
     log_failed_payloads: bool,
+    /// Controls the log format.
+    format: LogFormat,
     /// When set to true, backtraces are forced on.
     enable_backtraces: bool,
 }
@@ -194,6 +210,7 @@ impl Default for Logging {
         Logging {
             level: log::LevelFilter::Info,
             log_failed_payloads: false,
+            format: LogFormat::Auto,
             enable_backtraces: true,
         }
     }
@@ -514,6 +531,11 @@ impl Config {
         self.values.logging.log_failed_payloads
     }
 
+    /// Which log format should be used?
+    pub fn log_format(&self) -> LogFormat {
+        self.values.logging.format
+    }
+
     /// Returns the socket addresses for statsd.
     ///
     /// If stats is disabled an empty vector is returned.

config/src/types.rs

@@ -116,16 +116,25 @@ impl<T: FromRequest<ServiceState> + 'static> FromRequest<ServiceState> for Proje
 
         req.extensions_mut().insert(auth.clone());
 
-        match req.match_info()
+        let project_id = match req.match_info()
             .get("project")
             .unwrap_or_default()
             .parse::<ProjectId>()
             .map_err(BadProjectRequest::BadProject)
         {
-            Ok(project_id) => req.extensions_mut().insert(project_id),
+            Ok(project_id) => project_id,
             Err(err) => return Box::new(future::err(err.into())),
         };
 
+        sentry::configure_scope(|scope| {
+            scope.set_user(Some(sentry::User {
+                id: Some(project_id.to_string()),
+                ..Default::default()
+            }));
+        });
+
+        req.extensions_mut().insert(project_id);
+
         Box::new(
             T::from_request(&req, cfg)
                 .into()

server/src/extractors.rs

@@ -13,6 +13,11 @@ extern crate parking_lot;
 extern crate pretty_env_logger;
 #[macro_use]
 extern crate sentry;
+extern crate serde;
+#[macro_use]
+extern crate serde_derive;
+extern crate chrono;
+extern crate serde_json;
 extern crate uuid;
 
 extern crate semaphore_common;

src/main.rs

@@ -1,15 +1,18 @@
 use std::env;
+use std::io;
 use std::io::Write;
 
+use chrono::{DateTime, Utc};
 use console;
 use env_logger;
 use failure::Error;
-use log::LevelFilter;
+use log::{Level, LevelFilter};
 use pretty_env_logger;
 use sentry;
+use serde_json;
 
 use semaphore_common::metrics;
-use semaphore_config::Config;
+use semaphore_config::{Config, LogFormat};
 
 /// Print spawn infos to the log.
 pub fn dump_spawn_infos(config: &Config) {
@@ -79,22 +82,56 @@ pub fn init_logging(config: &Config) {
     }
 
     let mut log_builder = {
-        if console::user_attended() {
-            pretty_env_logger::formatted_builder().unwrap()
-        } else {
-            let mut builder = env_logger::Builder::new();
-            builder.format(|buf, record| {
-                let ts = buf.timestamp();
-                writeln!(
-                    buf,
-                    "{} [{}] {}: {}",
-                    ts,
-                    record.module_path().unwrap_or("<unknown>"),
-                    record.level(),
-                    record.args()
-                )
-            });
-            builder
+        match (config.log_format(), console::user_attended()) {
+            (LogFormat::Auto, true) | (LogFormat::Pretty, _) => {
+                pretty_env_logger::formatted_builder().unwrap()
+            }
+            (LogFormat::Auto, false) | (LogFormat::Simplified, _) => {
+                let mut builder = env_logger::Builder::new();
+                builder.format(|buf, record| {
+                    let ts = buf.timestamp();
+                    writeln!(
+                        buf,
+                        "{} [{}] {}: {}",
+                        ts,
+                        record.module_path().unwrap_or("<unknown>"),
+                        record.level(),
+                        record.args()
+                    )
+                });
+                builder
+            }
+            (LogFormat::Json, _) => {
+                #[derive(Serialize, Deserialize, Debug)]
+                struct LogRecord<'a> {
+                    timestamp: DateTime<Utc>,
+                    level: Level,
+                    logger: &'a str,
+                    message: String,
+                    module_path: Option<&'a str>,
+                    filename: Option<&'a str>,
+                    lineno: Option<u32>,
+                }
+
+                let mut builder = env_logger::Builder::new();
+                builder.format(|mut buf, record| -> io::Result<()> {
+                    serde_json::to_writer(
+                        &mut buf,
+                        &LogRecord {
+                            timestamp: Utc::now(),
+                            level: record.level(),
+                            logger: record.target(),
+                            message: record.args().to_string(),
+                            module_path: record.module_path(),
+                            filename: record.file(),
+                            lineno: record.line(),
+                        },
+                    ).map_err(|err| io::Error::new(io::ErrorKind::Other, err))?;
+                    buf.write(b"\n")?;
+                    Ok(())
+                });
+                builder
+            }
         }
     };