Error when I statistcs the time of IO executed in tbb threads

[chqiu]

I have create several threads in my parallel program, unfortanetly each thread need write and read some files in the disks, which will cause i/o competition.
Now, I want to statistcs the total I/O time, and I use the following code:

this read code is:

[cpp]struct timeval tvafter,tvpre;
struct timezone tz;
gettimeofday (&tvpre , &tz);

//Write to the disk
store->Write(node->Path().Page(), buf);

gettimeofday (&tvafter , &tz);
writeTime += (tvafter.tv_sec - tvpre.tv_sec) * 1000 + (double)(tvafter.tv_usec - tvpre.tv_usec)/1000.0;[/cpp]

this write code is:

[cpp]struct timeval tvafter,tvpre;
struct timezone tz;
gettimeofday (&tvpre , &tz);

//Write to the disk
store->Read(node->Path().Page(), buf);

gettimeofday (&tvafter , &tz);
readTime += (tvafter.tv_sec - tvpre.tv_sec) * 1000 + (double)(tvafter.tv_usec - tvpre.tv_usec)/1000.0;[/cpp]

readTime and writeTime is two global parameters.
Total time of my program is statistcsed by the tick_count of tbb
The following is the time statistcs results of my programm, and I have use 1 and 4 threads.

1 thread:

Total time 459152 ms
Read time 16209.7ms
Write time 67889.2ms

4 thread:

Total time 197372ms
Read time 18958.2ms
Write time 234602ms

To 4 thread, the sum of read and write time is larger than the total time, its impossible.

I have thought that maybe I sould add the lock to the readTime and writeTime, so I use the spin_rw_mutex to protect these
two parameters. But the result is the same.

So, what mistake i have made? and Is there any good method to do it correctly.

Please do me a favour!
Thank you very much!

chu qiu

[RafSchietekat]

To avoid mishaps because of subtractingtwo unsigned integers (timeval::tv_usec), you could use tbb::tick_count instead, thereby also making this a valid TBB-related question. :-)

[Dmitry_Vyukov]

Quoting - chqiu@cuc.edu.cn

4 thread:

Total time 197372ms
Read time 18958.2ms
Write time 234602ms

4 threads are able to execute up to 788 seconds of reads/writes in 197 seconds of real time. And in your case they execute only 253 seconds of reads/writes. So I do not see anything strange in your numbers.

[RafSchietekat]

Sorry, I was too quick on the draw again: #0 did mention tick_count (but then why not use it also for read and write?), and tv_usec's type is signed all right (I was confusing type with value normalisation if using timeval as the result). readTime and writeTime should really be protected by a mutex, however (unless they're atomic).

[chqiu]

Quoting - Raf Schietekat

Sorry, I was too quick on the draw again: #0 did mention tick_count (but then why not use it also for read and write?), and tv_usec's type is signed all right (I was confusing type with value normalisation if using timeval as the result). readTime and writeTime should really be protected by a mutex, however (unless they're atomic).

Thank you for your reply!

the realTime and writeTime is double, and I think they're computed correctly, because the total time is computed with the same method.

Furthermore, I have use tick_count to get the total time of my program, its result is the same as my method.

Thank you very much!

I'll try you suggestion.

[chqiu]

Quoting - Dmitriy Vyukov

4 threads are able to execute up to 788 seconds of reads/writes in 197 seconds of real time. And in your case they execute only 253 seconds of reads/writes. So I do not see anything strange in your numbers.

197 seconds is the total time of my program running with 4 threads, not the time of one thread

thank you very much!