Logging: add '--log-show-timestamp' option.

Part of D4214 by @sobakasu w/ edits.

1 files changed, 55 insertions, 0 deletions

diff --git a/intern/clog/clog.c b/intern/clog/clog.c
index 6882d8e89de..6e201cf55f8 100644
--- a/intern/clog/clog.c
+++ b/intern/clog/clog.c
@@ -31,11 +31,19 @@
 /* For 'isatty' to check for color. */
 #if defined(__unix__) || defined(__APPLE__) || defined(__HAIKU__)
 #  include <unistd.h>
+#  include <sys/time.h>
 #endif
 
 #if defined(_MSC_VER)
 #  include <io.h>
+#  include <windows.h>
 #endif
+
+/* For printing timestamp. */
+#define __STDC_FORMAT_MACROS
+#include <inttypes.h>
+
+
 /* Only other dependency (could use regular malloc too). */
 #include "MEM_guardedalloc.h"
 
@@ -69,11 +77,15 @@ typedef struct CLogContext {
 	CLG_IDFilter *filters[2];
 	bool use_color;
 	bool use_basename;
+	bool use_timestamp;
 
 	/** Borrowed, not owned. */
 	int output;
 	FILE *output_file;
 
+	/** For timer (use_timestamp). */
+	uint64_t timestamp_tick_start;
+
 	/** For new types. */
 	struct {
 		int level;
@@ -346,12 +358,35 @@ static void clg_ctx_backtrace(CLogContext *ctx)
 	fflush(ctx->output_file);
 }
 
+static uint64_t clg_timestamp_ticks_get(void)
+{
+	uint64_t tick;
+#if defined(_MSC_VER)
+	tick = GetTickCount64();
+#else
+	struct timeval tv;
+	gettimeofday(&tv, NULL);
+	tick = tv.tv_sec * 1000 + tv.tv_usec / 1000;
+#endif
+	return tick;
+}
+
 /** \} */
 
 /* -------------------------------------------------------------------- */
 /** \name Logging API
  * \{ */
 
+static void write_timestamp(CLogStringBuf *cstr, const uint64_t timestamp_tick_start)
+{
+	char timestamp_str[64];
+	const uint64_t timestamp = clg_timestamp_ticks_get() - timestamp_tick_start;
+	const uint timestamp_len = snprintf(
+	        timestamp_str, sizeof(timestamp_str), "%" PRIu64 ".%03u ",
+	        timestamp / 1000, (uint)(timestamp % 1000));
+	clg_str_append_with_len(cstr, timestamp_str, timestamp_len);
+}
+
 static void write_severity(CLogStringBuf *cstr, enum CLG_Severity severity, bool use_color)
 {
 	assert((unsigned int)severity < CLG_SEVERITY_LEN);
@@ -403,6 +438,10 @@ void CLG_log_str(
 	char cstr_stack_buf[CLOG_BUF_LEN_INIT];
 	clg_str_init(&cstr, cstr_stack_buf, sizeof(cstr_stack_buf));
 
+	if (lg->ctx->use_timestamp) {
+		write_timestamp(&cstr, lg->ctx->timestamp_tick_start);
+	}
+
 	write_severity(&cstr, severity, lg->ctx->use_color);
 	write_type(&cstr, lg);
 
@@ -435,6 +474,10 @@ void CLG_logf(
 	char cstr_stack_buf[CLOG_BUF_LEN_INIT];
 	clg_str_init(&cstr, cstr_stack_buf, sizeof(cstr_stack_buf));
 
+	if (lg->ctx->use_timestamp) {
+		write_timestamp(&cstr, lg->ctx->timestamp_tick_start);
+	}
+
 	write_severity(&cstr, severity, lg->ctx->use_color);
 	write_type(&cstr, lg);
 
@@ -483,6 +526,14 @@ static void CLG_ctx_output_use_basename_set(CLogContext *ctx, int value)
 	ctx->use_basename = (bool)value;
 }
 
+static void CLG_ctx_output_use_timestamp_set(CLogContext *ctx, int value)
+{
+	ctx->use_timestamp = (bool)value;
+	if (ctx->use_timestamp) {
+		ctx->timestamp_tick_start = clg_timestamp_ticks_get();
+	}
+}
+
 /** Action on fatal severity. */
 static void CLG_ctx_fatal_fn_set(CLogContext *ctx, void (*fatal_fn)(void *file_handle))
 {
@@ -585,6 +636,10 @@ void CLG_output_use_basename_set(int value)
 	CLG_ctx_output_use_basename_set(g_ctx, value);
 }
 
+void CLG_output_use_timestamp_set(int value)
+{
+	CLG_ctx_output_use_timestamp_set(g_ctx, value);
+}
 
 void CLG_fatal_fn_set(void (*fatal_fn)(void *file_handle))
 {