[Box Backup-commit] COMMIT r3468 - box/trunk/lib/common

[subversion at boxbackup.org]

Author: chris
Date: 2014-12-21 13:36:44 +0000 (Sun, 21 Dec 2014)
New Revision: 3468

Modified:
   box/trunk/lib/common/BoxTime.cpp
Log:
Fix computation of fractional second part of ShortSleep().

Reduce precision in log messages from microseconds to milliseconds.

Log the amount of time actually slept in ShortSleep().


Modified: box/trunk/lib/common/BoxTime.cpp
===================================================================
--- box/trunk/lib/common/BoxTime.cpp	2014-12-21 13:31:53 UTC (rev 3467)
+++ box/trunk/lib/common/BoxTime.cpp	2014-12-21 13:36:44 UTC (rev 3468)
@@ -83,7 +83,7 @@
 
 		if (showMicros)
 		{
-			buf << "." << std::setw(6) << micros;
+			buf << "." << std::setw(3) << (int)(micros / 1000);
 		}
 	}
 	else
@@ -108,8 +108,7 @@
 {
 	if(logDuration)
 	{
-		BOX_TRACE("Sleeping for " << BoxTimeToMicroSeconds(duration) <<
-			" microseconds");
+		BOX_TRACE("Sleeping for " << BOX_FORMAT_MICROSECONDS(duration));
 	}
 
 #ifdef WIN32
@@ -118,8 +117,10 @@
 	struct timespec ts;
 	memset(&ts, 0, sizeof(ts));
 	ts.tv_sec  = duration / MICRO_SEC_IN_SEC;
-	ts.tv_nsec = duration % MICRO_SEC_IN_SEC;
+	ts.tv_nsec = (duration % MICRO_SEC_IN_SEC) * 1000;
 
+	box_time_t start_time = GetCurrentBoxTime();
+
 	while (nanosleep(&ts, &ts) == -1 && errno == EINTR)
 	{
 		// FIXME evil hack for OSX, where ts.tv_sec contains
@@ -140,6 +141,10 @@
 		BOX_TRACE("nanosleep interrupted with " << remain_ns <<
 			" nanosecs remaining, sleeping again");
 	}
+
+	box_time_t sleep_time = GetCurrentBoxTime() - start_time;	
+	BOX_TRACE("Actually slept for " << BOX_FORMAT_MICROSECONDS(sleep_time) <<
+		", was aiming for " << BOX_FORMAT_MICROSECONDS(duration));
 #endif
 }