[SOLVED] Why is my C program output not in the same order as when I redirect it to a file ?

Sxing · 11-15-2021, 02:32 AM

It's a multi-threading program synchronized with semaphore. According to my knowledge, those three thread should print one by one, at least in this way.
And if I redirect it to a file, it seems the lines are organized by thread and the print line in father thread is repeated 3 times ???
I am a rookie in multi-threading programming. please help me.

compiled with gcc -pthread on Ubuntu x86/64

Code:

#include <sys/sem.h>
#include <stdio.h>
#include <sys/types.h>
#include <stdlib.h>
#include <sys/ipc.h>
#include <sys/shm.h>
#include <unistd.h>
#include <errno.h>
#include <string.h>
#include <fcntl.h>
#include <semaphore.h>
#include <sys/stat.h>
#include <time.h>
#include <sys/wait.h>

int main()
{
    int pipe_fd[2];
    int status = 20;
    char buffer[4096]; //会初始化为0吗？Y
    pid_t pid1, pid2, pid3;
    sem_t *pipe_mutex;
    pipe_mutex = sem_open("pipe_mutex", O_CREAT | O_RDWR, 0666, 0);

    printf("init\n");

    if ((pid1 = fork()) == 0)
    {

        printf("child1 init.\n");
        // fflush(stdout);
        while (status >= 0)
        {
            sem_wait(pipe_mutex);
            fprintf(stdout, "child1 start writing\n");
            // fflush(stdout);
            // status = write(pipe_fd[1], buffer, 128);
            fprintf(stdout, "child1 write %d\n", status);
            // fflush(stdout);
            // sleep(1);
            sem_post(pipe_mutex);
            status--;
        }
        exit(0);
    }
    else if ((pid2 = fork()) == 0)
    {

        printf("child2 init.\n");
        // fflush(stdout);
        while (status >= 0)
        {
            sem_wait(pipe_mutex);
            fprintf(stdout, "child2 start writing\n");
            // fflush(stdout);
            // status = write(pipe_fd[1], buffer, 2047);
            fprintf(stdout, "child2 write %d\n", status);
            // fflush(stdout);
            // sleep(1);
            sem_post(pipe_mutex);
            status--;
        }

        exit(0);
    }
    else if ((pid3 = fork()) == 0)
    {

        printf("child3 init.\n");
        // fflush(stdout);
        while (status >= 0)
        {
            sem_wait(pipe_mutex);
            fprintf(stdout, "child3 start writing\n");
            // fflush(stdout);
            // status = write(pipe_fd[1], buffer, 4200);
            fprintf(stdout, "child3 write %d\n", status);
            // fflush(stdout);
            // sleep(1);
            sem_post(pipe_mutex);
            status--;
        }

        exit(0);
    }
    else
    {
        // getchar(); //这个语句在这里的作用是什么？type anything and enter to start
        sem_post(pipe_mutex);
        wait(0);
        wait(0);
        wait(0);
        // pipe_left_size(pipe_fd, pipe_mutex); //这两个函数的作用又是什么？
        printf("end\n");
        // sem_unlink("pipe_mutex");
    }

    return 0;
}

in a file:
init
child1 init.
child1 start writing
child1 write 20
child1 start writing
child1 write 19
child1 start writing
child1 write 18
child1 start writing
child1 write 17
child1 start writing
child1 write 16
child1 start writing
child1 write 15
child1 start writing
child1 write 14
child1 start writing
child1 write 13
child1 start writing
child1 write 12
child1 start writing
child1 write 11
child1 start writing
child1 write 10
child1 start writing
child1 write 9
child1 start writing
child1 write 8
child1 start writing
child1 write 7
child1 start writing
child1 write 6
child1 start writing
child1 write 5
child1 start writing
child1 write 4
child1 start writing
child1 write 3
child1 start writing
child1 write 2
child1 start writing
child1 write 1
child1 start writing
child1 write 0
init
child2 init.
child2 start writing
child2 write 20
child2 start writing
child2 write 19
child2 start writing
child2 write 18
child2 start writing
child2 write 17
child2 start writing
child2 write 16
child2 start writing
child2 write 15
child2 start writing
child2 write 14
child2 start writing
child2 write 13
child2 start writing
child2 write 12
child2 start writing
child2 write 11
child2 start writing
child2 write 10
child2 start writing
child2 write 9
child2 start writing
child2 write 8
child2 start writing
child2 write 7
child2 start writing
child2 write 6
child2 start writing
child2 write 5
child2 start writing
child2 write 4
child2 start writing
child2 write 3
child2 start writing
child2 write 2
child2 start writing
child2 write 1
child2 start writing
child2 write 0
init
child3 init.
child3 start writing
child3 write 20
child3 start writing
child3 write 19
child3 start writing
child3 write 18
child3 start writing
child3 write 17
child3 start writing
child3 write 16
child3 start writing
child3 write 15
child3 start writing
child3 write 14
child3 start writing
child3 write 13
child3 start writing
child3 write 12
child3 start writing
child3 write 11
child3 start writing
child3 write 10
child3 start writing
child3 write 9
child3 start writing
child3 write 8
child3 start writing
child3 write 7
child3 start writing
child3 write 6
child3 start writing
child3 write 5
child3 start writing
child3 write 4
child3 start writing
child3 write 3
child3 start writing
child3 write 2
child3 start writing
child3 write 1
child3 start writing
child3 write 0
init
end


in terminal:
init
child2 init.
child2 start writing
child2 write 20
child2 start writing
child2 write 19
child2 start writing
child2 write 18
child2 start writing
child2 write 17
child2 start writing
child2 write 16
child2 start writing
child2 write 15
child2 start writing
child2 write 14
child2 start writing
child2 write 13
child2 start writing
child2 write 12
child2 start writing
child2 write 11
child2 start writing
child2 write 10
child2 start writing
child2 write 9
child2 start writing
child2 write 8
child2 start writing
child2 write 7
child2 start writing
child2 write 6
child2 start writing
child2 write 5
child2 start writing
child2 write 4
child2 start writing
child2 write 3
child2 start writing
child2 write 2
child2 start writing
child2 write 1
child2 start writing
child2 write 0
child1 init.
child1 start writing
child1 write 20
child1 start writing
child1 write 19
child1 start writing
child1 write 18
child1 start writing
child1 write 17
child1 start writing
child1 write 16
child1 start writing
child1 write 15
child1 start writing
child1 write 14
child1 start writing
child1 write 13
child3 init.
child1 start writing
child3 start writing
child1 write 12
child1 start writing
child1 write 11
child1 start writing
child1 write 10
child3 write 20
child1 start writing
child3 start writing
child1 write 9
child3 write 19
child1 start writing
child3 start writing
child1 write 8
child3 write 18
child1 start writing
child3 start writing
child1 write 7
child3 write 17
child1 start writing
child3 start writing
child3 write 16
child1 write 6
child3 start writing
child1 start writing
child3 write 15
child1 write 5
child3 start writing
child1 start writing
child3 write 14
child1 write 4
child3 start writing
child1 start writing
child3 write 13
child1 write 3
child3 start writing
child1 start writing
child3 write 12
child1 write 2
child3 start writing
child1 start writing
child3 write 11
child1 write 1
child3 start writing
child1 start writing
child3 write 10
child1 write 0
child3 start writing
child3 write 9
child3 start writing
child3 write 8
child3 start writing
child3 write 7
child3 start writing
child3 write 6
child3 start writing
child3 write 5
child3 start writing
child3 write 4
child3 start writing
child3 write 3
child3 start writing
child3 write 2
child3 start writing
child3 write 1
child3 start writing
child3 write 0
end

pan64 · 11-15-2021, 02:48 AM

this is not multithreading, but multitasking. -pthread is useless here (actually it is required because of the semaphore, but it is still not a multithreaded app).
(Multithreading) multitasking means the three children will run parallel, therefore the output can be mixed. And occasionally they are not mixed, it just depends on the kernel and the execution.

Sxing · 11-15-2021, 03:47 AM

Quote:

Originally Posted by pan64

this is not multithreading, but multitasking. -pthread is useless here (actually it is required because of the semaphore, but it is still not a multithreaded app).
(Multithreading) multitasking means the three children will run parallel, therefore the output can be mixed. And occasionally they are not mixed, it just depends on the kernel and the execution.

Thx for the reply. I noticed the lines are mixed in a different way between executions but are in different dimensions: In terminal every line is mixed. In the file each task’s output is mixed but lines from different tasks are not.
Also, why is the line of printf in the shared code have four outputs in a file but one in a terminal?

Sxing · 11-15-2021, 03:59 AM

why doesn't my reply appear?

Sxing · 11-15-2021, 04:01 AM

Quote:

Originally Posted by Sxing

why doesn't my reply appear?

test

pan64 · 11-15-2021, 04:19 AM

I guess it depends on the load of the system and other resources (like ram, cache). In general the order of those output lines is unpredictable. It also may depend on the internal buffers used by the app (for example printf) and the timings (for example if fork needs more time than the full loop).

Sxing · 11-15-2021, 04:30 AM

Quote:

Originally Posted by pan64

I guess it depends on the load of the system and other resources (like ram, cache). In general the order of those output lines is unpredictable. It also may depend on the internal buffers used by the app (for example printf) and the timings (for example if fork needs more time than the full loop).

That's alright. Thanks for your help anyway! *😄

onebuck · 11-15-2021, 05:10 AM

Quote:

Originally Posted by Sxing

why doesn't my reply appear?

Your duplicate posts went to moderation control.

rknichols · 11-15-2021, 09:08 AM

Quote:

Originally Posted by Sxing

It's a multi-threading program synchronized with semaphore. According to my knowledge, those three thread should print one by one, at least in this way.
And if I redirect it to a file, it seems the lines are organized by thread and the print line in father thread is repeated 3 times ???

This is almost certainly due to stdio buffering. Output to a terminal is by default line-buffered, i.e., the buffer is flushed after each newline character. Output to a file defaults to block-buffered, where the buffer is flushed whenever a full block (typically 4K) is collected.

You can use the setlinebuf() call to force an output stream to be line-buffered regardless of the device. See `man serlinebuf` for details.

sundialsvcs · 11-15-2021, 05:47 PM

You have "forked" several different processes, all of which are producing output that is "directed to the terminal." However, because they are "several different processes," each of them has its own STDIN, STDERR, STDOUT streams, to which each of them are writing independently. Yes, the various outputs are ultimately being gathered to the same physical destination – whether it be a terminal screen or a disk file – but it is unpredictable as to the order in which the various events might occur. (Likewise, the possibility of "buffering" which you also have no control over.)

I note that your source-code is peppered with wait() calls, as though you were trying to use these to achieve the "expected" output.

Your rule-of-thumb must be that the order-of-events of multitasking or even multithreaded operations is "UNPREDICTABLE."

Sxing · 11-15-2021, 09:14 PM

Thanks for replying. I kind of understand that it's the buffering cause the differences.
When I use the setlinebuf() call, the output in the file behaves the same as the terminal.
There's still one thing I'm confused about.
I think the buffering should only affect the order of lines. But the “printf(”init\n”);” prints 1 line when line-buffered, however, 3 lines when block-buffered. Is it a feature of Linux (merging the duplicate lines printed by the shared part of several tasks when line-buffered)?

rknichols · 11-15-2021, 10:45 PM

Quote:

Originally Posted by Sxing

But the “printf(”init\n”);” prints 1 line when line-buffered, however, 3 lines when block-buffered. Is it a feature of Linux (merging the duplicate lines printed by the shared part of several tasks when line-buffered)?

That should not be happening. Pipe the output through "hexdump -c", and/or run "hexdump -c" on the output file, to see exactly the characters being sent.

Sxing · 11-16-2021, 04:17 AM

Quote:

Originally Posted by rknichols

That should not be happening. Pipe the output through "hexdump -c", and/or run "hexdump -c" on the output file, to see exactly the characters being sent.

This may be due to my ignorance, but I don’t understand how does that help?
As you can see, there are 3 "init\n"(not child* init) in a (block-buffered)file but 1 "init\n" in a terminal.
In other words, the total numbers of rows are different.

Also, is my semaphore code completely useless? I haven't noticed any of semaphore's functions behaving at runtime.

pan64 · 11-16-2021, 05:16 AM

the 3 init lines are tricky, the forked processes may inherit the content of the buffer too (because that was not flushed).
From the other hand the semaphores are completely useless. But in some cases (when you have something else in between sem_wait and sem_post) it can be useful.

Sxing · 11-16-2021, 05:41 AM

Quote:

Originally Posted by pan64

the 3 init lines are tricky, the forked processes may inherit the content of the buffer too (because that was not flushed).
From the other hand the semaphores are completely useless. But in some cases (when you have something else in between sem_wait and sem_post) it can be useful.

I thought that placing the “printf” between the sem_wait() and sem_post() would make 3 children to be printing in order.
For example, when child1 runs into printf, child 2 and child 3 will be waiting for releasing of semaphore, which will cause child 1 to not print sequentially. If I was right, the output should be like:
child1 write
child2 write
child3 write
or
child1 write
child3 write
child2 write
or something similar
but not
child 1 write
child 1 write
child 1 write
but they are obviously not

So, where is the error in my description?