blackbox: fix recording exit codes (issue3938)
Previously the blackbox wrapped runcommand, but this failed to see the error
codes that were created if an exception occurred. I moved that logging to now
wrap _runcatch, so it can observe and log the actual error code (such as when
a user ctrl+c's during a command).
Updated the tests as well. Tested the change by running all the tests with the
blackbox extension enabled and verifying nothing broke (aside from things that
printed what extensions were enabeld).
The progress tests are affected by calls to time.time() so they needed to be
updated to pass.
--- a/mercurial/dispatch.py Tue May 21 15:31:56 2013 -0500
+++ b/mercurial/dispatch.py Wed May 22 17:31:47 2013 -0700
@@ -62,7 +62,16 @@
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 @@
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()
--- a/tests/test-blackbox.t Tue May 21 15:31:56 2013 -0500
+++ b/tests/test-blackbox.t Wed May 22 17:31:47 2013 -0700
@@ -26,7 +26,7 @@
$ 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 @@
$ 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 @@
$ 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 @@
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
--- a/tests/test-progress.t Tue May 21 15:31:56 2013 -0500
+++ b/tests/test-progress.t Wed May 22 17:31:47 2013 -0700
@@ -167,7 +167,6 @@
$ 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 @@
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)