diff --git a/mercurial/dispatch.py b/mercurial/dispatch.py --- a/mercurial/dispatch.py +++ b/mercurial/dispatch.py @@ -62,7 +62,16 @@ def dispatch(req): ferr.write(_("hg: parse error: %s\n") % inst.args[0]) return -1 - return _runcatch(req) + msg = ' '.join(' ' in a and repr(a) or a for a in req.args) + starttime = time.time() + ret = None + try: + ret = _runcatch(req) + return ret + finally: + duration = time.time() - starttime + req.ui.log("commandfinish", "%s exited %s after %0.2f seconds\n", + msg, ret or 0, duration) def _runcatch(req): def catchterm(*args): @@ -764,16 +773,10 @@ def _dispatch(req): msg = ' '.join(' ' in a and repr(a) or a for a in fullargs) ui.log("command", '%s\n', msg) d = lambda: util.checksignature(func)(ui, *args, **cmdoptions) - starttime = time.time() - ret = None try: - ret = runcommand(lui, repo, cmd, fullargs, ui, options, d, - cmdpats, cmdoptions) - return ret + return runcommand(lui, repo, cmd, fullargs, ui, options, d, + cmdpats, cmdoptions) finally: - duration = time.time() - starttime - ui.log("commandfinish", "%s exited %s after %0.2f seconds\n", - cmd, ret, duration) if repo and repo != req.repo: repo.close() diff --git a/tests/test-blackbox.t b/tests/test-blackbox.t --- a/tests/test-blackbox.t +++ b/tests/test-blackbox.t @@ -26,7 +26,7 @@ command, exit codes, and duration $ hg add a $ hg blackbox 1970/01/01 00:00:00 bob> add a - 1970/01/01 00:00:00 bob> add exited 0 after * seconds (glob) + 1970/01/01 00:00:00 bob> add a exited 0 after * seconds (glob) incoming change tracking @@ -58,7 +58,7 @@ clone, commit, pull $ hg blackbox -l 3 1970/01/01 00:00:00 bob> pull 1970/01/01 00:00:00 bob> 1 incoming changes - new heads: d02f48003e62 - 1970/01/01 00:00:00 bob> pull exited None after * seconds (glob) + 1970/01/01 00:00:00 bob> pull exited 0 after * seconds (glob) we must not cause a failure if we cannot write to the log @@ -118,7 +118,7 @@ backup bundles get logged $ hg blackbox -l 3 1970/01/01 00:00:00 bob> strip tip 1970/01/01 00:00:00 bob> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob) - 1970/01/01 00:00:00 bob> strip exited 0 after * seconds (glob) + 1970/01/01 00:00:00 bob> strip tip exited 0 after * seconds (glob) extension and python hooks - use the eol extension for a pythonhook @@ -133,7 +133,7 @@ extension and python hooks - use the eol 1970/01/01 00:00:00 bob> update 1970/01/01 00:00:00 bob> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob) 1970/01/01 00:00:00 bob> exthook-update: echo hooked finished in * seconds (glob) - 1970/01/01 00:00:00 bob> update exited False after * seconds (glob) + 1970/01/01 00:00:00 bob> update exited 0 after * seconds (glob) log rotation diff --git a/tests/test-progress.t b/tests/test-progress.t --- a/tests/test-progress.t +++ b/tests/test-progress.t @@ -167,7 +167,6 @@ test delay time estimates $ hg -y loop 8 \r (no-eol) (esc) - loop [====> ] 1/8 1m18s\r (no-eol) (esc) loop [=========> ] 2/8 1m07s\r (no-eol) (esc) loop [===============> ] 3/8 56s\r (no-eol) (esc) loop [=====================> ] 4/8 45s\r (no-eol) (esc) @@ -204,7 +203,6 @@ test delay time estimates Time estimates should not fail when there's no end point: $ hg -y loop -- -4 \r (no-eol) (esc) - loop [ <=> ] 1\r (no-eol) (esc) - loop [ <=> ] 2\r (no-eol) (esc) - loop [ <=> ] 3\r (no-eol) (esc) + loop [ <=> ] 2\r (no-eol) (esc) + loop [ <=> ] 3\r (no-eol) (esc) \r (no-eol) (esc)