Mercurial > hg
changeset 18670:ddc7268da176
blackbox: log the commands that are run
Uses ui.log to log which commands are run, their exit code, the time taken,
and any unhandled exceptions thrown.
Example log lines:
2013/02/09 08:35:19 durham> add foo
2013/02/09 08:35:19 durham> add exited 0 after 0.02 seconds
Updates the progress tests because they use a mocked time.time() which these
changes affect.
| author | Durham Goode <durham@fb.com> |
|---|---|
| date | Sat, 09 Feb 2013 09:04:14 -0800 |
| parents | 18242716a014 |
| children | 1c305128e5b9 |
| files | mercurial/dispatch.py tests/test-progress.t |
| diffstat | 2 files changed, 13 insertions(+), 4 deletions(-) [+] |
line wrap: on
line diff
--- a/mercurial/dispatch.py Tue Feb 12 14:08:33 2013 -0800 +++ b/mercurial/dispatch.py Sat Feb 09 09:04:14 2013 -0800 @@ -247,6 +247,7 @@ (_("** Mercurial Distributed SCM (version %s)\n") % myver) + (_("** Extensions loaded: %s\n") % ", ".join([x[0] for x in extensions.extensions()]))) + ui.log("commandexception", "%s\n%s\n", warning, traceback.format_exc()) ui.warn(warning) raise @@ -738,10 +739,16 @@ msg = ' '.join(' ' in a and repr(a) or a for a in fullargs) ui.log("command", msg + "\n") d = lambda: util.checksignature(func)(ui, *args, **cmdoptions) + starttime = time.time() + ret = None try: - return runcommand(lui, repo, cmd, fullargs, ui, options, d, - cmdpats, cmdoptions) + ret = runcommand(lui, repo, cmd, fullargs, ui, options, d, + cmdpats, cmdoptions) + return ret 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-progress.t Tue Feb 12 14:08:33 2013 -0800 +++ b/tests/test-progress.t Sat Feb 09 09:04:14 2013 -0800 @@ -167,6 +167,7 @@ $ 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) @@ -203,6 +204,7 @@ Time estimates should not fail when there's no end point: $ hg -y loop -- -4 \r (no-eol) (esc) - loop [ <=> ] 2\r (no-eol) (esc) - loop [ <=> ] 3\r (no-eol) (esc) + loop [ <=> ] 1\r (no-eol) (esc) + loop [ <=> ] 2\r (no-eol) (esc) + loop [ <=> ] 3\r (no-eol) (esc) \r (no-eol) (esc)