From 5a0bf91707e1f4ed2e830aac8b1274a6504936a0 Mon Sep 17 00:00:00 2001 From: Bruce Allen Date: Tue, 13 Sep 2005 16:30:04 +0000 Subject: [PATCH] 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 | 11 +++++++++++ lib/msg_log.C | 6 +++--- lib/util.C | 20 ++++++++++++++++++++ lib/util.h | 1 + 4 files changed, 35 insertions(+), 3 deletions(-) diff --git a/checkin_notes b/checkin_notes index 4b488e2cb8..2f13b98ff4 100755 --- a/checkin_notes +++ b/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 diff --git a/lib/msg_log.C b/lib/msg_log.C index 8bb0aab686..9a6b455865 100644 --- a/lib/msg_log.C +++ b/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"); diff --git a/lib/util.C b/lib/util.C index 58684c8c85..c8712245ed 100755 --- a/lib/util.C +++ b/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; diff --git a/lib/util.h b/lib/util.h index 112124708c..2e3a577f39 100755 --- a/lib/util.h +++ b/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)