Don't use tee to split output (#231)

* Don't use `tee` to split output

* Restore behaviour

* Clippy

* Drop stray print

build-trycp.sh

@@ -2,5 +2,4 @@
 set -e
 
 # build TryCP server
-cd crates/trycp_server
-cargo build --release --target-dir target
+cargo build --release --manifest-path crates/trycp_server/Cargo.toml

crates/trycp_server/src/download_logs.rs

@@ -35,14 +35,14 @@ pub(crate) fn download_logs(id: String) -> Result<MessageResponse, DownloadLogsE
     let player_dir = get_player_dir(&id);
 
     let lair_stderr = player_dir.join(LAIR_STDERR_LOG_FILENAME);
-    let lair_stderr = std::fs::read(&lair_stderr).context(LairStdErr { id: id.clone() })?;
+    let lair_stderr = std::fs::read(lair_stderr).context(LairStdErr { id: id.clone() })?;
 
     let conductor_stdout = player_dir.join(CONDUCTOR_STDOUT_LOG_FILENAME);
     let conductor_stdout =
-        std::fs::read(&conductor_stdout).context(HolochainStdout { id: id.clone() })?;
+        std::fs::read(conductor_stdout).context(HolochainStdout { id: id.clone() })?;
 
     let conductor_stderr = player_dir.join(CONDUCTOR_STDERR_LOG_FILENAME);
-    let conductor_stderr = std::fs::read(&conductor_stderr).context(HolochainStderr { id })?;
+    let conductor_stderr = std::fs::read(conductor_stderr).context(HolochainStderr { id })?;
 
     Ok(MessageResponse::Bytes(
         rmp_serde::to_vec_named(&TryCpServerResponse::DownloadLogs(DownloadLogsResponse {

crates/trycp_server/src/startup.rs

@@ -1,22 +1,24 @@
-use std::{
-    io::{self, BufRead, BufReader, Write},
-    path::PathBuf,
-    process::{Command, Stdio},
-};
-
-use snafu::{OptionExt, ResultExt, Snafu};
-
 use crate::{
     get_player_dir, PlayerProcesses, CONDUCTOR_CONFIG_FILENAME, CONDUCTOR_MAGIC_STRING,
     CONDUCTOR_STDERR_LOG_FILENAME, CONDUCTOR_STDOUT_LOG_FILENAME, LAIR_MAGIC_STRING,
     LAIR_PASSPHRASE, LAIR_STDERR_LOG_FILENAME, PLAYERS,
 };
+use snafu::{OptionExt, ResultExt, Snafu};
+use std::io::Lines;
+use std::process::ChildStdout;
+use std::{
+    io::{self, BufRead, BufReader, Write},
+    path::PathBuf,
+    process::{Command, Stdio},
+};
 
 #[derive(Debug, Snafu)]
 pub enum Error {
     #[snafu(display("Could not find a configuration for player with ID {:?}", id))]
     PlayerNotConfigured { id: String },
-    #[snafu(display("Could not create log file at {} for lair-keystore's stdout: {}", path.display(), source))]
+    #[snafu(display(
+        "Could not create log file at {} for lair-keystore's stdout: {}", path.display(), source
+    ))]
     CreateLairStdoutFile { path: PathBuf, source: io::Error },
     #[snafu(display("Could not spawn lair-keystore: {}", source))]
     SpawnLair { source: io::Error },
@@ -27,8 +29,6 @@ pub enum Error {
     CheckLairReady { source: io::Error },
     #[snafu(display("Could not spawn holochain: {}", source))]
     SpawnHolochain { source: io::Error },
-    #[snafu(display("Could not spawn tee: {}", source))]
-    SpawnTee { source: io::Error },
     #[snafu(display(
         "Could not check holochain's output to confirm that it's ready: {}",
         source
@@ -83,15 +83,14 @@ pub fn startup(id: String, log_level: Option<String>) -> Result<(), Error> {
         }
 
         {
-            // Wait until lair begins to output before starting conductor,
-            // otherwise Holochain starts its own copy of lair that we can't manage.
-            for line in BufReader::new(lair.stdout.take().unwrap()).lines() {
-                let line = line.context(CheckLairReady)?;
-                if line == LAIR_MAGIC_STRING {
-                    println!("Encountered magic lair string");
-                    break;
-                }
-            }
+            // Wait until lair begins to output before starting conductor.
+            stream_output_with_ready(
+                lair.stdout.take().unwrap(),
+                LAIR_MAGIC_STRING,
+                None,
+                format!("lair-keystore({id})"),
+            )
+            .context(CheckLairReady)?;
         }
 
         let mut conductor = Command::new("holochain")
@@ -126,29 +125,70 @@ pub fn startup(id: String, log_level: Option<String>) -> Result<(), Error> {
         });
     }
 
-    let mut log_stdout = Command::new("tee")
-        .arg(player_dir.join(CONDUCTOR_STDOUT_LOG_FILENAME))
-        .arg("--append")
-        .stdout(Stdio::piped())
-        .stdin(conductor_stdout)
-        .spawn()
-        .context(SpawnTee)?;
-
-    let _log_stderr = Command::new("tee")
-        .arg(player_dir.join(CONDUCTOR_STDERR_LOG_FILENAME))
-        .arg("--append")
-        .stdin(conductor_stderr)
-        .spawn()
-        .context(SpawnTee)?;
-
-    for line in BufReader::new(log_stdout.stdout.take().unwrap()).lines() {
-        let line = line.context(CheckHolochainReady)?;
-        if line == CONDUCTOR_MAGIC_STRING {
-            println!("Encountered magic conductor string");
+    stream_output_with_ready(
+        conductor_stdout,
+        CONDUCTOR_MAGIC_STRING,
+        Some(player_dir.join(CONDUCTOR_STDOUT_LOG_FILENAME)),
+        format!("holochain({id})"),
+    )
+    .context(CheckHolochainReady)?;
+
+    stream_output(
+        BufReader::new(conductor_stderr).lines(),
+        Some(player_dir.join(CONDUCTOR_STDERR_LOG_FILENAME)),
+        format!("holochain({id})"),
+    );
+
+    println!("conductor started up for {}", id);
+    Ok(())
+}
+
+fn open_log_file(path: PathBuf) -> io::Result<std::fs::File> {
+    std::fs::OpenOptions::new()
+        .create(true)
+        .append(true)
+        .open(path)
+}
+
+fn stream_output_with_ready(
+    stdout: ChildStdout,
+    ready_line: &str,
+    into_file: Option<PathBuf>,
+    context: String,
+) -> io::Result<()> {
+    let mut f = into_file.clone().map(open_log_file).transpose()?;
+
+    let mut reader = BufReader::new(stdout).lines();
+    for line in &mut reader {
+        let line = line?;
+        if let Some(f) = &mut f {
+            writeln!(f, "{}: {}", context, line)?;
+        }
+        println!("{context}: {line}");
+        if line == ready_line {
+            if let Some(f) = f {
+                drop(f);
+            }
+            stream_output(reader, into_file, context);
             break;
         }
     }
 
-    println!("conductor started up for {}", id);
     Ok(())
 }
+
+fn stream_output<B: BufRead + Send + 'static>(
+    mut reader: Lines<B>,
+    into_file: Option<PathBuf>,
+    context: String,
+) {
+    tokio::task::spawn_blocking(move || {
+        let mut f = into_file.clone().map(open_log_file).transpose().unwrap();
+        while let Some(Ok(line)) = reader.next() {
+            if let Some(f) = &mut f {
+                writeln!(f, "{}: {}", context, line).unwrap();
+            }
+            println!("{context}: {line}");
+        }
+    });
+}

ts/test/trycp/client.ts

@@ -315,7 +315,7 @@ test("TryCP Server - App API - get app info", async (t) => {
   await localTryCpServer.stop();
 });
 
-test("TryCP Client - download logs", async (t) => {
+test.only("TryCP Client - download logs", async (t) => {
   const localTryCpServer = await TryCpServer.start();
   const tryCpClient = await createTryCpClient();
   const conductor = await createTryCpConductor(tryCpClient);