git/list[1] front-page[2] threads[3] people[4] search[5] about
 

[RFC/PATCH v4 2/3] add trace_performance facility to debug performance issues

From
Karsten Blees <karsten.blees@gmail.com>
Date
May 20, 2014, 19:11 UTC
Message-ID
<537BA8D7.4000007@gmail.com>
In-Reply-To
<537BA806.50600@gmail.com>

Add trace_performance and trace_performance_since macros that print file name, line number, time and an optional printf-formatted text to the file specified in environment variable GIT_TRACE_PERFORMANCE.

Unless enabled via GIT_TRACE_PERFORMANCE, these macros have no noticeable impact on performance, so that test code may be shipped in release builds.

MSVC: variadic macros (__VA_ARGS__) require VC++ 2005 or newer.
Simple use case (measure one code section):
  uint64_t start = getnanotime();
  /* code section to measure */
  trace_performance_since(start, "foobar");
Medium use case (measure consecutive code sections):
  uint64_t start = getnanotime();
  /* first code section to measure */
  start = trace_performance_since(start, "first foobar");
  /* second code section to measure */
  trace_performance_since(start, "second foobar");
Complex use case (measure repetitive code sections):
  uint64_t t = 0;
  for (;;) {
    /* ignore */
    t -= getnanotime();
    /* code section to measure */
    t += getnanotime();
    /* ignore */
  }
  trace_performance(t, "frotz");
Signed-off-by: Karsten Blees <blees@dcon.de>
---
 cache.h | 18 ++++++++++++++++++
 trace.c | 40 ++++++++++++++++++++++++++++++++++++++++
 2 files changed, 58 insertions(+)
diff --git a/cache.h b/cache.h
index 48fc616..cb856d9 100644
--- a/cache.h
+++ b/cache.h
@@ -1363,6 +1363,24 @@ __attribute__((format (printf, 2, 3)))
 extern void trace_printf_key(const char *key, const char *fmt, ...);
 extern void trace_strbuf(const char *key, const struct strbuf *buf);
 extern uint64_t getnanotime(void);
+__attribute__((format (printf, 4, 5)))
+extern uint64_t trace_performance_file_line(const char *file, int lineno,
+	uint64_t nanos, const char *fmt, ...);
+
+/*
+ * Prints specified time (in nanoseconds) if GIT_TRACE_PERFORMANCE is enabled.
+ * Returns current time in nanoseconds.
+ */
+#define trace_performance(nanos, ...) \
+	trace_performance_file_line(__FILE__, __LINE__, nanos, __VA_ARGS__)
+
+/*
+ * Prints time since 'start' if GIT_TRACE_PERFORMANCE is enabled.
+ * Returns current time in nanoseconds.
+ */
+#define trace_performance_since(start, ...) \
+	trace_performance_file_line(__FILE__, __LINE__, \
+		getnanotime() - (start), __VA_ARGS__)
 
 void packet_trace_identity(const char *prog);
 
diff --git a/trace.c b/trace.c
index 3d72084..1b1903b 100644
--- a/trace.c
+++ b/trace.c
@@ -269,3 +269,43 @@ inline uint64_t getnanotime(void)
 		return now;
 	}
 }
+
+static const char *GIT_TRACE_PERFORMANCE = "GIT_TRACE_PERFORMANCE";
+
+static inline int trace_want_performance(void)
+{
+	static int enabled = -1;
+	if (enabled < 0)
+		enabled = trace_want(GIT_TRACE_PERFORMANCE);
+	return enabled;
+}
+
+/*
+ * Prints performance data if environment variable GIT_TRACE_PERFORMANCE is
+ * set, otherwise a NOOP. Returns the current time in nanoseconds.
+ */
+__attribute__((format (printf, 4, 5)))
+uint64_t trace_performance_file_line(const char *file, int lineno,
+				     uint64_t nanos, const char *fmt, ...)
+{
+	struct strbuf buf = STRBUF_INIT;
+	va_list args;
+
+	if (!trace_want_performance())
+		return 0;
+
+	strbuf_addf(&buf, "performance: at %s:%i, time: %.9f s", file, lineno,
+		    (double) nanos / 1000000000);
+
+	if (fmt && *fmt) {
+		strbuf_addstr(&buf, ": ");
+		va_start(args, fmt);
+		strbuf_vaddf(&buf, fmt, args);
+		va_end(args);
+	}
+	strbuf_addch(&buf, '\n');
+
+	trace_strbuf(GIT_TRACE_PERFORMANCE, &buf);
+	strbuf_release(&buf);
+	return getnanotime();
+}
-- 
1.9.2.msysgit.0.493.g47a82c3

-- 
-- 
*** Please reply-to-all at all times ***
*** (do not pretend to know who is subscribed and who is not) ***
*** Please avoid top-posting. ***
The msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.

You received this message because you are subscribed to the Google
Groups "msysGit" group.
To post to this group, send email to msysgit@googlegroups.com
To unsubscribe from this group, send email to
msysgit+unsubscribe@googlegroups.com
For more options, and view previous threads, visit this group at
http://groups.google.com/group/msysgit?hl=en_US?hl=en

--- 
You received this message because you are subscribed to the Google Groups "msysGit" group.
To unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Previous: Karsten BleesNext: Jeff King
Message 7 of 17 in “add high resolution timer function to debug performance issues”
  1. 1/3 add high resolution timer function to debug performance issuesKarsten Blees, May 20, 2014
  2. Noel GrandinMay 21, 2014
  3. Karsten BleesMay 21, 2014
  4. Richard HansenMay 21, 2014
  5. Richard HansenMay 21, 2014
  6. Karsten BleesMay 22, 2014
  7. 2/3 add trace_performance facility to debug performance issuesKarsten Blees, May 20, 2014
  8. Jeff KingMay 21, 2014
  9. Karsten BleesMay 21, 2014
  10. Jeff KingMay 21, 2014
  11. 3/3 add command performance tracing to debug scripted commandsKarsten Blees, May 20, 2014
  12. Jeff KingMay 21, 2014
  13. Junio C HamanoMay 21, 2014
  14. Karsten BleesMay 22, 2014
  15. Jeff KingMay 22, 2014
  16. Karsten BleesMay 23, 2014
  17. Jeff KingMay 23, 2014

Read the whole thread, see it on lore, or plain text.

$ cat FOOTERMessages come from the public archive at lore.kernel.org/git, fetched every hour. The front page is chosen and written each morning by an AI editor and can be wrong; the threads themselves are the record. About and API. For agents: an MCP server at https://gitlist.dev/mcp, and any thread, story or person page as Markdown by adding .md to its URL (or sending Accept: text/markdown). Details in /llms.txt.