How to log Child process in separate files?

Question

I'm use std::process::Command to spawn 3 child processes as below:

let args = ["run", "--features", "my-feat"];
for i in 0..3 {
  let _process = Command::new("cargo").env(..).args(..).spawn().expect("Failed to spawn");
}

Currently I'm logging it our using the command:

RUST_LOG=trace cargo test my-test --test integration_tests -- --nocapture > testfile.log 2>&1

This logs all the output of all the child processes in a single file testfile.log which becomes very difficult to debug. I want to log the output each 3 child processes in their own log files: testfile1.log, testfile2.log, testfile3.log.

How can I do that?

Also, I face a similar issue when I display the output on stdout instead of logging. The outputs of the child processes don't have any prefix so it's impossible to figure out which output statement corresponds to which child process. Currently this is the output:

Child process
Child process
Child process

I'm looking for something like below:

[0] Child process
[1] Child process
[2] Child process

Masklinn · Answer 1 · 2023-02-09T12:47:27.203

How can I do that?

Use direct file output in your program, or use additional fds.

As-is, your main program is getting the default stdout (conventionally fd 1) and the child processes just inherit that, so all children output directly to fd1 without any intermediate processing, or the ability to split the stream, they're literally writing to the same OS-level object.

The easiest way to fix this is to open 3 files in the main process, convert the files to Stdio structures, then set that as the children's stdout. This way the children will write to different files, and you can merge the files later, or not.

The alternative is somewhat more involved and unconventional: stdin, stdout, and stderr are just fds 0, 1, and 2. But nothing prevents having more of them, they just don't exist by default:

❯ python -c 'open(3, "a").write("ok")'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
OSError: [Errno 9] Bad file descriptor
❯ python -c 'open(3, "a").write("ok")' 3>&1
ok%                                                                                                                          ❯ python -c 'open(3, "a").write("ok")' 3>/dev/null

Doing the same in rust is a bit more complex, but you can use something like libc to try to open the relevant fds, if they exist convert them to owned fds then to Stdio objects which you can pass to Command.

If they don't exist, you can fallback to inheriting stdout, or to a File-based Stdio as above.

The outputs of the child processes don't have any prefix so it's impossible to figure out which output statement corresponds to which child process. Currently this is the output:

I don't think that's possible without an intermediate process which decorates output.

In that case what you'd do is spawn each child with an .stdout(Stdio::piped()). From this you can get a ChildStdout for each child, which you then convert to an Stdio, which you can then pass as stdin to a second process which reads lines from its input and adds a prefix of some sort (a different one for each child). You could just use sed or awk or ed for that.

The second process would then inherit the stdout from the main / bootstrapping program, and every line from every child would get written out to the original stdout, just with a prefix.

score 1 · Answer 2 · answered Feb 09 '23 at 13:09

Masklinn addded a pretty good explanation of what you have to do. But I thought I'd add some practical examples too.

An easy and safe solution would be to just create the files in the test itself:

use std::{fs::File, process::Command};

#[test]
fn test() {
    for i in 0..3 {
        let o = File::create(format!("log{i}.stdout")).unwrap();
        let e = File::create(format!("log{i}.stderr")).unwrap();
        Command::new("cargo")
            .arg("run")
            .stdout(o)
            .stderr(e)
            .spawn()
            .unwrap();
    }
}

Also using file descriptors isn't that convoluted:

use std::{fs::File, os::fd::FromRawFd, process::Command};
#[test]
fn test() {
    for i in 0..3 {
        let o = unsafe { File::from_raw_fd(i + 3) };
        let e = unsafe { File::from_raw_fd(i + 3) };
        // Command as before ommited for brevity
    }
}

RUST_LOG=trace cargo test -- --nocapture 3>log0 4>log1 5>log2

But make sure that in anything but a simple test you check that the file descriptor actually exists before blindly creating a File from it.

For the prefixes I agree with Maskilnn that you have to have some process running which prefixes your output for the last bit, but it can just be the test runner itself:

#[test]
fn test() {
    let procs: Vec<_> = (0..3)
        .map(|i| {
            let p = Command::new("cargo")
                .arg("run")
                .stdout(Stdio::piped())
                .stderr(Stdio::piped())
                .spawn()
                .unwrap();
            let stdout = BufReader::new(p.stdout.unwrap());
            let stdout = std::thread::spawn(move || {
                for line in stdout.lines() {
                    let line = line.unwrap();
                    println!("{i}: {line}");
                }
            });
            let stderr = BufReader::new(p.stderr.unwrap());
            let stderr = std::thread::spawn(move || {
                for line in stderr.lines() {
                    let line = line.unwrap();
                    eprintln!("{i}: {line}");
                }
            });
            (stdout, stderr)
        })
        .collect();
    // wait untill we processed all output
    for (o, e) in procs {
        o.join().unwrap();
        e.join().unwrap();
    }
}

Of course all unwrap are just used for brevity, use expect instead to provide useful information on errors.

How to log Child process in separate files?

2 Answers2