C++线程意外打印同一行多次

Question

我正在编写一个程序，只是为了通过从每个线程打印一些内容来查看线程的调度。我得到的是一些意外的输出。

虽然我在循环中的每个 print 语句之后更新我的变量值，但输出显示 print 语句在更新其值之前针对相同的变量值执行了多次。

为什么会这样？？？

我期待以下结果，

53674444272163,T35,1
53674444562178,T35,2
53674444563927,T35,3
53674444565225,T35,4

但实际上我得到了以下结果。

53674444272163,T35,1
53674444272163,T35,1
53674444272163,T35,1
53674444272163,T35,1
53674444272163,T35,1
53674444272163,T35,1
53674444272163,T35,1
53674444562178,T35,2
53674444562178,T35,2
53674444562178,T35,2
53674444562178,T35,2
53674444562178,T35,2
53674444562178,T35,2
53674444562178,T35,2
53674444563927,T35,3
53674444563927,T35,3
53674444563927,T35,3
53674444563927,T35,3
53674444563927,T35,3
53674444563927,T35,3
53674444563927,T35,3
53674444565225,T35,4
53674444565225,T35,4
53674444565225,T35,4
53674444565225,T35,4
53674444565225,T35,4
53674444565225,T35,4
53674444565225,T35,4

这是我的程序

#include <pthread.h>
#include <stdio.h>
#include <iostream>
#include <cstdlib>
#include <fstream>
#include <sys/time.h>
#include <time.h>       /* time_t, struct tm, time, localtime */
#include <mutex>          // std::mutex
#include <sstream>
#include <sys/resource.h>
#include <sys/types.h>
#include <assert.h>
#include <stdlib.h>
#include <stdint.h>

#define NTHREADS 100
#define MAX_COUNT 1000

using namespace std;
std::ostringstream out1;
ofstream fp1;

pthread_mutex_t     mutex1 = PTHREAD_MUTEX_INITIALIZER;

unsigned long long int rdtsc_start(void)
{
   unsigned a, d;
   __asm__ volatile("rdtsc" : "=a" (a), "=d" (d));
   return ((unsigned long long)a) | (((unsigned long long)d) << 32);;
}

/* This is our thread function.  It is like main(), but for a thread*/
void *threadA(void *arg)
{ 
    long my_id = (long)arg;
    int check=0;
    volatile long count = 0;
    int j=0;
    while(count++< MAX_COUNT)
    {
        unsigned long long time_x=rdtsc_start();
        pthread_mutex_lock(&mutex1);
        out1<<time_x<<",T"<<my_id<<","<<count<<"\n";
        pthread_mutex_unlock(&mutex1);

        // busy wait  to consume CPU
        volatile long  ii=0;
        while(ii++<50000);
    }
    fp1<<out1.str();
    pthread_exit(NULL);
    return NULL;
}

int main(void)
{
    pid_t pid;
    pid=getpid();

    printf("Thread pid %d\n",pid);

    fp1.open("result_Threaded_Process1.txt"); // in place of parent process 

    pthread_t             threadid[NTHREADS];
    int result;
    //printf("Create %d threads\n", NTHREADS);
    for(long i=0; i<NTHREADS; ++i) 
    {
        result= pthread_create(&threadid[i], NULL, threadA, (void *)i);
        if(result ==-1)
        {
            perror("Thread Creation Error: \n");
            exit(EXIT_FAILURE);
        }    
    }

    //  printf("Wait for threads and cleanup\n");
    for (long i=0; i<NTHREADS; ++i)
    {
        pthread_join(threadid[i], NULL);
    }
    fp1.close(); 
    return 0;
}

我哪里出错了？ 提前感谢您提供任何线索或提示来理解输出。

我在 Ubuntu 12.04 下使用 g++。

编辑

接受的答案:

根据@Jason 的评论，当我放置

pthread_mutex_lock(&mutex1);
fp1<<out1.str();
pthread_mutex_unlock(&mutex1);

在主函数中我得到了预期的结果

53674444272163,T35,1
53674444562178,T35,2
53674444563927,T35,3
53674444565225,T35,4

而当我把

   pthread_mutex_lock(&mutex1);
   fp1<<out1.str();
   pthread_mutex_unlock(&mutex1);

我得到相同的语句 (53674444272163,T35,1) 打印了 NTHREAD 次。(53674444562178,T35,2) 打印了 NTHREAD 次。

根据我的理解，我得到的输出是因为虽然每个线程只正确写入输出值一次，

53674444272163,T35,1 53674444562178,T35,2

所有线程都在退出时打印 out1 的值，所以我总共打印了 NTHREAD 次相同的语句。

现在，我的问题是为什么我没有像在我的原始程序中那样在没有互斥锁的情况下打印 NTHREAD 次 (53674444272163,T35,1)？

此外，根据我的原始程序，有时在没有互斥锁的情况下，我会得到 26773 Segmentation fault (core dumped)，而使用互斥锁时，Segmentation fault never happened 。为什么会这样？？？

谢谢。

Answer 1

我无法在我的盒子(4 核)上复制您的结果，但我发现了一些东西:

1. 您正在打印 out1 NTHREAD 次的结果(在线程末尾)。您应该只在所有线程完成后打印出 out1 的值(在 main() 中，在 pthread_joins 之后)

2. 当您读取 out1 以打印到 fp1 时，您并没有在 out1 上放置互斥量。如果您采纳建议 #1，这并不重要，但我想我会出于教育目的指出它。

我认为#1 是你的问题。希望这会有所帮助。