factor out common logging initialisation routine

This contains a lowest common denominator of pageserver and safekeeper log
initialisation routines. It uses daemonize flag to decide where to
stream log messages. In case daemonize is true log messages are
forwarded to file. Otherwise streaming to stdout is used. Usage of
stdout for log output is the default in docker side of things, so make
it easier to browse our logs via builtin docker commands.

Cargo.lock

@@ -1196,10 +1196,6 @@ dependencies = [
  "scopeguard",
  "serde",
  "serde_json",
- "slog",
- "slog-scope",
- "slog-stdlog",
- "slog-term",
  "tar",
  "thiserror",
  "tokio",
@@ -2333,11 +2329,6 @@ dependencies = [
  "regex",
  "rust-s3",
  "serde",
- "slog",
- "slog-async",
- "slog-scope",
- "slog-stdlog",
- "slog-term",
  "tokio",
  "tokio-stream",
  "walkdir",
@@ -2586,6 +2577,11 @@ dependencies = [
  "rustls-split",
  "serde",
  "serde_json",
+ "slog",
+ "slog-async",
+ "slog-scope",
+ "slog-stdlog",
+ "slog-term",
  "thiserror",
  "tokio",
  "webpki",

pageserver/Cargo.toml

@@ -16,10 +16,6 @@ byteorder = "1.4.3"
 futures = "0.3.13"
 hyper = "0.14"
 lazy_static = "1.4.0"
-slog-stdlog = "4.1.0"
-slog-scope = "4.4.0"
-slog-term = "2.8.0"
-slog = "2.7.0"
 log = "0.4.14"
 clap = "2.33.0"
 daemonize = "0.4.1"

pageserver/src/bin/pageserver.rs

@@ -13,13 +13,13 @@ use std::{
     thread,
     time::Duration,
 };
-use zenith_utils::{auth::JwtAuth, postgres_backend::AuthType};
+use zenith_utils::{auth::JwtAuth, logging, postgres_backend::AuthType};
 
 use anyhow::{ensure, Result};
 use clap::{App, Arg, ArgMatches};
 use daemonize::Daemonize;
 
-use pageserver::{branches, http, logger, page_service, tenant_mgr, PageServerConf};
+use pageserver::{branches, http, page_service, tenant_mgr, PageServerConf, LOG_FILE_NAME};
 use zenith_utils::http::endpoint;
 
 const DEFAULT_LISTEN_ADDR: &str = "127.0.0.1:64000";
@@ -273,11 +273,7 @@ fn main() -> Result<()> {
 
 fn start_pageserver(conf: &'static PageServerConf) -> Result<()> {
     // Initialize logger
-    let (_scope_guard, log_file) = logger::init_logging(conf, "pageserver.log")?;
-    let _log_guard = slog_stdlog::init()?;
-
-    // Note: this `info!(...)` macro comes from `log` crate
-    info!("standard logging redirected to slog");
+    let (_scope_guard, log_file) = logging::init(LOG_FILE_NAME, conf.daemonize)?;
 
     // TODO: Check that it looks like a valid repository before going further
 

pageserver/src/branches.rs

@@ -17,13 +17,13 @@ use std::{
 use zenith_utils::zid::{ZTenantId, ZTimelineId};
 
 use log::*;
+use zenith_utils::logging;
 use zenith_utils::lsn::Lsn;
 
-use crate::logger;
-use crate::restore_local_repo;
 use crate::tenant_mgr;
 use crate::walredo::WalRedoManager;
 use crate::{repository::Repository, PageServerConf};
+use crate::{restore_local_repo, LOG_FILE_NAME};
 
 #[derive(Serialize, Deserialize, Clone)]
 pub struct BranchInfo {
@@ -98,8 +98,8 @@ pub struct PointInTime {
 
 pub fn init_pageserver(conf: &'static PageServerConf, create_tenant: Option<&str>) -> Result<()> {
     // Initialize logger
-    let (_scope_guard, _log_file) = logger::init_logging(conf, "pageserver.log")?;
-    let _log_guard = slog_stdlog::init()?;
+    // use true as daemonize parameter because otherwise we pollute zenith cli output with a few pages long output of info messages
+    let (_scope_guard, _log_file) = logging::init(LOG_FILE_NAME, true)?;
 
     // We don't use the real WAL redo manager, because we don't want to spawn the WAL redo
     // process during repository initialization.
@@ -138,9 +138,6 @@ pub fn create_repo(
     fs::create_dir_all(&repo_dir)
         .with_context(|| format!("could not create directory {}", repo_dir.display()))?;
 
-    // Note: this `info!(...)` macro comes from `log` crate
-    info!("standard logging redirected to slog");
-
     fs::create_dir(conf.timelines_path(&tenantid))?;
     fs::create_dir_all(conf.branches_path(&tenantid))?;
     fs::create_dir_all(conf.tags_path(&tenantid))?;

pageserver/src/lib.rs

@@ -11,7 +11,6 @@ pub mod basebackup;
 pub mod branches;
 pub mod http;
 pub mod layered_repository;
-pub mod logger;
 pub mod page_service;
 pub mod relish;
 pub mod repository;
@@ -30,6 +29,8 @@ lazy_static! {
     .expect("failed to define a metric");
 }
 
+pub const LOG_FILE_NAME: &str = "pageserver.log";
+
 #[derive(Debug, Clone)]
 pub struct PageServerConf {
     pub daemonize: bool,

pageserver/src/logger.rs

@@ -1,45 +0,0 @@
-use crate::PageServerConf;
-
-use anyhow::{Context, Result};
-use slog::{Drain, FnValue};
-use std::fs::{File, OpenOptions};
-
-pub fn init_logging(
-    _conf: &PageServerConf,
-    log_filename: &str,
-) -> Result<(slog_scope::GlobalLoggerGuard, File)> {
-    // Don't open the same file for output multiple times;
-    // the different fds could overwrite each other's output.
-    let log_file = OpenOptions::new()
-        .create(true)
-        .append(true)
-        .open(&log_filename)
-        .with_context(|| format!("failed to open {:?}", &log_filename))?;
-
-    let logger_file = log_file.try_clone().unwrap();
-
-    let decorator = slog_term::PlainSyncDecorator::new(logger_file);
-    let drain = slog_term::FullFormat::new(decorator).build();
-    let drain = slog::Filter::new(drain, |record: &slog::Record| {
-        if record.level().is_at_least(slog::Level::Info) {
-            return true;
-        }
-        false
-    });
-    let drain = std::sync::Mutex::new(drain).fuse();
-    let logger = slog::Logger::root(
-        drain,
-        slog::o!(
-            "location" =>
-                FnValue(move |record| {
-                    format!("{}, {}:{}",
-                            record.module(),
-                            record.file(),
-                            record.line()
-                    )
-                }
-                )
-        ),
-    );
-    Ok((slog_scope::set_global_logger(logger), log_file))
-}

walkeeper/Cargo.toml

@@ -13,11 +13,6 @@ bytes = "1.0.1"
 byteorder = "1.4.3"
 fs2 = "0.4.3"
 lazy_static = "1.4.0"
-slog-stdlog = "4.1.0"
-slog-async = "2.6.0"
-slog-scope = "4.4.0"
-slog-term = "2.8.0"
-slog = "2.7.0"
 log = "0.4.14"
 clap = "2.33.0"
 daemonize = "0.4.1"

walkeeper/src/bin/wal_acceptor.rs

@@ -1,15 +1,14 @@
 //
 // Main entry point for the wal_acceptor executable
 //
-use anyhow::{Context, Result};
+use anyhow::Result;
 use clap::{App, Arg};
 use daemonize::Daemonize;
 use log::*;
-use slog::Drain;
+use std::env;
 use std::path::{Path, PathBuf};
 use std::thread;
-use std::{env, io};
-use std::{fs::File, fs::OpenOptions};
+use zenith_utils::logging;
 
 use walkeeper::s3_offload;
 use walkeeper::wal_service;
@@ -113,20 +112,7 @@ fn main() -> Result<()> {
 
 fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
     let log_filename = conf.data_dir.join("wal_acceptor.log");
-    // Don't open the same file for output multiple times;
-    // the different fds could overwrite each other's output.
-    let log_file = OpenOptions::new()
-        .create(true)
-        .append(true)
-        .open(&log_filename)
-        .with_context(|| format!("failed to open {:?}", &log_filename))?;
-
-    // Initialize logger
-    let logger_file = log_file.try_clone().unwrap();
-    let _scope_guard = init_logging(&conf, logger_file)?;
-    let _log_guard = slog_stdlog::init().unwrap();
-    // Note: this `info!(...)` macro comes from `log` crate
-    info!("standard logging redirected to slog");
+    let (_scope_guard, log_file) = logging::init(log_filename, conf.daemonize)?;
 
     if conf.daemonize {
         info!("daemonizing...");
@@ -179,29 +165,3 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
     }
     Ok(())
 }
-
-fn init_logging(
-    conf: &WalAcceptorConf,
-    log_file: File,
-) -> Result<slog_scope::GlobalLoggerGuard, io::Error> {
-    if conf.daemonize {
-        let decorator = slog_term::PlainSyncDecorator::new(log_file);
-        let drain = slog_term::CompactFormat::new(decorator).build();
-        let drain = slog::Filter::new(drain, |record: &slog::Record| {
-            record.level().is_at_least(slog::Level::Info)
-        });
-        let drain = std::sync::Mutex::new(drain).fuse();
-        let logger = slog::Logger::root(drain, slog::o!());
-        Ok(slog_scope::set_global_logger(logger))
-    } else {
-        let decorator = slog_term::TermDecorator::new().build();
-        let drain = slog_term::FullFormat::new(decorator).build().fuse();
-        let drain = slog::Filter::new(drain, |record: &slog::Record| {
-            record.level().is_at_least(slog::Level::Info)
-        })
-        .fuse();
-        let drain = slog_async::Async::new(drain).chan_size(1000).build().fuse();
-        let logger = slog::Logger::root(drain, slog::o!());
-        Ok(slog_scope::set_global_logger(logger))
-    }
-}

zenith_utils/Cargo.toml

@@ -19,6 +19,12 @@ serde_json = "1"
 thiserror = "1.0"
 tokio = { version = "1.5.0", features = ["full"] }
 
+slog-async = "2.6.0"
+slog-stdlog = "4.1.0"
+slog-scope = "4.4.0"
+slog-term = "2.8.0"
+slog = "2.7.0"
+
 zenith_metrics = { path = "../zenith_metrics" }
 workspace_hack = { path = "../workspace_hack" }
 rand = "0.8.3"

zenith_utils/src/lib.rs

@@ -28,3 +28,6 @@ pub mod http;
 
 // socket splitting utils
 pub mod sock_split;
+
+// common log initialisation routine
+pub mod logging;

zenith_utils/src/logging.rs

@@ -0,0 +1,47 @@
+use slog::{Drain, Level};
+use std::{
+    fs::{File, OpenOptions},
+    path::Path,
+};
+
+use anyhow::{Context, Result};
+
+pub fn init(
+    log_filename: impl AsRef<Path>,
+    daemonize: bool,
+) -> Result<(slog_scope::GlobalLoggerGuard, File)> {
+    // Don't open the same file for output multiple times;
+    // the different fds could overwrite each other's output.
+    let log_file = OpenOptions::new()
+        .create(true)
+        .append(true)
+        .open(&log_filename)
+        .with_context(|| format!("failed to open {:?}", log_filename.as_ref()))?;
+
+    // we are cloning and returning log file in order to allow redirecting daemonized stdout and stderr to it
+    // if we do not use daemonization (e.g. in docker) it is better to log to stdout directly
+    // for example to be in line with docker log command which expects logs comimg from stdout
+    let guard = if daemonize {
+        let decorator = slog_term::PlainSyncDecorator::new(log_file.try_clone()?);
+        let drain = slog_term::FullFormat::new(decorator)
+            .build()
+            .filter_level(Level::Info)
+            .fuse();
+        let logger = slog::Logger::root(drain, slog::o!());
+        slog_scope::set_global_logger(logger)
+    } else {
+        let decorator = slog_term::TermDecorator::new().build();
+        let drain = slog_term::FullFormat::new(decorator)
+            .build()
+            .filter_level(Level::Info)
+            .fuse();
+        let drain = slog_async::Async::new(drain).chan_size(1000).build().fuse();
+        let logger = slog::Logger::root(drain, slog::o!());
+        slog_scope::set_global_logger(logger)
+    };
+
+    // initialise forwarding of std log calls
+    slog_stdlog::init()?;
+
+    Ok((guard, log_file))
+}