{"thread":{"id":"36713","subject":"[RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","startedAt":"2014-05-20T19:11:13Z","lastAt":"2014-05-23T20:21:27Z","messageCount":17,"participants":["Karsten Blees","Noel Grandin","Jeff King","Junio C Hamano","Richard Hansen"],"isPatch":true,"patchVersion":4,"patchTotal":3},"messages":[{"id":"242312","messageId":"537BA8D1.1090503@gmail.com","threadId":"36713","inReplyTo":"537BA806.50600@gmail.com","subject":"[RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-20T19:11:13Z","receivedAt":"2014-05-20T19:11:13Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Add a getnanotime() function that returns nanoseconds since 01/01/1970 as\nunsigned 64-bit integer (i.e. overflows in july 2554). This is easier to\nwork with than e.g. struct timeval or struct timespec.\n\nThe implementation uses gettimeofday() by default; supports high precision\ntime sources on the following platforms:\n * Linux: using clock_gettime(CLOCK_MONOTONIC)\n * Windows: using QueryPerformanceCounter()\n\nTodo:\n * enable clock_gettime() on more platforms\n * implement Mac OSX version using mach_absolute_time\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n Makefile         |  7 +++++\n cache.h          |  1 +\n config.mak.uname |  1 +\n trace.c          | 82 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++\n 4 files changed, 91 insertions(+)\n\ndiff --git a/Makefile b/Makefile\nindex a53f3a8..3c05f8c 100644\n--- a/Makefile\n+++ b/Makefile\n@@ -341,6 +341,8 @@ all::\n #\n # Define GMTIME_UNRELIABLE_ERRORS if your gmtime() function does not\n # return NULL when it receives a bogus time_t.\n+#\n+# Define HAVE_CLOCK_GETTIME if your platform has clock_gettime in librt.\n \n GIT-VERSION-FILE: FORCE\n \t@$(SHELL_PATH) ./GIT-VERSION-GEN\n@@ -1497,6 +1499,11 @@ ifdef GMTIME_UNRELIABLE_ERRORS\n \tBASIC_CFLAGS += -DGMTIME_UNRELIABLE_ERRORS\n endif\n \n+ifdef HAVE_CLOCK_GETTIME\n+\tBASIC_CFLAGS += -DHAVE_CLOCK_GETTIME\n+\tEXTLIBS += -lrt\n+endif\n+\n ifeq ($(TCLTK_PATH),)\n NO_TCLTK = NoThanks\n endif\ndiff --git a/cache.h b/cache.h\nindex 107ac61..48fc616 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -1362,6 +1362,7 @@ extern int trace_want(const char *key);\n __attribute__((format (printf, 2, 3)))\n extern void trace_printf_key(const char *key, const char *fmt, ...);\n extern void trace_strbuf(const char *key, const struct strbuf *buf);\n+extern uint64_t getnanotime(void);\n \n void packet_trace_identity(const char *prog);\n \ndiff --git a/config.mak.uname b/config.mak.uname\nindex 23a8803..5e3b1dd 100644\n--- a/config.mak.uname\n+++ b/config.mak.uname\n@@ -33,6 +33,7 @@ ifeq ($(uname_S),Linux)\n \tHAVE_PATHS_H = YesPlease\n \tLIBC_CONTAINS_LIBINTL = YesPlease\n \tHAVE_DEV_TTY = YesPlease\n+\tHAVE_CLOCK_GETTIME = YesPlease\n endif\n ifeq ($(uname_S),GNU/kFreeBSD)\n \tNO_STRLCPY = YesPlease\ndiff --git a/trace.c b/trace.c\nindex 08180a9..3d72084 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -187,3 +187,85 @@ int trace_want(const char *key)\n \t\treturn 0;\n \treturn 1;\n }\n+\n+#ifdef HAVE_CLOCK_GETTIME\n+\n+static inline uint64_t highres_nanos(void)\n+{\n+\tstruct timespec ts;\n+\tif (clock_gettime(CLOCK_MONOTONIC, &ts))\n+\t\treturn 0;\n+\treturn (uint64_t) ts.tv_sec * 1000000000 + ts.tv_nsec;\n+}\n+\n+#elif defined (GIT_WINDOWS_NATIVE)\n+\n+static inline uint64_t highres_nanos(void)\n+{\n+\tstatic uint64_t high_ns, scaled_low_ns;\n+\tstatic int scale;\n+\tLARGE_INTEGER cnt;\n+\n+\tif (!scale) {\n+\t\tif (!QueryPerformanceFrequency(&cnt))\n+\t\t\treturn 0;\n+\n+\t\t/* high_ns = number of ns per cnt.HighPart */\n+\t\thigh_ns = (1000000000LL << 32) / (uint64_t) cnt.QuadPart;\n+\n+\t\t/*\n+\t\t * Number of ns per cnt.LowPart is 10^9 / frequency (or\n+\t\t * high_ns >> 32). For maximum precision, we scale this factor\n+\t\t * so that it just fits within 32 bit (i.e. won't overflow if\n+\t\t * multiplied with cnt.LowPart).\n+\t\t */\n+\t\tscaled_low_ns = high_ns;\n+\t\tscale = 32;\n+\t\twhile (scaled_low_ns >= 0x100000000LL) {\n+\t\t\tscaled_low_ns >>= 1;\n+\t\t\tscale--;\n+\t\t}\n+\t}\n+\n+\t/* if QPF worked on initialization, we expect QPC to work as well */\n+\tQueryPerformanceCounter(&cnt);\n+\n+\treturn (high_ns * cnt.HighPart) +\n+\t       ((scaled_low_ns * cnt.LowPart) >> scale);\n+}\n+\n+#else\n+# define highres_nanos() 0\n+#endif\n+\n+static inline uint64_t gettimeofday_nanos(void)\n+{\n+\tstruct timeval tv;\n+\tgettimeofday(&tv, NULL);\n+\treturn (uint64_t) tv.tv_sec * 1000000000 + tv.tv_usec * 1000;\n+}\n+\n+/*\n+ * Returns nanoseconds since the epoch (01/01/1970), for performance tracing\n+ * (i.e. favoring high precision over wall clock time accuracy).\n+ */\n+inline uint64_t getnanotime(void)\n+{\n+\tstatic uint64_t offset;\n+\tif (offset > 1) {\n+\t\t/* initialization succeeded, return offset + high res time */\n+\t\treturn offset + highres_nanos();\n+\t} else if (offset == 1) {\n+\t\t/* initialization failed, fall back to gettimeofday */\n+\t\treturn gettimeofday_nanos();\n+\t} else {\n+\t\t/* initialize offset if high resolution timer works */\n+\t\tuint64_t now = gettimeofday_nanos();\n+\t\tuint64_t highres = highres_nanos();\n+\t\tif (highres)\n+\t\t\toffset = now - highres;\n+\t\telse\n+\t\t\toffset = 1;\n+\t\treturn now;\n+\t}\n+}\n-- \n1.9.2.msysgit.0.493.g47a82c3\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242313","messageId":"537BA8D7.4000007@gmail.com","threadId":"36713","inReplyTo":"537BA806.50600@gmail.com","subject":"[RFC/PATCH v4 2/3] add trace_performance facility to debug performance issues","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-20T19:11:19Z","receivedAt":"2014-05-20T19:11:19Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Add trace_performance and trace_performance_since macros that print file\nname, line number, time and an optional printf-formatted text to the file\nspecified in environment variable GIT_TRACE_PERFORMANCE.\n\nUnless enabled via GIT_TRACE_PERFORMANCE, these macros have no noticeable\nimpact on performance, so that test code may be shipped in release builds.\n\nMSVC: variadic macros (__VA_ARGS__) require VC++ 2005 or newer.\n\nSimple use case (measure one code section):\n\n  uint64_t start = getnanotime();\n  /* code section to measure */\n  trace_performance_since(start, \"foobar\");\n\nMedium use case (measure consecutive code sections):\n\n  uint64_t start = getnanotime();\n  /* first code section to measure */\n  start = trace_performance_since(start, \"first foobar\");\n  /* second code section to measure */\n  trace_performance_since(start, \"second foobar\");\n\nComplex use case (measure repetitive code sections):\n\n  uint64_t t = 0;\n  for (;;) {\n    /* ignore */\n    t -= getnanotime();\n    /* code section to measure */\n    t += getnanotime();\n    /* ignore */\n  }\n  trace_performance(t, \"frotz\");\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n cache.h | 18 ++++++++++++++++++\n trace.c | 40 ++++++++++++++++++++++++++++++++++++++++\n 2 files changed, 58 insertions(+)\n\ndiff --git a/cache.h b/cache.h\nindex 48fc616..cb856d9 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -1363,6 +1363,24 @@ __attribute__((format (printf, 2, 3)))\n extern void trace_printf_key(const char *key, const char *fmt, ...);\n extern void trace_strbuf(const char *key, const struct strbuf *buf);\n extern uint64_t getnanotime(void);\n+__attribute__((format (printf, 4, 5)))\n+extern uint64_t trace_performance_file_line(const char *file, int lineno,\n+\tuint64_t nanos, const char *fmt, ...);\n+\n+/*\n+ * Prints specified time (in nanoseconds) if GIT_TRACE_PERFORMANCE is enabled.\n+ * Returns current time in nanoseconds.\n+ */\n+#define trace_performance(nanos, ...) \\\n+\ttrace_performance_file_line(__FILE__, __LINE__, nanos, __VA_ARGS__)\n+\n+/*\n+ * Prints time since 'start' if GIT_TRACE_PERFORMANCE is enabled.\n+ * Returns current time in nanoseconds.\n+ */\n+#define trace_performance_since(start, ...) \\\n+\ttrace_performance_file_line(__FILE__, __LINE__, \\\n+\t\tgetnanotime() - (start), __VA_ARGS__)\n \n void packet_trace_identity(const char *prog);\n \ndiff --git a/trace.c b/trace.c\nindex 3d72084..1b1903b 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -269,3 +269,43 @@ inline uint64_t getnanotime(void)\n \t\treturn now;\n \t}\n }\n+\n+static const char *GIT_TRACE_PERFORMANCE = \"GIT_TRACE_PERFORMANCE\";\n+\n+static inline int trace_want_performance(void)\n+{\n+\tstatic int enabled = -1;\n+\tif (enabled < 0)\n+\t\tenabled = trace_want(GIT_TRACE_PERFORMANCE);\n+\treturn enabled;\n+}\n+\n+/*\n+ * Prints performance data if environment variable GIT_TRACE_PERFORMANCE is\n+ * set, otherwise a NOOP. Returns the current time in nanoseconds.\n+ */\n+__attribute__((format (printf, 4, 5)))\n+uint64_t trace_performance_file_line(const char *file, int lineno,\n+\t\t\t\t     uint64_t nanos, const char *fmt, ...)\n+{\n+\tstruct strbuf buf = STRBUF_INIT;\n+\tva_list args;\n+\n+\tif (!trace_want_performance())\n+\t\treturn 0;\n+\n+\tstrbuf_addf(&buf, \"performance: at %s:%i, time: %.9f s\", file, lineno,\n+\t\t    (double) nanos / 1000000000);\n+\n+\tif (fmt && *fmt) {\n+\t\tstrbuf_addstr(&buf, \": \");\n+\t\tva_start(args, fmt);\n+\t\tstrbuf_vaddf(&buf, fmt, args);\n+\t\tva_end(args);\n+\t}\n+\tstrbuf_addch(&buf, '\\n');\n+\n+\ttrace_strbuf(GIT_TRACE_PERFORMANCE, &buf);\n+\tstrbuf_release(&buf);\n+\treturn getnanotime();\n+}\n-- \n1.9.2.msysgit.0.493.g47a82c3\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242314","messageId":"537BA8DC.9070104@gmail.com","threadId":"36713","inReplyTo":"537BA806.50600@gmail.com","subject":"[RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-20T19:11:24Z","receivedAt":"2014-05-20T19:11:24Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Add performance tracing to identify which git commands are called and how\nlong they execute. This is particularly useful to debug performance issues\nof scripted commands.\n\nUsage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list\n\nCreates a log file like this:\nperformance: at trace.c:319, time: 0.000303280 s: git command: 'git' 'rev-parse' '--git-dir'\nperformance: at trace.c:319, time: 0.000334409 s: git command: 'git' 'rev-parse' '--is-inside-work-tree'\nperformance: at trace.c:319, time: 0.000215243 s: git command: 'git' 'rev-parse' '--show-toplevel'\nperformance: at trace.c:319, time: 0.000410639 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive'\nperformance: at trace.c:319, time: 0.000394077 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold'\nperformance: at trace.c:319, time: 0.000280701 s: git command: 'git' 'config' '--get-color' '' 'reset'\nperformance: at trace.c:319, time: 0.000908185 s: git command: 'git' 'rev-parse' '--verify' 'refs/stash'\nperformance: at trace.c:319, time: 0.028827774 s: git command: 'git' 'stash' 'list'\n\nSigned-off-by: Karsten Blees <blees@dcon.de>\n---\n cache.h |  1 +\n git.c   |  2 ++\n trace.c | 22 ++++++++++++++++++++++\n 3 files changed, 25 insertions(+)\n\ndiff --git a/cache.h b/cache.h\nindex cb856d9..289e8fd 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -1366,6 +1366,7 @@ extern uint64_t getnanotime(void);\n __attribute__((format (printf, 4, 5)))\n extern uint64_t trace_performance_file_line(const char *file, int lineno,\n \tuint64_t nanos, const char *fmt, ...);\n+extern void trace_command_performance(const char **argv);\n \n /*\n  * Prints specified time (in nanoseconds) if GIT_TRACE_PERFORMANCE is enabled.\ndiff --git a/git.c b/git.c\nindex 9efd1a3..2ea65b1 100644\n--- a/git.c\n+++ b/git.c\n@@ -568,6 +568,8 @@ int main(int argc, char **av)\n \n \tgit_setup_gettext();\n \n+\ttrace_command_performance(argv);\n+\n \t/*\n \t * \"git-xxxx\" is the same as \"git xxxx\", but we obviously:\n \t *\ndiff --git a/trace.c b/trace.c\nindex 1b1903b..9edcb59 100644\n--- a/trace.c\n+++ b/trace.c\n@@ -309,3 +309,25 @@ uint64_t trace_performance_file_line(const char *file, int lineno,\n \tstrbuf_release(&buf);\n \treturn getnanotime();\n }\n+\n+static uint64_t command_start_time;\n+static struct strbuf command_line = STRBUF_INIT;\n+\n+static void print_command_performance_atexit(void)\n+{\n+\ttrace_performance_since(command_start_time, \"git command:%s\",\n+\t\t\t\tcommand_line.buf);\n+}\n+\n+void trace_command_performance(const char **argv)\n+{\n+\tif (!trace_want_performance())\n+\t\treturn;\n+\n+\tif (!command_start_time)\n+\t\tatexit(print_command_performance_atexit);\n+\n+\tstrbuf_reset(&command_line);\n+\tsq_quote_argv(&command_line, argv, 0);\n+\tcommand_start_time = getnanotime();\n+}\n-- \n1.9.2.msysgit.0.493.g47a82c3\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242357","messageId":"537C5634.3050807@peralex.com","threadId":"36713","inReplyTo":"537BA8D1.1090503@gmail.com","subject":"Re: [RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Noel Grandin","fromEmail":"noel@peralex.com","sentAt":"2014-05-21T07:31:00Z","receivedAt":"2014-05-21T07:31:00Z","isPatch":true,"sender":{"key":"noel@peralex.com","avatar":null},"body":"On 2014-05-20 21:11, Karsten Blees wrote:\n>   * implement Mac OSX version using mach_absolute_time\n>\n>\n\n\nNote that unlike the Windows and Linux APIs, mach_absolute_time does not do correction for frequency-scaling and \ncross-CPU synchronization with the TSC.\n\nI'm not aware of anything else that you could use on MacOS, so your best bet is probably just to use mach_absolute_time \nand document it's shortcomings.\n\nRegards, Noel.\n\nDisclaimer: http://www.peralex.com/disclaimer.html\n"},{"id":"242358","messageId":"537C6E68.8030104@gmail.com","threadId":"36713","inReplyTo":"537C5634.3050807@peralex.com","subject":"Re: [RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-21T09:14:16Z","receivedAt":"2014-05-21T09:14:16Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 21.05.2014 09:31, schrieb Noel Grandin:\n> On 2014-05-20 21:11, Karsten Blees wrote:\n>>   * implement Mac OSX version using mach_absolute_time\n>>\n>>\n> \n> \n> Note that unlike the Windows and Linux APIs, mach_absolute_time does not do correction for frequency-scaling\n\nI don't have a MAC so I can't test any of this, but supposedly mach_timebase_info() returns the frequency of mach_absolute_time(), so you could do similar frequency-scaling as I do for Windows with QueryPerformanceFrequency().\n\n> and cross-CPU synchronization with the TSC.\n> \n\nThe TSC is synchronized across cores and sockets on modern x86 hardware [1] (at least since Intel Nehalem, i.e. all Core i[357] processors). On older machines, I would expect the OS API to choose a more appropriate time source, e.g. the HPET. I'm not proposing to use asm(\"rdtsc\") or anything like that...\n\n[1] https://software.intel.com/en-us/articles/best-timing-function-for-measuring-ipp-api-timing\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242388","messageId":"20140521165508.GC2040@sigill.intra.peff.net","threadId":"36713","inReplyTo":"537BA8DC.9070104@gmail.com","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-05-21T16:55:08Z","receivedAt":"2014-05-21T16:55:08Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, May 20, 2014 at 09:11:24PM +0200, Karsten Blees wrote:\n\n> Add performance tracing to identify which git commands are called and how\n> long they execute. This is particularly useful to debug performance issues\n> of scripted commands.\n> \n> Usage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list\n> \n> Creates a log file like this:\n> performance: at trace.c:319, time: 0.000303280 s: git command: 'git' 'rev-parse' '--git-dir'\n> performance: at trace.c:319, time: 0.000334409 s: git command: 'git' 'rev-parse' '--is-inside-work-tree'\n> performance: at trace.c:319, time: 0.000215243 s: git command: 'git' 'rev-parse' '--show-toplevel'\n> performance: at trace.c:319, time: 0.000410639 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive'\n> performance: at trace.c:319, time: 0.000394077 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold'\n> performance: at trace.c:319, time: 0.000280701 s: git command: 'git' 'config' '--get-color' '' 'reset'\n> performance: at trace.c:319, time: 0.000908185 s: git command: 'git' 'rev-parse' '--verify' 'refs/stash'\n> performance: at trace.c:319, time: 0.028827774 s: git command: 'git' 'stash' 'list'\n\nNeat. I actually wanted something like this just yesterday. It looks\nlike you are mainly tracing the execution of programs. Would it make\nsense to just tie this to regular trace_* calls, and if\nGIT_TRACE_PERFORMANCE is set, add a timestamp to each line?\n\nThen we would not need to add separate trace_command_performance calls,\nand other parts of the code that are already instrumented with GIT_TRACE\nwould get the feature for free.\n\n-Peff\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242390","messageId":"20140521165806.GD2040@sigill.intra.peff.net","threadId":"36713","inReplyTo":"537BA8D7.4000007@gmail.com","subject":"Re: [RFC/PATCH v4 2/3] add trace_performance facility to debug performance issues","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-05-21T16:58:06Z","receivedAt":"2014-05-21T16:58:06Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, May 20, 2014 at 09:11:19PM +0200, Karsten Blees wrote:\n\n> Add trace_performance and trace_performance_since macros that print file\n> name, line number, time and an optional printf-formatted text to the file\n> specified in environment variable GIT_TRACE_PERFORMANCE.\n> \n> Unless enabled via GIT_TRACE_PERFORMANCE, these macros have no noticeable\n> impact on performance, so that test code may be shipped in release builds.\n> \n> MSVC: variadic macros (__VA_ARGS__) require VC++ 2005 or newer.\n\nI think we still have some Unix compilers that do not do variadic\nmacros, either. For a while, people were compiling with antique stuff\nlike SUNWspro and MIPSpro. I don't know if they still do, if they use\ngcc on such systems now, or if those systems have finally been\ndecomissioned.\n\nBut either we need to change our stance on variadic macros, or this\nfeature needs to be able to be compiled conditionally.\n\n-Peff\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242396","messageId":"xmqq1tvnqbga.fsf@gitster.dls.corp.google.com","threadId":"36713","inReplyTo":"20140521165508.GC2040@sigill.intra.peff.net","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-05-21T17:38:13Z","receivedAt":"2014-05-21T17:38:13Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King <peff@peff.net> writes:\n\n> On Tue, May 20, 2014 at 09:11:24PM +0200, Karsten Blees wrote:\n>\n>> Add performance tracing to identify which git commands are called and how\n>> long they execute. This is particularly useful to debug performance issues\n>> of scripted commands.\n>> \n>> Usage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list\n>> \n>> Creates a log file like this:\n>> performance: at trace.c:319, time: 0.000303280 s: git command: 'git' 'rev-parse' '--git-dir'\n>> performance: at trace.c:319, time: 0.000334409 s: git command: 'git' 'rev-parse' '--is-inside-work-tree'\n>> performance: at trace.c:319, time: 0.000215243 s: git command: 'git' 'rev-parse' '--show-toplevel'\n>> performance: at trace.c:319, time: 0.000410639 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive'\n>> performance: at trace.c:319, time: 0.000394077 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold'\n>> performance: at trace.c:319, time: 0.000280701 s: git command: 'git' 'config' '--get-color' '' 'reset'\n>> performance: at trace.c:319, time: 0.000908185 s: git command: 'git' 'rev-parse' '--verify' 'refs/stash'\n>> performance: at trace.c:319, time: 0.028827774 s: git command: 'git' 'stash' 'list'\n>\n> Neat. I actually wanted something like this just yesterday. It looks\n> like you are mainly tracing the execution of programs. Would it make\n> sense to just tie this to regular trace_* calls, and if\n> GIT_TRACE_PERFORMANCE is set, add a timestamp to each line?\n\nYeah, I very much like both, the output and your suggestion to hook\nit into the existing infrastructure.\n\n> Then we would not need to add separate trace_command_performance calls,\n> and other parts of the code that are already instrumented with GIT_TRACE\n> would get the feature for free.\n>\n> -Peff\n>\n> -- \n"},{"id":"242402","messageId":"537CF1C7.6030408@gmail.com","threadId":"36713","inReplyTo":"20140521165806.GD2040@sigill.intra.peff.net","subject":"Re: [RFC/PATCH v4 2/3] add trace_performance facility to debug performance issues","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-21T18:34:47Z","receivedAt":"2014-05-21T18:34:47Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 21.05.2014 18:58, schrieb Jeff King:\n> On Tue, May 20, 2014 at 09:11:19PM +0200, Karsten Blees wrote:\n> \n>> Add trace_performance and trace_performance_since macros that print file\n>> name, line number, time and an optional printf-formatted text to the file\n>> specified in environment variable GIT_TRACE_PERFORMANCE.\n>>\n>> Unless enabled via GIT_TRACE_PERFORMANCE, these macros have no noticeable\n>> impact on performance, so that test code may be shipped in release builds.\n>>\n>> MSVC: variadic macros (__VA_ARGS__) require VC++ 2005 or newer.\n> \n> I think we still have some Unix compilers that do not do variadic\n> macros, either. For a while, people were compiling with antique stuff\n> like SUNWspro and MIPSpro. I don't know if they still do, if they use\n> gcc on such systems now, or if those systems have finally been\n> decomissioned.\n> \n> But either we need to change our stance on variadic macros, or this\n> feature needs to be able to be compiled conditionally.\n> \n> -Peff\n> \n\nMacros are mainly used to supply __FILE__ and __LINE__, so that lazy people don't need to think of a unique message for each use of trace_performance_*. Without __FILE__, __LINE__ and message, the output would be pretty useless (i.e. just the time without any additional info).\n\nIf there's platforms that don't support variadic macros, I'd suggest to drop the __FILE__ __LINE__ feature completely and make message mandatory (with the added benefit that manually provided messages don't change if the code is moved, i.e. trace logs would become somewhat comparable across versions).\n\n(adding cc: Dscho as IIRC the __FILE__ __LINE__ idea was originally his).\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242409","messageId":"20140521205524.GB8381@sigill.intra.peff.net","threadId":"36713","inReplyTo":"537CF1C7.6030408@gmail.com","subject":"Re: [RFC/PATCH v4 2/3] add trace_performance facility to debug performance issues","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-05-21T20:55:24Z","receivedAt":"2014-05-21T20:55:24Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, May 21, 2014 at 08:34:47PM +0200, Karsten Blees wrote:\n\n> Macros are mainly used to supply __FILE__ and __LINE__, so that lazy\n> people don't need to think of a unique message for each use of\n> trace_performance_*. Without __FILE__, __LINE__ and message, the\n> output would be pretty useless (i.e. just the time without any\n> additional info).\n> \n> If there's platforms that don't support variadic macros, I'd suggest\n> to drop the __FILE__ __LINE__ feature completely and make message\n> mandatory (with the added benefit that manually provided messages\n> don't change if the code is moved, i.e. trace logs would become\n> somewhat comparable across versions).\n\nI do think __FILE__ and __LINE__ can be useful, and it would not be the\nend of the world to simply omit them on platforms that can't do the\nvariadic macros (there shouldn't be many these days, and I think they\nare used to living with reduced functionality in some cases).\n\nBut if this were attached to trace_printf, we would always have a\nmessage anyway, no?\n\n-Peff\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242431","messageId":"537D2528.3090806@bbn.com","threadId":"36713","inReplyTo":"537BA8D1.1090503@gmail.com","subject":"Re: [RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Richard Hansen","fromEmail":"rhansen@bbn.com","sentAt":"2014-05-21T22:14:00Z","receivedAt":"2014-05-21T22:14:00Z","isPatch":true,"sender":{"key":"rhansen@rhansen.org","avatar":null},"body":"On 2014-05-20 15:11, Karsten Blees wrote:\n> Add a getnanotime() function that returns nanoseconds since 01/01/1970 as\n> unsigned 64-bit integer (i.e. overflows in july 2554).\n\nMust it be relative to epoch?  If it was relative to system boot (like\nthe NetBSD kernel's nanouptime() function), then you wouldn't have to\nworry about clock adjustments messing with performance stats and you\nmight have more options for implementing getnanotime() on various platforms.\n\n-Richard\n"},{"id":"242433","messageId":"537D2615.20606@bbn.com","threadId":"36713","inReplyTo":"537D2528.3090806@bbn.com","subject":"Re: [RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Richard Hansen","fromEmail":"rhansen@bbn.com","sentAt":"2014-05-21T22:17:57Z","receivedAt":"2014-05-21T22:17:57Z","isPatch":true,"sender":{"key":"rhansen@rhansen.org","avatar":null},"body":"On 2014-05-21 18:14, Richard Hansen wrote:\n> On 2014-05-20 15:11, Karsten Blees wrote:\n>> Add a getnanotime() function that returns nanoseconds since 01/01/1970 as\n>> unsigned 64-bit integer (i.e. overflows in july 2554).\n> \n> Must it be relative to epoch?  If it was relative to system boot (like\n> the NetBSD kernel's nanouptime() function),\n\nor relative to some other arbitrary reference point\n\n> then you wouldn't have to\n> worry about clock adjustments messing with performance stats and you\n> might have more options for implementing getnanotime() on various platforms.\n> \n> -Richard\n"},{"id":"242447","messageId":"537D4790.6030106@gmail.com","threadId":"36713","inReplyTo":"20140521165508.GC2040@sigill.intra.peff.net","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-22T00:40:48Z","receivedAt":"2014-05-22T00:40:48Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 21.05.2014 18:55, schrieb Jeff King:\n> On Tue, May 20, 2014 at 09:11:24PM +0200, Karsten Blees wrote:\n> \n>> Add performance tracing to identify which git commands are called and how\n>> long they execute. This is particularly useful to debug performance issues\n>> of scripted commands.\n>>\n>> Usage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list\n>>\n>> Creates a log file like this:\n>> performance: at trace.c:319, time: 0.000303280 s: git command: 'git' 'rev-parse' '--git-dir'\n>> performance: at trace.c:319, time: 0.000334409 s: git command: 'git' 'rev-parse' '--is-inside-work-tree'\n>> performance: at trace.c:319, time: 0.000215243 s: git command: 'git' 'rev-parse' '--show-toplevel'\n>> performance: at trace.c:319, time: 0.000410639 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive'\n>> performance: at trace.c:319, time: 0.000394077 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold'\n>> performance: at trace.c:319, time: 0.000280701 s: git command: 'git' 'config' '--get-color' '' 'reset'\n>> performance: at trace.c:319, time: 0.000908185 s: git command: 'git' 'rev-parse' '--verify' 'refs/stash'\n>> performance: at trace.c:319, time: 0.028827774 s: git command: 'git' 'stash' 'list'\n> \n> Neat. I actually wanted something like this just yesterday. It looks\n> like you are mainly tracing the execution of programs. Would it make\n> sense to just tie this to regular trace_* calls, and if\n> GIT_TRACE_PERFORMANCE is set, add a timestamp to each line?\n> \n> Then we would not need to add separate trace_command_performance calls,\n> and other parts of the code that are already instrumented with GIT_TRACE\n> would get the feature for free.\n> \n> -Peff\n> \n\nIMO printing timestamps in all trace output would be a useful feature on its own, but its not what I'm trying to achieve here. Timestamps only give you a broad overview of when things started, not how long they took. And calculating the durations from timestamps in the log output is tedious work, esp. if multiple processes and threads are involved (would need pid and thread-id as well).\n\nThe first patch helps calculating durations (without having to mess with struct timespec/timeval), and the second helps logging the results. Its basically a utility for manual profiling. Printing total command execution time (this patch) is just one possible use case.\n\nE.g. if I'm interested in a particular code section, I throw in 2 lines of code (before and after the code section). This gives very accurate results, without significantly affecting overall performance. I can then push the changes to my Linux/Windows box and get comparable results there. No need to disable optimization. No worries that the profiling tool isn't available on the other platform. No analyzing megabytes of mostly irrelevant profiling data.\n\nDoes that make sense?\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242448","messageId":"537D53E5.2070605@gmail.com","threadId":"36713","inReplyTo":"537D2528.3090806@bbn.com","subject":"Re: [RFC/PATCH v4 1/3] add high resolution timer function to debug performance issues","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-22T01:33:25Z","receivedAt":"2014-05-22T01:33:25Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 22.05.2014 00:14, schrieb Richard Hansen:\n> On 2014-05-20 15:11, Karsten Blees wrote:\n>> Add a getnanotime() function that returns nanoseconds since 01/01/1970 as\n>> unsigned 64-bit integer (i.e. overflows in july 2554).\n> \n> Must it be relative to epoch?  If it was relative to system boot (like\n> the NetBSD kernel's nanouptime() function), then you wouldn't have to\n> worry about clock adjustments messing with performance stats and you\n> might have more options for implementing getnanotime() on various platforms.\n> \n> -Richard\n> \n\nNormalizing to the epoch adds the ability to use the same timestamps (div 10e9) in other time-related functions (e.g. gmtime, ctime etc.), with very little overhead (one 64-bit integer addition per call).\n\nThe getnanotime() implementation is actually platform independent and can be backed by any time source that returns nanoseconds relative to anything. Getnanotime() is synced to the system clock only once on startup, so if your time source is monotonic (which I think NetBSD's nanouptime() is), you don't have to worry about clock adjustments.\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242478","messageId":"20140522095920.GA15461@sigill.intra.peff.net","threadId":"36713","inReplyTo":"537D4790.6030106@gmail.com","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-05-22T09:59:20Z","receivedAt":"2014-05-22T09:59:20Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, May 22, 2014 at 02:40:48AM +0200, Karsten Blees wrote:\n\n> E.g. if I'm interested in a particular code section, I throw in 2\n> lines of code (before and after the code section). This gives very\n> accurate results, without significantly affecting overall performance.\n> I can then push the changes to my Linux/Windows box and get comparable\n> results there. No need to disable optimization. No worries that the\n> profiling tool isn't available on the other platform. No analyzing\n> megabytes of mostly irrelevant profiling data.\n> \n> Does that make sense?\n\nAh, I see. I misunderstood from your example above.\n\nI do agree that automatically stamping with __FILE__ and __LINE__ is\nvery helpful there. Could we maybe restrict that use of the variadic\nmacros to a few known-good compilers (maybe #ifdef __GNUC__, which also\nhits clang, and something to catch MSVC)? On other systems it would\nbecome a compile-time noop, and they could live without the feature.\n\n-Peff\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242570","messageId":"537F5E9A.1030901@gmail.com","threadId":"36713","inReplyTo":"20140522095920.GA15461@sigill.intra.peff.net","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Karsten Blees","fromEmail":"karsten.blees@gmail.com","sentAt":"2014-05-23T14:43:38Z","receivedAt":"2014-05-23T14:43:38Z","isPatch":true,"sender":{"key":"karsten.blees@gmail.com","avatar":"https://avatars.githubusercontent.com/u/1111200?v=4"},"body":"Am 22.05.2014 11:59, schrieb Jeff King:\n> On Thu, May 22, 2014 at 02:40:48AM +0200, Karsten Blees wrote:\n> \n>> E.g. if I'm interested in a particular code section, I throw in 2\n>> lines of code (before and after the code section). This gives very\n>> accurate results, without significantly affecting overall performance.\n>> I can then push the changes to my Linux/Windows box and get comparable\n>> results there. No need to disable optimization. No worries that the\n>> profiling tool isn't available on the other platform. No analyzing\n>> megabytes of mostly irrelevant profiling data.\n>>\n>> Does that make sense?\n> \n> Ah, I see. I misunderstood from your example above.\n> \n> I do agree that automatically stamping with __FILE__ and __LINE__ is\n> very helpful there. Could we maybe restrict that use of the variadic\n> macros to a few known-good compilers (maybe #ifdef __GNUC__, which also\n> hits clang, and something to catch MSVC)? On other systems it would\n> become a compile-time noop, and they could live without the feature.\n> \n> -Peff\n> \n\nAlright then. I've queued vor v5:\n* add __FILE__ __LINE__ for all trace output, if the compiler supports variadic macros\n* add timestamp for all trace output\n* perhaps move trace declarations to new trace.h\n* improve commit messages of existing patches to clarify the issues discussed so far\n\nI'm on holiday next week , so please be patient...\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"},{"id":"242606","messageId":"20140523202127.GF19088@sigill.intra.peff.net","threadId":"36713","inReplyTo":"537F5E9A.1030901@gmail.com","subject":"Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-05-23T20:21:27Z","receivedAt":"2014-05-23T20:21:27Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, May 23, 2014 at 04:43:38PM +0200, Karsten Blees wrote:\n\n> Alright then. I've queued vor v5:\n> * add __FILE__ __LINE__ for all trace output, if the compiler supports variadic macros\n> * add timestamp for all trace output\n> * perhaps move trace declarations to new trace.h\n> * improve commit messages of existing patches to clarify the issues discussed so far\n\nThanks, that all sounds reasonable.\n\n> I'm on holiday next week , so please be patient...\n\nNo hurry. :)\n\n-Peff\n\n-- \n-- \n*** Please reply-to-all at all times ***\n*** (do not pretend to know who is subscribed and who is not) ***\n*** Please avoid top-posting. ***\nThe msysGit Wiki is here: https://github.com/msysgit/msysgit/wiki - Github accounts are free.\n\nYou received this message because you are subscribed to the Google\nGroups \"msysGit\" group.\nTo post to this group, send email to msysgit@googlegroups.com\nTo unsubscribe from this group, send email to\nmsysgit+unsubscribe@googlegroups.com\nFor more options, and view previous threads, visit this group at\nhttp://groups.google.com/group/msysgit?hl=en_US?hl=en\n\n--- \nYou received this message because you are subscribed to the Google Groups \"msysGit\" group.\nTo unsubscribe from this group and stop receiving emails from it, send an email to msysgit+unsubscribe@googlegroups.com.\nFor more options, visit https://groups.google.com/d/optout.\n"}]}