OpenMp 多线程编程计时问题

在做矩阵乘法并行化测试的时候,在利用<time.h>的clock()计时时出现了一点问题。

首先看串行的程序:

//&nbsp;matrix_cpu.c
#include&nbsp;<stdio.h>
#include&nbsp;<stdlib.h>
#include&nbsp;<time.h>
#define&nbsp;NUM&nbsp;2048

void&nbsp;matrixMul(float&nbsp;*A,&nbsp;float&nbsp;*B,&nbsp;float&nbsp;*C,&nbsp;int&nbsp;M,&nbsp;int&nbsp;K,&nbsp;int&nbsp;N)
{
&nbsp;&nbsp;&nbsp;&nbsp;int&nbsp;i,&nbsp;j,&nbsp;k;
&nbsp;&nbsp;&nbsp;&nbsp;for(i&nbsp;=&nbsp;0;&nbsp;i&nbsp;<&nbsp;M;&nbsp;i++)
&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;for(j&nbsp;=&nbsp;0;&nbsp;j&nbsp;<&nbsp;N;&nbsp;j++)
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;float&nbsp;sum&nbsp;=&nbsp;0.0f;
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;for(k&nbsp;=&nbsp;0;&nbsp;k&nbsp;<&nbsp;K;&nbsp;k++)
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;sum&nbsp;+=&nbsp;A[i*k+k]&nbsp;*&nbsp;B[k*N+j];
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;}
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;C[i*N+j]&nbsp;=&nbsp;sum;
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;}
&nbsp;&nbsp;&nbsp;&nbsp;}
}

int&nbsp;main(int&nbsp;argc,&nbsp;char*&nbsp;argv[])
{
&nbsp;&nbsp;&nbsp;&nbsp;float&nbsp;*A,&nbsp;*B,&nbsp;*C;
&nbsp;&nbsp;&nbsp;&nbsp;clock_t&nbsp;start,&nbsp;finish;
&nbsp;&nbsp;&nbsp;&nbsp;double&nbsp;duration;

&nbsp;&nbsp;&nbsp;&nbsp;A&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;B&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;C&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(A,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(B,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(C,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;
&nbsp;&nbsp;&nbsp;&nbsp;printf("Start...\n");

&nbsp;&nbsp;&nbsp;&nbsp;start&nbsp;=&nbsp;clock();
&nbsp;&nbsp;&nbsp;&nbsp;matrixMul(A,&nbsp;B,&nbsp;C,&nbsp;NUM,&nbsp;NUM,&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;finish&nbsp;=&nbsp;clock();
&nbsp;&nbsp;&nbsp;&nbsp;
&nbsp;&nbsp;&nbsp;&nbsp;duration&nbsp;=&nbsp;(double)(finish&nbsp;-&nbsp;start)&nbsp;/&nbsp;CLOCKS_PER_SEC;
&nbsp;&nbsp;&nbsp;&nbsp;printf("Time:&nbsp;%fs\n",&nbsp;duration);
&nbsp;&nbsp;&nbsp;&nbsp;return&nbsp;0;
}

在编译后,运行该程序,得到如下结果:

[wfshen@cu05&nbsp;matrix]$&nbsp;./matrix_cpu
Start...
Time:&nbsp;26.130000s

由于CPU是至强E5-2650,所以算得比较快(但目前仍然是串行,也就是说单核单线程),这样也要26秒了(在博主的i5-4200 ThinkPad上用时是171秒)。

加上time命令再运行一遍,结果如下:

[wfshen@cu05&nbsp;matrix]$&nbsp;time&nbsp;./matrix_cpu
Start...
Time:&nbsp;26.770000s

real	0m28.073s
user	0m26.779s
sys	0m0.019s

可以看到,时间与程序中统计的差不多,实际执行时间由于加了malloc等的时间所以长了一点,但还是合情合理的。

那么,再来看并行的OpenMP程序:

#include&nbsp;<stdio.h>
#include&nbsp;<stdlib.h>
#include&nbsp;<time.h>
#define&nbsp;NUM&nbsp;2048
#define&nbsp;THREAD_NUM&nbsp;2

void&nbsp;matrixMul(float&nbsp;*A,&nbsp;float&nbsp;*B,&nbsp;float&nbsp;*C,&nbsp;int&nbsp;M,&nbsp;int&nbsp;K,&nbsp;int&nbsp;N)
{
&nbsp;&nbsp;&nbsp;&nbsp;int&nbsp;i,&nbsp;j,&nbsp;k;
#pragma&nbsp;omp&nbsp;parallel&nbsp;for&nbsp;private(j,k)&nbsp;num_threads(THREAD_NUM)
&nbsp;&nbsp;&nbsp;&nbsp;for(i&nbsp;=&nbsp;0;&nbsp;i&nbsp;<&nbsp;M;&nbsp;i++)
&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;for(j&nbsp;=&nbsp;0;&nbsp;j&nbsp;<&nbsp;N;&nbsp;j++)
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;float&nbsp;sum&nbsp;=&nbsp;0.0f;
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;#pragma&nbsp;ivdep
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;for(k&nbsp;=&nbsp;0;&nbsp;k&nbsp;<&nbsp;K;&nbsp;k++)
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;{
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;sum&nbsp;+=&nbsp;A[i*k+k]&nbsp;*&nbsp;B[k*N+j];
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;}
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;C[i*N+j]&nbsp;=&nbsp;sum;
&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;}
&nbsp;&nbsp;&nbsp;&nbsp;}
}

int&nbsp;main(int&nbsp;argc,&nbsp;char*&nbsp;argv[])
{
&nbsp;&nbsp;&nbsp;&nbsp;float&nbsp;*A,&nbsp;*B,&nbsp;*C;
&nbsp;&nbsp;&nbsp;&nbsp;clock_t&nbsp;start,&nbsp;finish;
&nbsp;&nbsp;&nbsp;&nbsp;double&nbsp;duration;

&nbsp;&nbsp;&nbsp;&nbsp;A&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;B&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;C&nbsp;=&nbsp;(float&nbsp;*)&nbsp;malloc&nbsp;(sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(A,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(B,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;memset(C,&nbsp;0,&nbsp;sizeof(float)&nbsp;*&nbsp;NUM&nbsp;*&nbsp;NUM);

&nbsp;&nbsp;&nbsp;&nbsp;printf("Start...\n");

&nbsp;&nbsp;&nbsp;&nbsp;start&nbsp;=&nbsp;clock();
&nbsp;&nbsp;&nbsp;&nbsp;matrixMul(A,&nbsp;B,&nbsp;C,&nbsp;NUM,&nbsp;NUM,&nbsp;NUM);
&nbsp;&nbsp;&nbsp;&nbsp;finish&nbsp;=&nbsp;clock();

&nbsp;&nbsp;&nbsp;&nbsp;duration&nbsp;=&nbsp;(double)(finish&nbsp;-&nbsp;start)&nbsp;/&nbsp;CLOCKS_PER_SEC;
&nbsp;&nbsp;&nbsp;&nbsp;printf("Time:&nbsp;%fs\n",&nbsp;duration);
&nbsp;&nbsp;&nbsp;&nbsp;return&nbsp;0;
}

可以看到,该OpenMP程序只使用了两个线程,那么运行时间理论上来说能减半。

在编译后,运行该程序,得到如下结果:

[wfshen@cu05&nbsp;matrix]$&nbsp;./matrix_omp
Start...
Time:&nbsp;26.550000s

这就奇怪了,明明心里面数了一下大概花了15秒,但是为什么计时还是26秒呢?

再加上time命令运行一遍:

[wfshen@cu05&nbsp;matrix]$&nbsp;time&nbsp;./matrix_omp
Start...
Time:&nbsp;26.440000s

real	0m13.438s
user	0m26.457s
sys	0m0.016s

可以看到,实际的运行时间是13秒,但是user却超过了13秒,且几乎是real的两倍。

查了一下,发现了这样的解释:

real:&nbsp;墙上时间,即程序从开启到结束的实际运行时间
user:&nbsp;执行用户代码所花的实际时间(不包括内核调用),指进程执行所消耗的实际CPU时间
sys:该程序在内核调用上花的时间

在,单线程串行的时候,只有一个线程在运行,那么user所代表的就是一个cpu的时间。然而,当到多线程的情况下,一个进程可能有多个线程并行执行,但是user把所有的线程时间都加起来了,也就是算了一个总时间,这样,user的时间也就基本上等于单线程时的user时间。

这样,我们把线程数调到4,再运行代码(大概7秒):

[wfshen@cu05&nbsp;matrix]$&nbsp;./matrix_omp
Start...
Time:&nbsp;27.270000s
[wfshen@cu05&nbsp;matrix]$&nbsp;time&nbsp;./matrix_omp
Start...
Time:&nbsp;27.170000s

real	0m7.486s
user	0m27.176s
sys	0m0.018s

可以发现,实际运行时间7秒,CPU总时间27秒,差不多:

再把线程数调到16,再运行代码(大概2秒多):

[wfshen@cu05&nbsp;matrix]$&nbsp;./matrix_omp
Start...
Time:&nbsp;33.980000s
[wfshen@cu05&nbsp;matrix]$&nbsp;time&nbsp;./matrix_omp
Start...
Time:&nbsp;33.530000s

real	0m2.241s
user	0m33.479s
sys	0m0.075s

可以发现,CPU总时间有增加的趋势,不过实际时间还是大有减少。E5-2650是8核心16线程,再往上加线程时间反而会增长。

总结:在多线程的情况下,还是用time命令看时间吧。