don't open log files multiple times

Multiple fds writing to the same file doesn't work. One fd will
overwrite the output of the other fd. We were opening log files three
times (stdout, stderr, and slog).

The symptoms can be seen when the program panics; the final file will
have truncated or lost messages. After this change, all messages are
preserved. If panicking and logging are concurrent (and they definitely
can be), some of the messages may be interleaved in slightly
inconvenient ways.

File::try_clone() is essentially `dup` underneath, meaning the two will
share the same file offset.

pageserver/src/bin/pageserver.rs

@@ -4,7 +4,7 @@
 
 use log::*;
 use parse_duration::parse;
-use std::fs::{self, OpenOptions};
+use std::fs::{self, File, OpenOptions};
 use std::io;
 use std::process::exit;
 use std::thread;
@@ -98,8 +98,19 @@ fn main() -> Result<()> {
 }
 
 fn start_pageserver(conf: &PageServerConf) -> Result<()> {
+    let repodir = zenith_repo_dir();
+    let log_filename = repodir.join("pageserver.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 _scope_guard = init_logging(&conf)?;
+    let logger_file = log_file.try_clone().unwrap();
+    let _scope_guard = init_logging(&conf, logger_file)?;
     let _log_guard = slog_stdlog::init()?;
 
     // Note: this `info!(...)` macro comes from `log` crate
@@ -124,21 +135,10 @@ fn start_pageserver(conf: &PageServerConf) -> Result<()> {
     if conf.daemonize {
         info!("daemonizing...");
 
-        let repodir = zenith_repo_dir();
-
         // There should'n be any logging to stdin/stdout. Redirect it to the main log so
         // that we will see any accidental manual fprintf's or backtraces.
-        let log_filename = repodir.join("pageserver.log");
-        let stdout = OpenOptions::new()
-            .create(true)
-            .append(true)
-            .open(&log_filename)
-            .with_context(|| format!("failed to open {:?}", &log_filename))?;
-        let stderr = OpenOptions::new()
-            .create(true)
-            .append(true)
-            .open(&log_filename)
-            .with_context(|| format!("failed to open {:?}", &log_filename))?;
+        let stdout = log_file.try_clone().unwrap();
+        let stderr = log_file;
 
         let daemonize = Daemonize::new()
             .pid_file(repodir.join("pageserver.pid"))
@@ -199,20 +199,13 @@ fn start_pageserver(conf: &PageServerConf) -> Result<()> {
     Ok(())
 }
 
-fn init_logging(conf: &PageServerConf) -> Result<slog_scope::GlobalLoggerGuard, io::Error> {
+fn init_logging(
+    conf: &PageServerConf,
+    log_file: File,
+) -> Result<slog_scope::GlobalLoggerGuard, io::Error> {
     if conf.interactive {
         Ok(tui::init_logging())
     } else if conf.daemonize {
-        let log = zenith_repo_dir().join("pageserver.log");
-        let log_file = OpenOptions::new()
-            .create(true)
-            .append(true)
-            .open(&log)
-            .map_err(|err| {
-                // We failed to initialize logging, so we can't log this message with error!
-                eprintln!("Could not create log file {:?}: {}", log, err);
-                err
-            })?;
         let decorator = slog_term::PlainSyncDecorator::new(log_file);
         let drain = slog_term::FullFormat::new(decorator).build();
         let drain = slog::Filter::new(drain, |record: &slog::Record| {

walkeeper/src/bin/wal_acceptor.rs

@@ -1,20 +1,18 @@
 //
 // Main entry point for the wal_acceptor executable
 //
+use anyhow::{Context, Result};
+use clap::{App, Arg};
 use daemonize::Daemonize;
 use log::*;
 use parse_duration::parse;
+use slog::Drain;
 use std::io;
 use std::path::{Path, PathBuf};
 use std::thread;
 use std::time::Duration;
 use std::{fs::File, fs::OpenOptions};
 
-use anyhow::Result;
-use clap::{App, Arg};
-
-use slog::Drain;
-
 use walkeeper::s3_offload;
 use walkeeper::wal_service;
 use walkeeper::WalAcceptorConf;
@@ -115,8 +113,18 @@ 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 _scope_guard = init_logging(&conf)?;
+    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");
@@ -126,16 +134,8 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
 
         // There should'n be any logging to stdin/stdout. Redirect it to the main log so
         // that we will see any accidental manual fprintf's or backtraces.
-        let stdout = OpenOptions::new()
-            .create(true)
-            .append(true)
-            .open("wal_acceptor.log")
-            .unwrap();
-        let stderr = OpenOptions::new()
-            .create(true)
-            .append(true)
-            .open("wal_acceptor.log")
-            .unwrap();
+        let stdout = log_file.try_clone().unwrap();
+        let stderr = log_file;
 
         let daemonize = Daemonize::new()
             .pid_file("wal_acceptor.pid")
@@ -178,14 +178,11 @@ fn start_wal_acceptor(conf: WalAcceptorConf) -> Result<()> {
     Ok(())
 }
 
-fn init_logging(conf: &WalAcceptorConf) -> Result<slog_scope::GlobalLoggerGuard, io::Error> {
+fn init_logging(
+    conf: &WalAcceptorConf,
+    log_file: File,
+) -> Result<slog_scope::GlobalLoggerGuard, io::Error> {
     if conf.daemonize {
-        let log = conf.data_dir.join("wal_acceptor.log");
-        let log_file = File::create(&log).map_err(|err| {
-            // We failed to initialize logging, so we can't log this message with error!
-            eprintln!("Could not create log file {:?}: {}", log, err);
-            err
-        })?;
         let decorator = slog_term::PlainSyncDecorator::new(log_file);
         let drain = slog_term::CompactFormat::new(decorator).build();
         let drain = std::sync::Mutex::new(drain).fuse();