From: David Goulet <dgoulet@efficios.com>
Date: Thu, 22 May 2014 20:59:30 +0000 (-0400)
Subject: Add timestamp to log
X-Git-Url: http://git.efficios.com/?p=lttng-tools.git;a=commitdiff_plain;h=a0b439da54ed351640b74ade4de16db27338ddd1

Add timestamp to log

Also, the ERR() and WARN() now have the timestamp and the PID
information.

Fixes #519

Signed-off-by: David Goulet <dgoulet@efficios.com>
---

diff --git a/src/common/error.c b/src/common/error.c
index eec9b7a3e..93b69843d 100644
--- a/src/common/error.c
+++ b/src/common/error.c
@@ -17,6 +17,7 @@
 
 #define _GNU_SOURCE
 #include <assert.h>
+#include <inttypes.h>
 
 #include <lttng/lttng-error.h>
 #include <common/common.h>
@@ -25,6 +26,42 @@
 
 #define ERROR_INDEX(code) (code - LTTNG_OK)
 
+/* TLS variable that contains the time of one single log entry. */
+DEFINE_URCU_TLS(struct log_time, error_log_time);
+
+const char *log_add_time(void)
+{
+	int ret;
+	struct tm tm, *res;
+	struct timespec tp;
+	time_t now;
+
+	ret = clock_gettime(CLOCK_REALTIME, &tp);
+	if (ret < 0) {
+		goto error;
+	}
+	now = (time_t) tp.tv_sec;
+
+	res = localtime_r(&now, &tm);
+	if (!res) {
+		goto error;
+	}
+
+	/* Format time in the TLS variable. */
+	ret = snprintf(error_log_time.str, sizeof(error_log_time.str),
+			"%02d:%02d:%02d.%06ld",
+			tm.tm_hour, tm.tm_min, tm.tm_sec, tp.tv_nsec);
+	if (ret < 0) {
+		goto error;
+	}
+
+	return error_log_time.str;
+
+error:
+	/* Return an empty string on error so logging is not affected. */
+	return "";
+}
+
 /*
  * Human readable error message.
  */
diff --git a/src/common/error.h b/src/common/error.h
index f8c0a1d06..1b000ab7a 100644
--- a/src/common/error.h
+++ b/src/common/error.h
@@ -22,6 +22,8 @@
 #include <stdio.h>
 #include <stdint.h>
 #include <string.h>
+#include <urcu/tls-compat.h>
+#include <time.h>
 
 #ifndef _GNU_SOURCE
 #error "lttng-tools error.h needs _GNU_SOURCE"
@@ -34,6 +36,17 @@
 #define XSTR(d) STR(d)
 #define STR(s) #s
 
+/*
+ * Contains the string of the log entry time. This is used as a thread local
+ * storage so we don't race between thread and also avoid memory allocation
+ * every time a log is fired.
+ */
+struct log_time {
+	/* Format: 00:00:00.000000 plus NULL byte. */
+	char str[16];
+};
+extern DECLARE_URCU_TLS(struct log_time, error_log_time);
+
 extern int lttng_opt_quiet;
 extern int lttng_opt_verbose;
 
@@ -69,17 +82,17 @@ extern int lttng_opt_verbose;
 
 /* Three level of debug. Use -v, -vv or -vvv for the levels */
 #define _ERRMSG(msg, type, fmt, args...) __lttng_print(type, msg \
-		" [%ld/%ld]: " fmt " (in %s() at " __FILE__ ":" XSTR(__LINE__) ")\n", \
-			(long) getpid(), (long) gettid(), ## args, __func__)
+		" - %s [%ld/%ld]: " fmt " (in %s() at " __FILE__ ":" XSTR(__LINE__) ")\n", \
+			log_add_time(), (long) getpid(), (long) gettid(), ## args, __func__)
 
 #define MSG(fmt, args...) \
 	__lttng_print(PRINT_MSG, fmt "\n", ## args)
 #define _MSG(fmt, args...) \
 	__lttng_print(PRINT_MSG, fmt, ## args)
 #define ERR(fmt, args...) \
-	__lttng_print(PRINT_ERR, "Error: " fmt "\n", ## args)
+	_ERRMSG("ERROR", PRINT_ERR, fmt, ## args)
 #define WARN(fmt, args...) \
-	__lttng_print(PRINT_WARN, "Warning: " fmt "\n", ## args)
+	_ERRMSG("WARN", PRINT_WARN, fmt, ## args)
 
 #define BUG(fmt, args...) _ERRMSG("BUG", PRINT_BUG, fmt, ## args)
 
@@ -115,4 +128,11 @@ extern int lttng_opt_verbose;
 
 const char *error_get_str(int32_t code);
 
+/*
+ * Function that format the time and return the reference of log_time.str to
+ * the caller. On error, an empty string is returned thus no time will be
+ * printed in the log.
+ */
+const char *log_add_time();
+
 #endif /* _ERROR_H */