Merge pull request #1493 from akoshelev/log-file

Add an option to put helper logs into a file

ipa-core/src/cli/verbosity.rs

@@ -1,4 +1,8 @@
-use std::io::{stderr, IsTerminal};
+use std::{
+    fs::OpenOptions,
+    io::{stderr, IsTerminal},
+    path::PathBuf,
+};
 
 use clap::Parser;
 use tracing::{info, metadata::LevelFilter, Level};
@@ -20,6 +24,9 @@ pub struct Verbosity {
     /// Verbose mode (-v, or -vv for even more verbose)
     #[arg(short, long, action = clap::ArgAction::Count, global = true)]
     verbose: u8,
+
+    #[arg(long, help = "Specify the output file for logs")]
+    log_file: Option<PathBuf>,
 }
 
 pub struct LoggingHandle {
@@ -36,15 +43,33 @@ impl Verbosity {
         let filter_layer = self.log_filter();
         info!("Logging setup at level {}", filter_layer);
 
-        let fmt_layer = fmt::layer()
+        let stderr_writer = fmt::layer()
             .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
             .with_ansi(std::io::stderr().is_terminal())
             .with_writer(stderr);
 
-        tracing_subscriber::registry()
+        let registry = tracing_subscriber::registry()
             .with(filter_layer)
-            .with(fmt_layer)
-            .init();
+            .with(stderr_writer);
+
+        if let Some(path) = &self.log_file {
+            let log_file = OpenOptions::new()
+                .append(true)
+                .create(true)
+                .open(path)
+                .unwrap_or_else(|e| panic!("failed to open log file {path:?}: {e}"));
+            let file_writer = fmt::layer()
+                .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
+                .with_ansi(false)
+                .with_writer(log_file);
+
+            // that's the only stderr message that should appear to give a hint where
+            // the logs are written to
+            tracing::info!("Logs will be written to {path:?}");
+            registry.with(file_writer).init();
+        } else {
+            registry.init();
+        }
 
         let metrics_handle = install_collector().expect("Can install metrics");
 

ipa-core/tests/common/mod.rs

@@ -1,12 +1,12 @@
 use std::{
     array,
     error::Error,
-    io::{self, Write},
+    io::{self, Read, Write},
     net::TcpListener,
     ops::Deref,
     os::fd::AsRawFd,
-    path::Path,
-    process::{Child, Command, ExitStatus, Stdio},
+    path::{Path, PathBuf},
+    process::{Child, ChildStderr, Command, ExitStatus, Stdio},
 };
 
 use command_fds::CommandFdExt;
@@ -83,6 +83,9 @@ impl Drop for TerminateOnDrop {
     fn drop(&mut self) {
         if let Some(mut child) = self.0.take() {
             eprintln!("killing process {}", child.id());
+            if std::thread::panicking() {
+                print_stderr(child.stderr.as_mut());
+            }
             let _ = child.kill();
         }
     }
@@ -232,17 +235,23 @@ pub fn spawn_helpers(
     // (mpc port + shard port) for 3 helpers
     sockets: &[ShardTcpListeners; 3],
     https: bool,
+    log_files: Option<[PathBuf; 3]>,
 ) -> Vec<TerminateOnDrop> {
     sockets
         .iter()
         .enumerate()
-        .map(|(id, ShardTcpListeners { mpc, shard })| {
+        .zip(
+            log_files
+                .map(|v| v.map(Some))
+                .unwrap_or_else(|| [None, None, None]),
+        )
+        .map(|((id, ShardTcpListeners { mpc, shard }), log_file)| {
             let id = id + 1;
             let mut command = Command::new(HELPER_BIN);
             command
+                .stderr(Stdio::piped())
                 .args(["-i", &id.to_string()])
-                .args(["--network".into(), config_path.join("network.toml")])
-                .silent();
+                .args(["--network".into(), config_path.join("network.toml")]);
 
             if https {
                 command
@@ -260,13 +269,18 @@ pub fn spawn_helpers(
                 command.arg("--disable-https");
             }
 
+            if let Some(log_file) = log_file {
+                command.args(["--log-file".into(), log_file]);
+            }
+
             command.preserved_fds(vec![mpc.as_raw_fd(), shard.as_raw_fd()]);
             command.args(["--server-socket-fd", &mpc.as_raw_fd().to_string()]);
             command.args(["--shard-server-socket-fd", &shard.as_raw_fd().to_string()]);
 
             // something went wrong if command is terminated at this point.
             let mut child = command.spawn().unwrap();
             if let Ok(Some(status)) = child.try_wait() {
+                print_stderr(child.stderr.as_mut());
                 panic!("Helper binary terminated early with status = {status}");
             }
 
@@ -316,10 +330,25 @@ pub fn test_network<T: NetworkTest>(https: bool) {
     let path = dir.path();
 
     println!("generating configuration in {}", path.display());
+    let log_files = [
+        path.join("h1.log"),
+        path.join("h2.log"),
+        path.join("h3.log"),
+    ];
     let sockets = test_setup(path);
-    let _helpers = spawn_helpers(path, &sockets, https);
+    let _helpers = spawn_helpers(path, &sockets, https, Some(log_files.clone()));
 
     T::execute(path, https);
+
+    // check that helpers logged something
+    for log_file in log_files {
+        assert!(log_file.exists(), "log file {log_file:?} does not exist");
+        let log = std::fs::read_to_string(&log_file).unwrap();
+        assert!(
+            log.contains("server listening on"),
+            "Logs don't indicate that HTTP server has started: {log}"
+        );
+    }
 }
 
 pub fn test_sharded_network<const SHARDS: usize, T: NetworkTest<SHARDS>>(https: bool) {
@@ -364,7 +393,7 @@ pub fn test_ipa_with_config(
 
     println!("generating configuration in {}", path.display());
     let sockets = test_setup(path);
-    let _helpers = spawn_helpers(path, &sockets, https);
+    let _helpers = spawn_helpers(path, &sockets, https, None);
 
     // Gen inputs
     let inputs_file = dir.path().join("ipa_inputs.txt");
@@ -526,3 +555,10 @@ impl<const SHARDS: usize> NetworkTest<SHARDS> for ShardedShuffle {
         TerminateOnDrop::wait(test_mpc).unwrap_status();
     }
 }
+
+fn print_stderr(err_pipe: Option<&mut ChildStderr>) {
+    let stderr = err_pipe.unwrap();
+    let mut buf = String::new();
+    stderr.read_to_string(&mut buf).unwrap();
+    println!("stderr output:\n==begin==\n{buf}\n==end==")
+}

ipa-core/tests/helper_networks.rs

@@ -123,13 +123,13 @@ fn keygen_confgen() {
     }
 
     exec_conf_gen(false);
-    let helpers = spawn_helpers(path, &sockets, true);
+    let helpers = spawn_helpers(path, &sockets, true, None);
     test_multiply(path, true);
     drop(helpers);
 
     // now overwrite the configuration file and try again
     exec_conf_gen(true);
-    let helpers = spawn_helpers(path, &sockets, true);
+    let helpers = spawn_helpers(path, &sockets, true, None);
     test_multiply(path, true);
     drop(helpers);
 }