[PATCH 1 of 1] blackblox extension to help with debugging

[Nicolas Dumazet]

# HG changeset patch
# User Nicolas Dumazet <nicdumz.commits at gmail.com>
# Date 1287388636 -32400
# Node ID 5f9627e140d751e8b8a5eee956f91da759ea2f0e
# Parent  df7c2f81afd534dd3f7b37ce6f584e0c5fc0b412
blackblox extension to help with debugging

diff --git a/hgext/blackbox.py b/hgext/blackbox.py
new file mode 100644
--- /dev/null
+++ b/hgext/blackbox.py
@@ -0,0 +1,79 @@
+"""log repository events to help debugging
+
+Appends to .hg/blackbox events happening in the repository to help
+debugging and diagnosis. So far, this blackbox will track:
+ - hg commands and their return codes
+ - tracebacks
+ - hooks
+ - incoming changesets
+"""
+
+from mercurial import dispatch, extensions, hook, util
+import os, traceback, sys
+
+def wrapui(ui, repo):
+    class blackboxui(ui.__class__):
+        @util.propertycache
+        def _blackbox(self):
+            introduction = not os.path.exists(repo.join('blackbox'))
+            blackbox = repo.opener('blackbox', 'a')
+            if introduction:
+                blackbox.write(
+"""
+blackbox extension logs here hg events to help diagnosing errors.
+You can truncate or delete this file, or include parts of the log
+in bug reports on http://mercurial.selenic.com/bts/
+
+""")
+            blackbox.write(util.datestr() + '\n')
+            return blackbox
+
+        def blackbox(self, msg):
+            self._blackbox.write(' %s\n' % msg)
+
+    ui.__class__ = blackboxui
+
+def runcommand(orig, lui, repo, cmd, fullargs, *args, **kwargs):
+    if repo is None:
+        # not much we can log
+        return orig(lui, repo, cmd, fullargs, *args, **kwargs)
+
+    wrapui(lui, repo)
+
+    lui.blackbox(' '.join(fullargs))
+    try:
+        ret = orig(lui, repo, cmd, fullargs, *args, **kwargs)
+        if ret:
+            lui._blackbox.write(' [%d]\n' % ret)
+        return ret
+    except:
+        lui._blackbox.write("** Python %s\n" % sys.version.replace('\n', ''))
+        lui._blackbox.write("** Mercurial Distributed SCM (version %s)\n"
+               % util.version())
+        lui._blackbox.write("** Extensions loaded: %s\n"
+               % ", ".join([x[0] for x in extensions.extensions()]))
+        traceback.print_exc(None, lui._blackbox)
+        raise
+
+def exthook(orig, ui, repo, name, cmd, *args, **kw):
+    if repo:
+        ui.blackbox('exthook: %s: %s' % (name, cmd))
+    return orig(ui, repo, name, cmd, *args, **kw)
+def pythonhook(orig, ui, repo, name, hname, funcname, *args, **kw):
+    if repo and not hname.endswith('.blackbox'):
+        ui.blackbox('pythonhook: %s: %s' % (hname, funcname))
+    return orig(ui, repo, name, hname, funcname, *args, **kw)
+
+def uisetup(ui):
+    extensions.wrapfunction(dispatch, 'runcommand', runcommand)
+    extensions.wrapfunction(hook, '_exthook', exthook)
+    extensions.wrapfunction(hook, '_pythonhook', pythonhook)
+
+def reposetup(ui, repo):
+    if not repo.local():
+        return
+
+    wrapui(ui, repo)
+    def incoming(ui, repo, hooktype, node, source, url):
+        ui.blackbox('incoming: %s: %s from %s' % (source, node[:12], url))
+    ui.setconfig('hooks', 'incoming.blackbox', incoming)
diff --git a/tests/test-blackbox.t b/tests/test-blackbox.t
new file mode 100644
--- /dev/null
+++ b/tests/test-blackbox.t
@@ -0,0 +1,100 @@
+  $ echo '[extensions]' >> $HGRCPATH
+  $ echo 'blackbox =' >> $HGRCPATH
+
+  $ blackbox() {
+  >   # trash the header
+  >   tail --lines=+6 .hg/blackbox
+  > }
+
+== Non-zero exit codes / header ==
+
+  $ hg init empty; cd empty
+  $ hg log
+  $ hg add empty
+  empty: No such file or directory
+  [1]
+  $ cat .hg/blackbox
+  
+  blackbox extension logs here hg events to help diagnosing errors.
+  You can truncate or delete this file, or include parts of the log
+  in bug reports on http://mercurial.selenic.com/bts/
+  
+  * (glob)
+   log
+  * (glob)
+   add empty
+   [1]
+
+== Logging hooks ==
+
+  $ rm .hg/blackbox
+  $ hg --config "hooks.pre-log.foo=echo 'hook'" log
+  hook
+  $ blackbox
+  * (glob)
+   log
+   exthook: pre-log.foo: echo 'hook'
+  $ cd ..
+
+== Incoming changesets ==
+
+Create a repo with a dummy changeset
+
+  $ hg init foo; cd foo
+  $ touch a
+  $ hg ci -Am'a'
+  adding a
+  $ hg clone . ../remote
+  updating to branch default
+  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
+
+And pretend we push to remote a new changeset
+
+  $ echo foo > a
+  $ hg ci -Am'modify a'
+  $ hg push ../remote
+  pushing to ../remote
+  searching for changes
+  adding changesets
+  adding manifests
+  adding file changes
+  added 1 changesets with 1 changes to 1 files
+
+And check that the incoming operation was recorded
+
+  $ cd ../remote
+  $ blackbox
+  * (glob)
+   incoming: push: c3cdbe7bbdc4 from file:$TESTTMP/foo
+
+== Tracebacks ==
+
+  $ rm .hg/blackbox
+  $ hg diff -c notexisting
+  abort: unknown revision 'notexisting'!
+  [255]
+  $ blackbox
+  * (glob)
+   diff -c notexisting
+  \*\* Python * (glob)
+  \*\* Mercurial Distributed SCM (version *) (glob)
+  ** Extensions loaded: blackbox
+  Traceback (most recent call last):
+    File "*/hgext/blackbox.py", line *, in runcommand (glob)
+      ret = orig(lui, repo, cmd, fullargs, *args, **kwargs)
+    File "*/mercurial/dispatch.py", line *, in runcommand (glob)
+      ret = _runcommand(ui, options, cmd, d)
+    File "*/mercurial/dispatch.py", line *, in _runcommand (glob)
+      return checkargs()
+    File "*/mercurial/dispatch.py", line *, in checkargs (glob)
+      return cmdfunc()
+    File "*/mercurial/dispatch.py", line *, in <lambda> (glob)
+      d = lambda: util.checksignature(func)(ui, *args, **cmdoptions)
+    File "*/mercurial/util.py", line *, in check (glob)
+      return func(*args, **kwargs)
+    File "*/mercurial/commands.py", line *, in diff (glob)
+      node2 = repo.lookup(change)
+    File "*/mercurial/localrepo.py", line *, in lookup (glob)
+      raise error.RepoLookupError(_("unknown revision '%s'") % key)
+  RepoLookupError: unknown revision 'notexisting'
+