linux pipe: capture output from forked child

user_3853711 0
Viewed 27

I am having a simple program to send numbers 0 to 2 into a pipe, then function fork_child receive number from this pipe and print out the 1st number it receive and send following number into another pipe connecting to the next child created by fork_child:

#include <stdio.h>
#include <stdlib.h>
#include <sys/wait.h>
#include <unistd.h>

void fork_child(int port_in, int generation) {
    int number;
    int receive_first_number = 0;
    int pid = -1;
    int fd[2];

    while (read(port_in, &number, sizeof(number)) != 0) {
        if (receive_first_number == 0) {
            receive_first_number = 1;
            printf("child-%d (pid %d) receives: %d\n", generation, getpid(), number);
            continue;
        }

        if (pid == -1) {
            // execute only once to create child
            pipe(fd);
            pid = fork();
            if (pid == 0) {
                // child process
                close(fd[1]);
                fork_child(fd[0], generation + 1);
                close(fd[0]);
                exit(0);
            } else {
                // parent process
                close(fd[0]);
            }
        }
        // send number to next child
        write(fd[1], &number, sizeof(number));
    }

    close(fd[1]);
    wait(&pid);
}

int main() {
    int fd[2];
    pipe(fd);

    int pid = fork();
    if (pid == 0) {
        // child process
        close(fd[1]);
        fork_child(fd[0], 0);
        close(fd[0]);
        exit(0);
    } else {
        // parent process
        close(fd[0]);
        for (int number = 0; number < 3; number++) {
            write(fd[1], &number, sizeof(number));
        }
        close(fd[1]);
        wait(&pid);
    }

    return 0;
}

It works as expected when running:

$ ./pipe
child-0 (pid 149437) receives: 0
child-1 (pid 149438) receives: 1
child-2 (pid 149439) receives: 2

execept capturing the output and redirect into a file:

$ ./pipe > out
$ cat out
child-0 (pid 151246) receives: 0
child-1 (pid 151247) receives: 1
child-2 (pid 151248) receives: 2
child-0 (pid 151246) receives: 0
child-1 (pid 151247) receives: 1
child-0 (pid 151246) receives: 0

Why is captured output different from what it was without pipe and redirecting?

concurrency pipe fork linux c
1 Answers

This is a concurrency bug that depends on buffering:

$ stdbuf -o 0 ./pipe 
child-0 (pid 864370) receives: 0
child-1 (pid 864371) receives: 1
child-2 (pid 864372) receives: 2
$ stdbuf -o 0 ./pipe > out && cat out
child-0 (pid 864355) receives: 0
child-1 (pid 864356) receives: 1
child-2 (pid 864357) receives: 2
$ stdbuf -o L ./pipe 
child-0 (pid 866493) receives: 0
child-1 (pid 866494) receives: 1
child-2 (pid 866495) receives: 2
$ stdbuf -o L ./pipe > out && cat out
child-0 (pid 866501) receives: 0
child-1 (pid 866502) receives: 1
child-2 (pid 866503) receives: 2
$ stdbuf -o 4096 ./pipe 
child-0 (pid 864399) receives: 0
child-1 (pid 864400) receives: 1
child-2 (pid 864401) receives: 2
child-0 (pid 864399) receives: 0
child-1 (pid 864400) receives: 1
child-0 (pid 864399) receives: 0
$ stdbuf -o 4096 ./pipe > out && cat out
child-0 (pid 864385) receives: 0
child-1 (pid 864386) receives: 1
child-2 (pid 864387) receives: 2
child-0 (pid 864385) receives: 0
child-1 (pid 864386) receives: 1
child-0 (pid 864385) receives: 0

Note that this type of buffering only affects printf(), not read() or write().

When there's no buffering (stdbuf -o 0), or when buffering is done every line (stdbuf -o L), printf() will flush its write buffer immediately after printing.

When redirecting to a file, the buffer is much bigger (e.g. 4k bytes), and printf() will not flush that buffer.
And then you fork(). But printf()'s buffer is a userspace thing, and the kernel isn't aware of it, so after fork() both the parent and child have a copy of the buffer.
After 2 such forks, the buffer contains all 3 prints, which the 3rd child will print.
But the 2nd child isn't aware that the 3rd child already printed everything, and it will print its buffer, which contains the first 2 prints. Similarly, the 1st child will print its buffer, which legitimately contains only its own print.
That's how you get 0, 1, 2 (from 3rd child), 0, 1 (from 2nd child), 0 (from first child).

You can see that with strace(1) by checking the amount of bytes written:

$ strace -o /tmp/trace -f ./x && grep 'write.*child-' /tmp/trace
child-0 (pid 867548) receives: 0
child-1 (pid 867549) receives: 1
child-2 (pid 867550) receives: 2
867548 write(1, "child-0 (pid 867548) receives: 0"..., 33) = 33
867549 write(1, "child-1 (pid 867549) receives: 1"..., 33) = 33
867550 write(1, "child-2 (pid 867550) receives: 2"..., 33) = 33
$ strace -o /tmp/trace -f ./x > out && cat out && grep 'write.*child-' /tmp/trace
child-0 (pid 867515) receives: 0
child-1 (pid 867516) receives: 1
child-2 (pid 867517) receives: 2
child-0 (pid 867515) receives: 0
child-1 (pid 867516) receives: 1
child-0 (pid 867515) receives: 0
867517 write(1, "child-0 (pid 867515) receives: 0"..., 99) = 99
867516 write(1, "child-0 (pid 867515) receives: 0"..., 66) = 66
867515 write(1, "child-0 (pid 867515) receives: 0"..., 33) = 33

Possible solutions:

  • Be explicit about buffer size
  • fflush() after printf()

See also this question.

user_106789550
Related