Why OpenMP invoking 2 threads to each print one line, but end up printing 3 lines-CodePudding

In this program, I invoke two threads to add a random number to sum, and the first thread to make sum > 1000 is the winner.

#include <omp.h>
#include <random>
#include <iostream>
#include <fstream>

using namespace std;

int main() {
    ofstream outFileForTask;
    outFileForTask.open("task_output.txt", std::ios_base::app);
    time_t currentTime;
    time(&currentTime);
    outFileForTask << "\n\nTestTime: " << ctime(&currentTime);

    std::mt19937 randomNumGenerator(std::random_device{}());
    std::uniform_int_distribution<std::mt19937::result_type> uniformDist(-50, 100);
    int sum = 0;
    int terminatingSum = 1000;
    int winnerThreadId = -1;
    int round = 0;
    while (winnerThreadId == -1) {
        round  ;
#pragma omp parallel num_threads(2) shared(sum)
        {
            int randomNum = uniformDist(randomNumGenerator);
            int threadNum = omp_get_thread_num();
            int prevSum;
#pragma omp atomic capture
            {
                prevSum = sum;
                sum  = randomNum;
            }
            if (prevSum <= terminatingSum && prevSum   randomNum > terminatingSum) {
                winnerThreadId = threadNum;
            }
            outFileForTask << "Round: " << round
                            << "Thread Id：" << threadNum
                            << " added: " << randomNum
                            << " to sum, and new sum is ：" << prevSum   randomNum
                            << endl;
        }
    }

    outFileForTask << "Winner is thread: " << winnerThreadId <<
                    endl;
    return 0;
}

But the result I get is:

I wonder why in each round, thread 0 prints two identical lines. In fact, in each parallel block there is only one print statement, and two worker threads to execute the parallel block, so there should be two lines per round.



TestTime: Wed Oct 19 16:59:15 2022
Round: Round: 11hread Id： 0 added: -30� added: -30 to sum, and new sum is ：-60


TestTime: Wed Oct 19 16:59:15 2022
Round: Round: 11hread Id： 0 added: -30� added: -30 to sum, and new sum is ：-60

Round: 2Thread Id：0 added: 60Round: , and new sum is ：0Id： 2Round: 2Thread Id：0 added: 60Round: , and new sum is ：0Id： 2Thread Id：1 added: -19 to sum, and new sum is ：-19
Round: 3Thread Id：0 added: 24 to sum, and new sum is ：5
Round: 3Thread Id：0 added: 24 to sum, and new sum is ：5
Round: 3Thread Id：1 added: -13 to sum, and new sum is ：-8
Round: 4Thread Id：0 added: -49 to sum, and new sum is ：-57
Round: 4Thread Id：0 added: -49 to sum, and new sum is ：-57
Round: 4Thread Id：1 added: 34 to sum, and new sum is ：-23
Round: 5Thread Id：0 added: 56 to sum, and new sum is ：33
Round: 5Thread Id：0 added: 56 to sum, and new sum is ：33
Round: 5Thread Id：1 added: 52 to sum, and new sum is ：85
Round: 6Thread Id：0 added: 35 to sum, and new sum is ：120
Round: 6Thread Id：0 added: 35 to sum, and new sum is ：120
Round: 6Thread Id：1 added: 4 to sum, and new sum is ：124
Round: 7Thread Id：0 added: 21 to sum, and new sum is ：145
Round: 7Thread Id：0 added: 21 to sum, and new sum is ：145
Round: 7Thread Id：1 added: 44 to sum, and new sum is ：189
Round: 8Thread Id：0 added: 62 to sum, and new sum is ：251
Round: 8Thread Id：0 added: 62 to sum, and new sum is ：251
Round: 8Thread Id：1 added: -29 to sum, and new sum is ：222
Round: 9Thread Id：0 added: -2 to sum, and new sum is ：220
Round: 9Thread Id：0 added: -2 to sum, and new sum is ：220
Round: 9Thread Id：1 added: 20 to sum, and new sum is ：240
Round: 10Thread Id：0 added: 3 to sum, and new sum is ：243
Round: 10Thread Id：0 added: 3 to sum, and new sum is ：243
Round: 10Thread Id：1 added: 20 to sum, and new sum is ：263
Round: 11Thread Id：0 added: 27 to sum, and new sum is ：290
Round: 11Thread Id：0 added: 27 to sum, and new sum is ：290
Round: 11Thread Id：1 added: 52 to sum, and new sum is ：342
Round: 12Thread Id：0 added: -18 to sum, and new sum is ：324
Round: 12Thread Id：0 added: -18 to sum, and new sum is ：324
Round: 12Thread Id：1 added: -9 to sum, and new sum is ：315
Round: 13Thread Id：0 added: 49 to sum, and new sum is ：364
Round: 13Thread Id：0 added: 49 to sum, and new sum is ：364
Round: 13Thread Id：1 added: 43 to sum, and new sum is ：407
Round: 14Thread Id：0 added: -27 to sum, and new sum is ：380
Round: 14Thread Id：0 added: -27 to sum, and new sum is ：380
Round: 14Thread Id：1 added: 24 to sum, and new sum is ：404
Round: 15Thread Id：0 added: 68 to sum, and new sum is ：472
Round: 15Thread Id：0 added: 68 to sum, and new sum is ：472
Round: 15Thread Id：1 added: 27 to sum, and new sum is ：499
Round: 16Thread Id：0 added: 76 to sum, and new sum is ：575
Round: 16Thread Id：0 added: 76 to sum, and new sum is ：575
Round: 16Thread Id：1 added: 91 to sum, and new sum is ：666
Round: 17Thread Id：0 added: -4 to sum, and new sum is ：662
Round: 17Thread Id：0 added: -4 to sum, and new sum is ：662
Round: 17Thread Id：1 added: -19 to sum, and new sum is ：643
Round: 18Thread Id：0 added: -47 to sum, and new sum is ：596
Round: 18Thread Id：0 added: -47 to sum, and new sum is ：596
Round: 18Thread Id：1 added: -28 to sum, and new sum is ：568
Round: 19Thread Id：0 added: 43 to sum, and new sum is ：611
Round: 19Thread Id：0 added: 43 to sum, and new sum is ：611
Round: 19Thread Id：1 added: -9 to sum, and new sum is ：602
Round: 20Thread Id：0 added: 33 to sum, and new sum is ：635
Round: 20Thread Id：0 added: 33 to sum, and new sum is ：635
Round: 20Thread Id：1 added: 29 to sum, and new sum is ：664
Round: 21Thread Id：0 added: -29 to sum, and new sum is ：635
Round: 21Thread Id：0 added: -29 to sum, and new sum is ：635
Round: 21Thread Id：1 added: 28 to sum, and new sum is ：663
Round: 22Thread Id：0 added: 25 to sum, and new sum is ：688
Round: 22Thread Id：0 added: 25 to sum, and new sum is ：688
Round: 22Thread Id：1 added: -23 to sum, and new sum is ：665
Round: 23Thread Id：0 added: 11 to sum, and new sum is ：676
Round: 23Thread Id：0 added: 11 to sum, and new sum is ：676
Round: 23Thread Id：1 added: 55 to sum, and new sum is ：731
Round: 24Thread Id：0 added: -49 to sum, and new sum is ：682
Round: 24Thread Id：0 added: -49 to sum, and new sum is ：682
Round: 24Thread Id：1 added: 22 to sum, and new sum is ：704
Round: 25Thread Id：0 added: 49 to sum, and new sum is ：753
Round: 25Thread Id：0 added: 49 to sum, and new sum is ：753
Round: 25Thread Id：1 added: 14 to sum, and new sum is ：767
Round: 26Thread Id：0 added: 61 to sum, and new sum is ：828
Round: 26Thread Id：0 added: 61 to sum, and new sum is ：828
Round: 26Thread Id：1 added: 29 to sum, and new sum is ：857
Round: 27Thread Id：0 added: -16 to sum, and new sum is ：841
Round: 27Thread Id：0 added: -16 to sum, and new sum is ：841
Round: 27Thread Id：1 added: -18 to sum, and new sum is ：823
Round: 28Thread Id：0 added: 98 to sum, and new sum is ：921
Round: 28Thread Id：0 added: 98 to sum, and new sum is ：921
Round: 28Thread Id：1 added: 21 to sum, and new sum is ：942
Round: 29Thread Id：0 added: 13 to sum, and new sum is ：955
Round: 29Thread Id：0 added: 13 to sum, and new sum is ：955
Round: 29Thread Id：1 added: 28 to sum, and new sum is ：983
Round: 30Thread Id：0 added: 74 to sum, and new sum is ：1057
Round: 30Thread Id：0 added: 74 to sum, and new sum is ：1057
Round: 30Thread Id：1 added: -14 to sum, and new sum is ：1043
Winner is thread: 0

CodePudding user response：

Adding #pragma omp critical before the prints in the parallel region not only avoids blending the output, it also removes all duplicate prints. Writing to the same output file seems to not be thread-safe in this context and results in undefined behavior.

EDIT (copying the latest comment of the OP, which tend to confirm the thread-safety issue):

I just tried using printf instead of fstream (printf is thread-safe), and the result is correct (no more multiple TestTime or identical line issue). So I guessed this confirmed that the problem comes from fstream