chg: show timestamp with debug messages
Like `strace -tr`, this helps finding performance bottlenecks.
Differential Revision: https://phab.mercurial-scm.org/D807
--- a/contrib/chg/util.c Mon Sep 25 11:05:16 2017 +0200
+++ b/contrib/chg/util.c Sat Sep 23 14:58:40 2017 -0700
@@ -14,6 +14,7 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
+#include <sys/time.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <unistd.h>
@@ -59,6 +60,13 @@
}
static int debugmsgenabled = 0;
+static double debugstart = 0;
+
+static double now() {
+ struct timeval t;
+ gettimeofday(&t, NULL);
+ return t.tv_usec / 1e6 + t.tv_sec;
+}
void enablecolor(void)
{
@@ -68,6 +76,7 @@
void enabledebugmsg(void)
{
debugmsgenabled = 1;
+ debugstart = now();
}
void debugmsg(const char *fmt, ...)
@@ -78,7 +87,7 @@
va_list args;
va_start(args, fmt);
fsetcolor(stderr, "1;30");
- fputs("chg: debug: ", stderr);
+ fprintf(stderr, "chg: debug: %4.6f ", now() - debugstart);
vfprintf(stderr, fmt, args);
fsetcolor(stderr, "");
fputc('\n', stderr);
--- a/tests/test-chg.t Mon Sep 25 11:05:16 2017 +0200
+++ b/tests/test-chg.t Sat Sep 23 14:58:40 2017 -0700
@@ -48,7 +48,7 @@
$ touch foo
$ CHGDEBUG= HGEDITOR=cat chg ci -Am channeled --edit 2>&1 \
> | egrep "HG:|run 'cat"
- chg: debug: run 'cat "*"' at '$TESTTMP/editor' (glob)
+ chg: debug: * run 'cat "*"' at '$TESTTMP/editor' (glob)
HG: Enter commit message. Lines beginning with 'HG:' are removed.
HG: Leave message empty to abort commit.
HG: --
@@ -165,16 +165,16 @@
warm up server:
$ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
- chg: debug: start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
+ chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
new server should be started if extension modified:
$ sleep 1
$ touch dummyext.py
$ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
- chg: debug: instruction: unlink $TESTTMP/extreload/chgsock/server-* (glob)
- chg: debug: instruction: reconnect
- chg: debug: start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
+ chg: debug: * instruction: unlink $TESTTMP/extreload/chgsock/server-* (glob)
+ chg: debug: * instruction: reconnect (glob)
+ chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
old server will shut down, while new server should still be reachable:
@@ -196,7 +196,7 @@
(this test makes sure that old server shut down automatically)
$ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
- chg: debug: start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
+ chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)
shut down servers and restore environment: