Strange output when using fork() in a for loop C

Question

I'm playing around with the following C code

int main(int argc, char **argv) {

int i;
int n;
int iterations;

if(argc != 2) {
    fprintf(stderr, "Usage: forkloop <iterations>\n");
    exit(1);
}

iterations = atoi(argv[1]);

for(i = 0; i < iterations; i++) {
    n = fork();
    if(n < 0) {
        perror("fork");
        exit(1);
    }
    //printf("pid = %d, i = %d\n", getpid(), i);
    printf("ppid = %d, pid = %d, i = %d\n", getppid(), getpid(), i);
}

return 0;
}

and getting the following output:

ppid = 16380, pid = 24628, i = 0
ppid = 16380, pid = 24628, i = 1
ppid = 16380, pid = 24628, i = 2
ppid = 24628, pid = 24629, i = 0
ppid = 24628, pid = 24629, i = 1
ppid = 24628, pid = 24629, i = 2
ppid = 16380, pid = 24628, i = 0
ppid = 24628, pid = 24630, i = 1
ppid = 24630, pid = 24635, i = 2

I find it very confusing that lines 1 and 7 of this output are the same. After reading this post I get the impression that each (child and parent) process should run normally as I would expect any C program to run, yet the program seems to be skipping back. What's going on here? I've tried this on 2 different machines (running Ubuntu 14.04, Ubuntu 12.04 and both with bash) now and received similarly confusing output on both.

This worked, thanks! What's going on behind the scenes here? — Atreus, Jul 02 '16 at 00:44
The program you posted isn't program you ran. It can't possibly output the same number of lines with i=0, i=1 and i=2. The program you posted outputs 2x i=0, 4x i=1, 8x i=2, etc. — ikegami, Jul 02 '16 at 00:44
@ikegami sure it is the same program. The child process will also execute the `printf()` — pah, Jul 02 '16 at 00:48
@threadp, Exactly, the parent and the child will print `i=0`. Whose the third? Then, those two processes will create a child each, for a total of 4 processes printing `i=1`. Then, those four processes will create a child each, for a total of 8 processes printing `i=2`. Try it yourself! — ikegami, Jul 02 '16 at 00:49
@ikegami `i` represent the iteration, and `iterations` is given from the command line. Each PID should iterate `iterations - i` times before dying. — pah, Jul 02 '16 at 00:52
@ikegami maybe there's something wrong here :). I haven't tried it yet, but I think you're right. — pah, Jul 02 '16 at 00:54
@ikegami This is indeed the program I ran, the reason I am posting here is because of such strange output. — Atreus, Jul 02 '16 at 01:11
That's not possible. Maybe you made some changes to the source after you last compiled it? Even if buffering caused weirdness, that would *add* output, not remove some. There needs to be 6 more lines with `i = 2`. Did you perhaps only post some of the output? [Actual output](http://pastebin.com/pCbs35Xu) (The `sleep` is there to prevent the prompt from appearing in the middle of the output.) — ikegami, Jul 02 '16 at 02:13
Are you writing the output to file or directly to the terminal? I strongly suspect this is a duplicate of [`printf()` anomaly after `fork()`](https://stackoverflow.com/questions/2530663/printf-anomaly-after-fork/2530870#2530870). — Jonathan Leffler, Jul 02 '16 at 05:50

score 0 · Answer 1 · answered Jul 02 '16 at 15:59

I'm not clear how you're getting the repeated line in the output. My best guess is that you're running into the problems detailed in printf() anomaly after fork().

I've created a mildly modified variant of your code. I modified your printing code to print the child PID (the value of n) as well as the parent process's information, and tarted up the format so that PIDs always occupy 5 spaces for alignment.

I added code to accept -i 3 for the number of iterations (default was 3 anyway), and to accept -w for processes to wait for all their children to die before exiting themselves.

Code

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

int main(int argc, char **argv)
{
    int i;
    int n;
    int waitmode = 0;
    int iterations = 3;

    int opt;
    while ((opt = getopt(argc, argv, "i:w")) != -1)
    {
        switch (opt)
        {
        case 'i':
            iterations = atoi(optarg);
            break;
        case 'w':
            waitmode = 1;
            break;
        default:
            exit(1);
        }
    }

    if (argc != optind)
    {
        fprintf(stderr, "Usage: forkloop [-i iterations] [-w]\n");
        exit(1);
    }

    for (i = 0; i < iterations; i++)
    {
        n = fork();
        if (n < 0)
        {
            perror("fork");
            exit(1);
        }
        // printf("pid = %5d, i = %d\n", getpid(), i);
        printf("ppid = %5d, pid = %5d, i = %d (n = %5d)\n", getppid(), getpid(), i, n);
    }

    if (waitmode)
    {
        int status;
        int corpse;
        while ((corpse = wait(&status)) != -1)
        {
            printf("ppid = %5d, pid = %5d, corpse = %5d, status = 0x%.4X\n",
                    getppid(), getpid(), corpse, status);
        }
    }

    return 0;
}

Sample runs

For better or worse, I called the program pff19 instead of forkloop. I was testing on Mac OS X 10.11.5 with GCC 6.1.0. The machine has an Intel Core i7 chip so it has multiple cores. This matters when there isn't waiting; the PPID 1 indicates that the process's parent had died before the child got to report. You can see in the last set of output that PID 15908 first reported PPID 15907 then PPID 1.

When the output of the program is piped through cat, the output is fully buffered, so child processes have in their output buffer data that its parent has already printed but that has not yet been flushed — that's the 'printf() anomaly after fork()' behaviour.

$ pff19 -i 3 | cat
ppid = 85956, pid = 15878, i = 0 (n = 15880)
ppid = 85956, pid = 15878, i = 1 (n = 15881)
ppid = 85956, pid = 15878, i = 2 (n = 15882)
ppid = 85956, pid = 15878, i = 0 (n = 15880)
ppid = 85956, pid = 15878, i = 1 (n = 15881)
ppid =     1, pid = 15882, i = 2 (n =     0)
ppid = 85956, pid = 15878, i = 0 (n = 15880)
ppid = 15878, pid = 15881, i = 1 (n =     0)
ppid =     1, pid = 15881, i = 2 (n = 15884)
ppid = 15878, pid = 15880, i = 0 (n =     0)
ppid =     1, pid = 15880, i = 1 (n = 15883)
ppid =     1, pid = 15880, i = 2 (n = 15885)
ppid = 85956, pid = 15878, i = 0 (n = 15880)
ppid = 15878, pid = 15881, i = 1 (n =     0)
ppid =     1, pid = 15884, i = 2 (n =     0)
ppid = 15878, pid = 15880, i = 0 (n =     0)
ppid =     1, pid = 15880, i = 1 (n = 15883)
ppid =     1, pid = 15885, i = 2 (n =     0)
ppid = 15878, pid = 15880, i = 0 (n =     0)
ppid = 15880, pid = 15883, i = 1 (n =     0)
ppid =     1, pid = 15883, i = 2 (n = 15886)
ppid = 15878, pid = 15880, i = 0 (n =     0)
ppid = 15880, pid = 15883, i = 1 (n =     0)
ppid = 15883, pid = 15886, i = 2 (n =     0)
$ pff19 -w -i 3 | cat
ppid = 85956, pid = 15888, i = 0 (n = 15890)
ppid = 85956, pid = 15888, i = 1 (n = 15891)
ppid = 15888, pid = 15892, i = 2 (n =     0)
ppid = 85956, pid = 15888, i = 0 (n = 15890)
ppid = 15888, pid = 15891, i = 1 (n =     0)
ppid = 15891, pid = 15895, i = 2 (n =     0)
ppid = 15888, pid = 15890, i = 0 (n =     0)
ppid = 15888, pid = 15890, i = 1 (n = 15893)
ppid = 15890, pid = 15894, i = 2 (n =     0)
ppid = 15888, pid = 15890, i = 0 (n =     0)
ppid = 15890, pid = 15893, i = 1 (n =     0)
ppid = 15893, pid = 15896, i = 2 (n =     0)
ppid = 85956, pid = 15888, i = 0 (n = 15890)
ppid = 15888, pid = 15891, i = 1 (n =     0)
ppid = 15888, pid = 15891, i = 2 (n = 15895)
ppid = 15888, pid = 15891, corpse = 15895, status = 0x0000
ppid = 15888, pid = 15890, i = 0 (n =     0)
ppid = 15890, pid = 15893, i = 1 (n =     0)
ppid = 15890, pid = 15893, i = 2 (n = 15896)
ppid = 15890, pid = 15893, corpse = 15896, status = 0x0000
ppid = 15888, pid = 15890, i = 0 (n =     0)
ppid = 15888, pid = 15890, i = 1 (n = 15893)
ppid = 15888, pid = 15890, i = 2 (n = 15894)
ppid = 15888, pid = 15890, corpse = 15894, status = 0x0000
ppid = 15888, pid = 15890, corpse = 15893, status = 0x0000
ppid = 85956, pid = 15888, i = 0 (n = 15890)
ppid = 85956, pid = 15888, i = 1 (n = 15891)
ppid = 85956, pid = 15888, i = 2 (n = 15892)
ppid = 85956, pid = 15888, corpse = 15892, status = 0x0000
ppid = 85956, pid = 15888, corpse = 15891, status = 0x0000
ppid = 85956, pid = 15888, corpse = 15890, status = 0x0000
$ pff19 -w -i 3 
ppid = 85956, pid = 15898, i = 0 (n = 15899)
ppid = 85956, pid = 15898, i = 1 (n = 15900)
ppid = 15898, pid = 15899, i = 0 (n =     0)
ppid = 85956, pid = 15898, i = 2 (n = 15901)
ppid = 15898, pid = 15899, i = 1 (n = 15902)
ppid = 15898, pid = 15900, i = 1 (n =     0)
ppid = 15898, pid = 15901, i = 2 (n =     0)
ppid = 15898, pid = 15899, i = 2 (n = 15903)
ppid = 15898, pid = 15900, i = 2 (n = 15904)
ppid = 15899, pid = 15902, i = 1 (n =     0)
ppid = 85956, pid = 15898, corpse = 15901, status = 0x0000
ppid = 15899, pid = 15902, i = 2 (n = 15905)
ppid = 15899, pid = 15903, i = 2 (n =     0)
ppid = 15900, pid = 15904, i = 2 (n =     0)
ppid = 15898, pid = 15899, corpse = 15903, status = 0x0000
ppid = 15902, pid = 15905, i = 2 (n =     0)
ppid = 15898, pid = 15900, corpse = 15904, status = 0x0000
ppid = 15899, pid = 15902, corpse = 15905, status = 0x0000
ppid = 85956, pid = 15898, corpse = 15900, status = 0x0000
ppid = 15898, pid = 15899, corpse = 15902, status = 0x0000
ppid = 85956, pid = 15898, corpse = 15899, status = 0x0000
$ pff19 -i 3 
ppid = 85956, pid = 15907, i = 0 (n = 15908)
ppid = 85956, pid = 15907, i = 1 (n = 15909)
ppid = 15907, pid = 15908, i = 0 (n =     0)
ppid = 85956, pid = 15907, i = 2 (n = 15910)
ppid = 15907, pid = 15908, i = 1 (n = 15911)
ppid = 15907, pid = 15909, i = 1 (n =     0)
ppid = 15907, pid = 15910, i = 2 (n =     0)
ppid = 15907, pid = 15909, i = 2 (n = 15913)
ppid =     1, pid = 15908, i = 2 (n = 15912)
ppid = 15908, pid = 15911, i = 1 (n =     0)
ppid =     1, pid = 15913, i = 2 (n =     0)
ppid =     1, pid = 15911, i = 2 (n = 15914)
ppid =     1, pid = 15912, i = 2 (n =     0)
ppid =     1, pid = 15914, i = 2 (n =     0)
$

Strange output when using fork() in a for loop C

1 Answers1

Code

Sample runs