[SOLVED] Mismatch in timing

Mismatch in timing

struct timeval start, end, duration;
gettimeofday(&start, NULL);

res = curl_easy_perform(curl);

gettimeofday(&end, NULL);
timersub(&end, &start, &duration);

tm* startTime = localtime(&start.tv_sec);
tm* endTime = localtime(&end.tv_sec);
char buf[64];
strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", startTime);
char buf2[64];
strftime(buf2, sizeof(buf2), "%Y-%m-%d %H:%M:%S", endTime);

ofstream timeFile;
timeFile.open ("timingSheet.txt");
timeFile << fixed << showpoint;
timeFile << setprecision(6);
timeFile << "Duration: " << duration.tv_sec << "." << duration.tv_usec << " seconds \n";
timeFile << "Start time: " <<  buf <<"." << start.tv_usec << "\n";
timeFile << "End time: " <<  buf2 <<"." << end.tv_usec << "\n";
timeFile.close();

When I run this code I get this output:

Duration: 3.462243 seconds 
Start time: 2012-05-15 17:14:07.432613
End time: 2012-05-15 17:14:07.894856

What puzzles me is that the duration value doesn't match up with the Start and End times. The two dates only differ by the micro seconds. Is there a reason for this?

Thanks!

Solution

localtime return a statically allocated buffer and you call it twice ,so StartTime and EndTime are the same. You need to copy it in another buffer directcly after each call.

tm* startTime = localtime(&start.tv_sec); 
char buf[64]; 
strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", startTime); 

tm* endTime = localtime(&end.tv_sec); 
char buf2[64]; 
strftime(buf2, sizeof(buf2), "%Y-%m-%d %H:%M:%S", endTime);

EDIT: you can also write this:

tm* pTimeBuf = localtime(&start.tv_sec); 
char buf[64]; 
strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", pTimeBuf); 

localtime(&end.tv_sec); // NB. I don't store th return value (since I have it already)
char buf2[64]; 
strftime(buf2, sizeof(buf2), "%Y-%m-%d %H:%M:%S", pTimeBuf);