trace: add current timestamp to all trace output

This is useful to tell apart trace output of separate test runs.

It can also be used for basic, coarse-grained performance analysis. Note
that the accuracy is tainted by writing to the trace file, and you have to
calculate the deltas yourself (which is next to impossible if multiple
threads or processes are involved).

Signed-off-by: Karsten Blees <blees@dcon.de>
Signed-off-by: Junio C Hamano <gitster@pobox.com>

diff --git a/trace.c b/trace.c
index a194b16000516edd5de7c8ff36f2969a7ef20820..18e5d93c1fbad1a44ec1696b55efe885921cbcab 100644 (file)
--- a/trace.c
+++ b/trace.c
@@ -88,6 +88,9 @@ static const char err_msg[] = "Could not trace into fd given by "
 static int prepare_trace_line(struct trace_key *key, struct strbuf *buf)
 {
        static struct trace_key trace_bare = TRACE_KEY_INIT(BARE);
+       struct timeval tv;
+       struct tm tm;
+       time_t secs;
 
        if (!trace_want(key))
                return 0;
@@ -98,7 +101,12 @@ static int prepare_trace_line(struct trace_key *key, struct strbuf *buf)
        if (trace_want(&trace_bare))
                return 1;
 
-       /* add line prefix here */
+       /* print current timestamp */
+       gettimeofday(&tv, NULL);
+       secs = tv.tv_sec;
+       localtime_r(&secs, &tm);
+       strbuf_addf(buf, "%02d:%02d:%02d.%06ld ", tm.tm_hour, tm.tm_min,
+                   tm.tm_sec, (long) tv.tv_usec);
 
        return 1;
 }