Add timestamp prefix to LOG[0|1|2]() macros
authorRobert Tivy <rtivy@ti.com>
Fri, 28 Feb 2014 00:19:11 +0000 (16:19 -0800)
committerChris Ring <cring@ti.com>
Thu, 13 Mar 2014 15:21:55 +0000 (08:21 -0700)
For the timestamp prefix, subtract the start time (which is established
when the logFile is opened) so that the massive "since the epoch" value
is not displayed.  For this, subtract only the timeval.tv_sec (seconds)
value so we don't have to worry about the "borrow" that results when
start_tv.tv_usec > tv.tv_usec (essentially, treat start_tv.tv_usec as 0,
which skews this "relative" time ahead by start_tv.tv_usec microseconds).

linux/include/_lad.h
linux/src/daemon/lad.c

index 572956c3842a95bb5781ad4f48d920c8b349f3e6..5f00a988198154e553049138040d10f82250d432 100644 (file)
@@ -49,20 +49,50 @@ extern "C" {
 #include <ti/ipc/GateMP.h>
 #include <_GateMP.h>
 #include <GateHWSpinlock.h>
+#include <sys/time.h>
 
 extern Bool logFile;
 extern FILE *logPtr;
+extern struct timeval start_tv;
 
-/* macros for writing to log file: */
+/*
+ * Macros for writing to log file.
+ *
+ * For the timestamp prefix, subtract the start time (which is established
+ * when the logFile is opened) so that the massive "since the epoch" value
+ * is not displayed.  For this, subtract only the timeval.tv_sec (seconds)
+ * value so we don't have to worry about the "borrow" that results when
+ * start_tv.tv_usec > tv.tv_usec.
+ */
 #define LOG0(a)  \
-    if (logFile == TRUE) {  fprintf(logPtr, a); fflush(logPtr); }
+    if (logFile == TRUE) { \
+        struct timeval tv; \
+        gettimeofday(&tv, NULL); \
+        fprintf(logPtr, "[%d.%06d] " a, \
+                (unsigned int)(tv.tv_sec - start_tv.tv_sec), \
+                (unsigned int)tv.tv_usec); \
+        fflush(logPtr); \
+    }
 
 #define LOG1(a, b)  \
-    if (logFile == TRUE) {  fprintf(logPtr, a, b); fflush(logPtr); }
+    if (logFile == TRUE) { \
+        struct timeval tv; \
+        gettimeofday(&tv, NULL); \
+        fprintf(logPtr, "[%d.%06d] " a, \
+                (unsigned int)(tv.tv_sec - start_tv.tv_sec), \
+                (unsigned int)tv.tv_usec, b); \
+        fflush(logPtr); \
+    }
 
 #define LOG2(a, b, c)  \
-    if (logFile == TRUE) {  fprintf(logPtr, a, b, c); fflush(logPtr); }
-
+    if (logFile == TRUE) { \
+        struct timeval tv; \
+        gettimeofday(&tv, NULL); \
+        fprintf(logPtr, "[%d.%06d] " a, \
+                (unsigned int)(tv.tv_sec - start_tv.tv_sec), \
+                (unsigned int)tv.tv_usec, b, c); \
+        fflush(logPtr); \
+    }
 
 /* macros for generating verbose output: */
 #define PRINTVERBOSE0(a)  \
index 3d6626c9e7140c425de36687ad187d5a6884b541..80d662a414e71ba2bf547f56885e4e992971d119 100644 (file)
@@ -41,6 +41,7 @@
 #include <errno.h>
 #include <fcntl.h>
 #include <sys/stat.h>
+#include <sys/time.h>
 #include <sys/types.h>
 #include <signal.h>
 #include <unistd.h>
@@ -61,6 +62,7 @@
 
 Bool logFile = FALSE;
 FILE *logPtr = NULL;
+struct timeval start_tv;
 
 static String commandFIFOFile = LAD_COMMANDFIFO;
 static FILE *commandFIFOFilePtr = NULL;
@@ -166,6 +168,7 @@ int main(int argc, char * argv[])
                 }
                 else {
                     logFile = TRUE;
+                    gettimeofday(&start_tv, NULL);
                     printf("\nOpened log file: %s", optarg);
                     /* close log file upon LAD termination */
                     flags = fcntl(fileno(logPtr), F_GETFD);