1 files changed, 129 insertions, 47 deletions

diff --git a/plugins/imklog/linux.c b/plugins/imklog/linux.c
index 727708a5..efa25dcc 100644
--- a/plugins/imklog/linux.c
+++ b/plugins/imklog/linux.c
@@ -28,6 +28,8 @@
 #include "rsyslog.h"
 #include <stdlib.h>
 #include <stdio.h>
+#include <ctype.h>
+#include <time.h>
 #include <assert.h>
 #include <signal.h>
 #include <string.h>
@@ -85,15 +87,15 @@ static enum LOGSRC {none, proc, kernel} logsrc;
 extern int ksyslog(int type, char *buf, int len);
 
 
-static uchar *GetPath(void)
+static uchar *GetPath(modConfData_t *pModConf)
 {
-	return pszPath ? pszPath : UCHAR_CONSTANT(_PATH_KLOG);
+	return pModConf->pszPath ? pModConf->pszPath : UCHAR_CONSTANT(_PATH_KLOG);
 }
 
-static void CloseLogSrc(void)
+static void CloseLogSrc(modConfData_t *pModConf)
 {
 	/* Turn on logging of messages to console, but only if a log level was speficied */
-	if(console_log_level != -1)
+	if(pModConf->console_log_level != -1)
 		ksyslog(7, NULL, 0);
   
         /* Shutdown the log sources. */
@@ -114,13 +116,13 @@ static void CloseLogSrc(void)
 }
 
 
-static enum LOGSRC GetKernelLogSrc(void)
+static enum LOGSRC GetKernelLogSrc(modConfData_t *pModConf)
 {
 	auto struct stat sb;
 
 	/* Set level of kernel console messaging.. */
-	if (   (console_log_level != -1) &&
-	       (ksyslog(8, NULL, console_log_level) < 0) &&
+	if (   (pModConf->console_log_level != -1) &&
+	       (ksyslog(8, NULL, pModConf->console_log_level) < 0) &&
 	     (errno == EINVAL) )
 	{
 		/*
@@ -137,8 +139,8 @@ static enum LOGSRC GetKernelLogSrc(void)
 	 * First do a stat to determine whether or not the proc based
 	 * file system is available to get kernel messages from.
 	 */
-	if ( use_syscall ||
-	    ((stat((char*)GetPath(), &sb) < 0) && (errno == ENOENT)) )
+	if ( pModConf->use_syscall ||
+	    ((stat((char*)GetPath(pModConf), &sb) < 0) && (errno == ENOENT)) )
 	{
 	  	/* Initialize kernel logging. */
 	  	ksyslog(1, NULL, 0);
@@ -147,14 +149,15 @@ static enum LOGSRC GetKernelLogSrc(void)
 		return(kernel);
 	}
 
-	if ( (kmsg = open((char*)GetPath(), O_RDONLY|O_CLOEXEC)) < 0 )
+	if ( (kmsg = open((char*)GetPath(pModConf), O_RDONLY|O_CLOEXEC)) < 0 )
 	{
 		imklogLogIntMsg(LOG_ERR, "imklog: Cannot open proc file system, %d.\n", errno);
 		ksyslog(7, NULL, 0);
 		return(none);
 	}
 
-	imklogLogIntMsg(LOG_INFO, "imklog %s, log source = %s started.", VERSION, GetPath());
+	imklogLogIntMsg(LOG_INFO, "imklog %s, log source = %s, fd = %d started.",
+		VERSION, GetPath(pModConf), kmsg);
 	return(proc);
 }
 
@@ -181,6 +184,93 @@ static int copyin( uchar *line,      int space,
     return(i);
 }
 
+
+/* submit a message to imklog Syslog() API. In this function, we check if 
+ * a kernel timestamp is present and, if so, extract and strip it.
+ * Note: this is an extra processing step. We should revisit the whole
+ * idea in v6 and remove all that old stuff that we do not longer need
+ * (like symbol resolution). <-- TODO 
+ * Special thanks to Lennart Poettering for suggesting on how to convert
+ * the kernel timestamp to a realtime timestamp. This method depends on 
+ * the fact the the kernel timestamp is written using the monotonic clock.
+ * Shall that change (very unlikely), this code must be changed as well. Note
+ * that due to the way we generate the delta, we are unable to write the
+ * absolutely correc timestamp (system call overhead of the clock calls
+ * prevents us from doing so). However, the difference is very minor.
+ * rgerhards, 201106-24
+ */
+static void
+submitSyslog(int pri, uchar *buf)
+{
+	long secs;
+	long nsecs;
+	long secOffs;
+	long nsecOffs;
+	unsigned i;
+	unsigned bufsize;
+	struct timespec monotonic, realtime;
+	struct timeval tv;
+	struct timeval *tp = NULL;
+
+	if(buf[3] != '[')
+		goto done;
+	DBGPRINTF("imklog: kernel timestamp detected, extracting it\n");
+
+	/* we now try to parse the timestamp. iff it parses, we assume
+	 * it is a timestamp. Otherwise we know for sure it is no ts ;)
+	 */
+	i = 4; /* first digit after '[' */
+	secs = 0;
+	while(buf[i] && isdigit(buf[i])) {
+		secs = secs * 10 + buf[i] - '0';
+		++i;
+	}
+	if(buf[i] != '.') {
+		DBGPRINTF("no dot --> no kernel timestamp\n");
+		goto done; /* no TS! */
+	}
+	
+	++i; /* skip dot */
+	nsecs = 0;
+	while(buf[i] && isdigit(buf[i])) {
+		nsecs = nsecs * 10 + buf[i] - '0';
+		++i;
+	}
+	if(buf[i] != ']') {
+		DBGPRINTF("no trailing ']' --> no kernel timestamp\n");
+		goto done; /* no TS! */
+	}
+	++i; /* skip ']' */
+
+	/* we have a timestamp */
+	DBGPRINTF("kernel timestamp is %ld %ld\n", secs, nsecs);
+	bufsize= strlen((char*)buf);
+	memcpy(buf+3, buf+i, bufsize - i + 1);
+
+	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) {
+		secOffs--;
+		nsecOffs += 1000000000l;
+	}
+	
+	nsecs +=nsecOffs;
+	if(nsecs > 999999999l) {
+		secs++;
+		nsecs -= 1000000000l;
+	}
+	secs += secOffs;
+	tv.tv_sec = secs;
+	tv.tv_usec = nsecs / 1000;
+	tp = &tv;
+
+done:
+	Syslog(pri, buf, tp);
+}
+
+
 /*
  * Messages are separated by "\n".  Messages longer than
  * LOG_LINE_LENGTH are broken up.
@@ -200,7 +290,7 @@ static int copyin( uchar *line,      int space,
  * original text.  Just in case somebody wants to run their own Oops
  * analysis on the syslog, e.g. ksymoops.
  */
-static void LogLine(char *ptr, int len)
+static void LogLine(modConfData_t *pModConf, char *ptr, int len)
 {
     enum parse_state_enum {
         PARSING_TEXT,
@@ -235,7 +325,7 @@ static void LogLine(char *ptr, int len)
 	    //dbgprintf("Line buffer full:\n");
        	    //dbgprintf("\tLine: %s\n", line);
 
-            Syslog(LOG_INFO, line_buff);
+            submitSyslog(LOG_INFO, line_buff);
             line  = line_buff;
             space = sizeof(line_buff)-1;
             parse_state = PARSING_TEXT;
@@ -254,40 +344,34 @@ static void LogLine(char *ptr, int len)
                space -= delta;
                len   -= delta;
 
-               if( space == 0 || len == 0 )
-               {
+               if( space == 0 || len == 0 ) {
 		  break;  /* full line_buff or end of input buffer */
                }
 
-               if( *ptr == '\0' )  /* zero byte */
-               {
+               if( *ptr == '\0' )  /* zero byte */ {
                   ptr++;	/* skip zero byte */
                   space -= 1;
                   len   -= 1;
-
 		  break;
 	       }
 
-               if( *ptr == '\n' )  /* newline */
-               {
+               if( *ptr == '\n' )  /* newline */ {
                   ptr++;	/* skip newline */
                   space -= 1;
                   len   -= 1;
 
                   *line = 0;  /* force null terminator */
-	          Syslog(LOG_INFO, line_buff);
+	          submitSyslog(LOG_INFO, line_buff);
                   line  = line_buff;
                   space = sizeof(line_buff)-1;
-		  if (symbols_twice) {
+		  if(pModConf->symbols_twice) {
 		      if (symbols_expanded) {
 			  /* reprint this line without symbol lookup */
 			  symbols_expanded = 0;
 			  skip_symbol_lookup = 1;
 			  ptr = save_ptr;
 			  len = save_len;
-		      }
-		      else
-		      {
+		      } else {
 			  skip_symbol_lookup = 0;
 			  save_ptr = ptr;
 			  save_len = len;
@@ -295,8 +379,7 @@ static void LogLine(char *ptr, int len)
 		  }
                   break;
                }
-               if( *ptr == '[' )   /* possible kernel symbol */
-               {
+               if( *ptr == '[' )   /* possible kernel symbol */ {
                   *line++ = *ptr++;
                   space -= 1;
                   len   -= 1;
@@ -310,8 +393,7 @@ static void LogLine(char *ptr, int len)
                break;
         
         case PARSING_SYMSTART:
-               if( *ptr != '<' )
-               {
+               if( *ptr != '<' ) {
                   parse_state = PARSING_TEXT;        /* not a symbol */
                   break;
                }
@@ -376,8 +458,7 @@ static void LogLine(char *ptr, int len)
                value  = strtoul((char*)(sym_start+1), (char **) 0, 16);
                *(line-1) = '>';  /* put back delim */
 
-               if ( !symbol_lookup || (symbol = LookupSymbol(value, &sym)) == (char *)0 )
-               {
+               if(!pModConf->symbol_lookup || (symbol = LookupSymbol(value, &sym)) == (char *)0 ) {
                   parse_state = PARSING_TEXT;
                   break;
                }
@@ -415,7 +496,7 @@ static void LogLine(char *ptr, int len)
 }
 
 
-static void LogKernelLine(void)
+static void LogKernelLine(modConfData_t *pModConf)
 {
 	auto int rdcnt;
 
@@ -433,12 +514,12 @@ static void LogKernelLine(void)
 		imklogLogIntMsg(LOG_ERR, "imklog Error return from sys_sycall: %d\n", errno);
 	}
 	else
-		LogLine(log_buffer, rdcnt);
+		LogLine(pModConf, log_buffer, rdcnt);
 	return;
 }
 
 
-static void LogProcLine(void)
+static void LogProcLine(modConfData_t *pModConf)
 {
 	auto int rdcnt;
 
@@ -452,9 +533,10 @@ static void LogProcLine(void)
 	if ( (rdcnt = read(kmsg, log_buffer, sizeof(log_buffer)-1)) < 0 ) {
 		if ( errno == EINTR )
 			return;
-		imklogLogIntMsg(LOG_ERR, "Cannot read proc file system: %d - %s.", errno, strerror(errno));
+		imklogLogIntMsg(LOG_ERR, "Cannot read proc file system: %d - %s "
+			"(fd %d)", errno, strerror(errno), kmsg);
 	} else {
-		LogLine(log_buffer, rdcnt);
+		LogLine(pModConf, log_buffer, rdcnt);
         }
 
 	return;
@@ -464,15 +546,15 @@ static void LogProcLine(void)
 /* to be called in the module's WillRun entry point
  * rgerhards, 2008-04-09
  */
-rsRetVal klogLogKMsg(void)
+rsRetVal klogLogKMsg(modConfData_t *pModConf)
 {
         DEFiRet;
         switch(logsrc) {
                 case kernel:
-                        LogKernelLine();
+                        LogKernelLine(pModConf);
                         break;
                 case proc:
-                        LogProcLine();
+                        LogProcLine(pModConf);
                         break;
                 case none:
                         /* TODO: We need to handle this case here somewhat more intelligent 
@@ -489,19 +571,19 @@ rsRetVal klogLogKMsg(void)
 /* to be called in the module's WillRun entry point
  * rgerhards, 2008-04-09
  */
-rsRetVal klogWillRun(void)
+rsRetVal klogWillRun(modConfData_t *pModConf)
 {
         DEFiRet;
 	/* Initialize this module. If that fails, we tell the engine we don't like to run */
 	/* Determine where kernel logging information is to come from. */
-	logsrc = GetKernelLogSrc();
+	logsrc = GetKernelLogSrc(pModConf);
 	if(logsrc == none) {
 		iRet = RS_RET_NO_KERNEL_LOGSRC;
 	} else {
-		if (symbol_lookup) {
-			symbol_lookup  = (InitKsyms(symfile) == 1);
-			symbol_lookup |= InitMsyms();
-			if (symbol_lookup == 0) {
+		if(pModConf->symbol_lookup) {
+			pModConf->symbol_lookup  = (InitKsyms(pModConf) == 1);
+			pModConf->symbol_lookup |= InitMsyms();
+			if(pModConf->symbol_lookup == 0) {
 				imklogLogIntMsg(LOG_WARNING, "cannot find any symbols, turning off symbol lookups");
 			}
 		}
@@ -514,12 +596,12 @@ rsRetVal klogWillRun(void)
 /* to be called in the module's AfterRun entry point
  * rgerhards, 2008-04-09
  */
-rsRetVal klogAfterRun(void)
+rsRetVal klogAfterRun(modConfData_t *pModConf)
 {
         DEFiRet;
 	/* cleanup here */
 	if(logsrc != none)
-		CloseLogSrc();
+		CloseLogSrc(pModConf);
 
 	DeinitKsyms();
 	DeinitMsyms();