bugfix: imklog mistakenly took kernel timestamp subseconds as nanoseconds

... actually, they are microseconds. So the fractional part of the
timestamp was not properly formatted.
Thanks to Marius Tomaschwesky for the bug report and the patch idea.

2 files changed, 27 insertions, 12 deletions

diff --git a/ChangeLog b/ChangeLog
index f4bec22e..55f75264 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -2,6 +2,21 @@
 Version 5.10.2  [V5-STABLE], 201?-??-??
 - bugfix: spurios error messages from imuxsock about (non-error) EAGAIN
   Thanks to Marius Tomaschwesky for the patch.
+- imklog: added $klogParseKernelTimestamp option
+  When enabled, kernel message [timestamp] is converted for message time.
+  Default is to use receive time as in 5.8.x and before, because the clock
+  used to create the timestamp is not supposed to be as accurate as the
+  monotonic clock (depends on hardware and kernel) resulting in differences
+  between kernel and system messages which occurred at same time.
+  Thanks to Marius Tomaschwesky for the patch.
+- imklog: added $klogKeepKernelTimestamp option
+  When enabled, the kernel [timestamp] remains at begin of
+  each message, even it is used for the message time too.
+  Thanks to Marius Tomaschwesky for the patch.
+- bugfix: imklog mistakenly took kernel timestamp subseconds as nanoseconds
+  ... actually, they are microseconds. So the fractional part of the 
+  timestamp was not properly formatted.
+  Thanks to Marius Tomaschwesky for the bug report and the patch idea.
 ---------------------------------------------------------------------------
 Version 5.10.1  [V5-STABLE], 2012-10-17
 - bugfix: imuxsock and imklog truncated head of received message
diff --git a/plugins/imklog/bsd.c b/plugins/imklog/bsd.c
index 06032373..17d4bead 100644
--- a/plugins/imklog/bsd.c
+++ b/plugins/imklog/bsd.c
@@ -76,9 +76,9 @@ static void
 submitSyslog(int pri, uchar *buf)
 {
 	long secs;
-	long nsecs;
+	long usecs;
 	long secOffs;
-	long nsecOffs;
+	long usecOffs;
 	unsigned i;
 	unsigned bufsize;
 	struct timespec monotonic, realtime;
@@ -109,9 +109,9 @@ submitSyslog(int pri, uchar *buf)
 	}
 	
 	++i; /* skip dot */
-	nsecs = 0;
+	usecs = 0;
 	while(buf[i] && isdigit(buf[i])) {
-		nsecs = nsecs * 10 + buf[i] - '0';
+		usecs = usecs * 10 + buf[i] - '0';
 		++i;
 	}
 	if(buf[i] != ']') {
@@ -121,7 +121,7 @@ submitSyslog(int pri, uchar *buf)
 	++i; /* skip ']' */
 
 	/* we have a timestamp */
-	DBGPRINTF("kernel timestamp is %ld %ld\n", secs, nsecs);
+	DBGPRINTF("kernel timestamp is %ld %ld\n", secs, usecs);
 	if(!bKeepKernelStamp) {
 		bufsize= strlen((char*)buf);
 		memmove(buf+3, buf+i, bufsize - i + 1);
@@ -130,20 +130,20 @@ submitSyslog(int pri, uchar *buf)
 	clock_gettime(CLOCK_MONOTONIC, &monotonic);
 	clock_gettime(CLOCK_REALTIME, &realtime);
 	secOffs = realtime.tv_sec - monotonic.tv_sec;
-	nsecOffs = realtime.tv_nsec - monotonic.tv_nsec;
-	if(nsecOffs < 0) {
+	usecOffs = (realtime.tv_nsec - monotonic.tv_nsec) / 1000;
+	if(usecOffs < 0) {
 		secOffs--;
-		nsecOffs += 1000000000l;
+		usecOffs += 1000000l;
 	}
 	
-	nsecs +=nsecOffs;
-	if(nsecs > 999999999l) {
+	usecs += usecOffs;
+	if(usecs > 999999l) {
 		secs++;
-		nsecs -= 1000000000l;
+		usecs -= 1000000l;
 	}
 	secs += secOffs;
 	tv.tv_sec = secs;
-	tv.tv_usec = nsecs / 1000;
+	tv.tv_usec = usecs;
 	tp = &tv;
 
 done: