Logging: to help resolve future race conditions etc, I have modified

the logging functions to print fractional seconds down to hundred
microsecond precision.  I think the only place that these logging
functions are used is in the server back-end code and in error logging
on the client side, where this should be OK. Rom, David, Charlie, if
you are unhappy with client side effects, I'm sure there is a way
to do this that only affects server side logging.

svn path=/trunk/boinc/; revision=8002

checkin_notes

@@ -11753,8 +11753,19 @@ Bruce 13 Sept 2005
       if the hardwired standard delay in the client is smaller than
       min_sendwork_interval, the client will keep getting connections
       refused at the server side.  David, please give this a glance.
+    - Logging: to help resolve future race conditions etc, I have modified
+      the logging functions to print fractional seconds down to hundred
+      microsecond precision.  I think the only place that these logging
+      functions are used is in the server back-end code and in error logging
+      on the client side, where this should be OK. Rom, David, Charlie, if
+      you are unhappy with client side effects, I'm sure there is a way
+      to do this that only affects server side logging.
 
     sched/
         server_types.C
+    lib/
+        util.C
+        util.h
+        msg_log.C
 
 

lib/msg_log.C

@@ -89,7 +89,7 @@ void MSG_LOG::enter_level(int diff) {
 
 void MSG_LOG::vprintf(int kind, const char* format, va_list va) {
     char buf[256];
-    const char* now_timestamp = time_to_string((double)time(0));
+    const char* now_timestamp = precision_time_to_string(dtime());
     if (!v_message_wanted(kind)) return;
     if (pid) {
         sprintf(buf, " [PID=%-5d]", pid);
@@ -112,7 +112,7 @@ void MSG_LOG::vprintf_multiline(
     if (prefix_format) {
         vsprintf(sprefix, prefix_format, va);
     }
-    const char* now_timestamp = time_to_string((double)time(0));
+    const char* now_timestamp = precision_time_to_string(dtime());
     const char* skind = v_format_kind(kind);
 
     string line;
@@ -139,7 +139,7 @@ void MSG_LOG::vprintf_file(
     if (prefix_format) {
         vsprintf(sprefix, prefix_format, va);
     }
-    const char* now_timestamp = time_to_string((double)time(0));
+    const char* now_timestamp = precision_time_to_string(dtime());
     const char* skind = v_format_kind(kind);
 
     FILE* f = fopen(filename, "r");

lib/util.C

@@ -530,6 +530,26 @@ char* time_to_string(double t) {
     return buf;
 }
 
+char* precision_time_to_string(double t) {
+    static char buf[100];
+    char finer[16];
+    int hundreds_of_microseconds=(int)(10000*(t-(int)t));
+    if (hundreds_of_microseconds == 10000) {
+        // paranoia -- this should never happen!
+        //
+        hundreds_of_microseconds=0;
+        t+=1.0;
+    }
+    time_t x = (time_t)t;
+    struct tm* tm = localtime(&x);
+
+    strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
+    sprintf(finer, ".%04d", hundreds_of_microseconds);
+    strcat(buf, finer);
+    return buf;
+}
+
+
 // set by command line
 bool debug_fake_exponential_backoff = false;
 double debug_total_exponential_backoff = 0;

lib/util.h

@@ -56,6 +56,7 @@ extern void safe_strncpy(char*, const char*, int);
 #define safe_strcpy(x, y) safe_strncpy(x, y, sizeof(x))
 #define safe_strcat(x, y) if (strlen(x)+strlen(y)<sizeof(x)) strcat(x, y)
 extern char* time_to_string(double);
+extern char* precision_time_to_string(double);
 extern std::string timediff_format(double);
 extern int read_file_string(const char* pathname, std::string& result);