# HG changeset patch
# User timeless <timeless@mozdev.org>
# Date 1454519104 0
# Node ID d2c0527af3646e0dd5c971d094ac81f57815f3dd
# Parent  b862e793ec109ad23dc8becc213fa81eda901712
blackbox: store the blackbox ui object instead of the log file

Without this, the last logged entry didn't have access to
the repository, and thus couldn't report its version
(and especially that an add or similar dirtied it).

A side-effect is that one repo leaks until process exit...

diff -r b862e793ec10 -r d2c0527af364 hgext/blackbox.py
--- a/hgext/blackbox.py	Tue Feb 09 15:44:13 2016 +0000
+++ b/hgext/blackbox.py	Wed Feb 03 17:05:04 2016 +0000
@@ -54,7 +54,7 @@
 # be specifying the version(s) of Mercurial they are tested with, or
 # leave the attribute unspecified.
 testedwith = 'internal'
-lastfp = None
+lastui = None
 
 filehandles = {}
 
@@ -115,15 +115,19 @@
                     fp = _openlog(self._bbvfs)
             return fp
 
+        def _bbwrite(self, fmt, *args):
+            self._bbfp.write(fmt % args)
+            self._bbfp.flush()
+
         def log(self, event, *msg, **opts):
-            global lastfp
+            global lastui
             super(blackboxui, self).log(event, *msg, **opts)
 
             if not '*' in self.track and not event in self.track:
                 return
 
-            if util.safehasattr(self, '_blackbox'):
-                fp = self._blackbox
+            if util.safehasattr(self, '_bbfp'):
+                ui = self
             elif util.safehasattr(self, '_bbvfs'):
                 try:
                     self._bbfp = self._openlogfile()
@@ -132,41 +136,41 @@
                                err.strerror)
                     del self._bbvfs
                     self._bbfp = None
-                fp = self._bbfp
+                ui = self
             else:
                 # certain ui instances exist outside the context of
                 # a repo, so just default to the last blackbox that
                 # was seen.
-                fp = lastfp
+                ui = lastui
 
-            if fp:
+            if (util.safehasattr(ui, '_bbfp') and
+                ui._bbfp is not None):
                 date = util.datestr(None, '%Y/%m/%d %H:%M:%S')
                 user = util.getuser()
                 pid = str(util.getpid())
                 formattedmsg = msg[0] % msg[1:]
                 rev = '(unknown)'
                 changed = ''
-                if util.safehasattr(self, '_bbrepo'):
-                    ctx = self._bbrepo[None]
+                if util.safehasattr(ui, '_bbrepo'):
+                    ctx = ui._bbrepo[None]
                     if ctx.rev() is not None:
                         rev = hexfn(ctx.node())
                     else:
                         parents = ctx.parents()
                         rev = ('+'.join([hexfn(p.node()) for p in parents]))
-                        if (self.configbool('blackbox', 'dirty', False) and (
-                            any(self._bbrepo.status()) or
+                        if (ui.configbool('blackbox', 'dirty', False) and (
+                            any(ui._bbrepo.status()) or
                             any(ctx.sub(s).dirty() for s in ctx.substate)
                         )):
                             changed = '+'
                 try:
-                    fp.write('%s %s @%s%s (%s)> %s' %
-                        (date, user, rev, changed, pid, formattedmsg))
-                    fp.flush()
+                    ui._bbwrite('%s %s @%s%s (%s)> %s',
+                        date, user, rev, changed, pid, formattedmsg)
                 except IOError as err:
                     self.debug('warning: cannot write to blackbox.log: %s\n' %
                                err.strerror)
-                if not lastfp or util.safehasattr(self, '_bbrepo'):
-                    lastfp = fp
+                if not lastui or util.safehasattr(ui, '_bbrepo'):
+                    lastui = ui
 
         def setrepo(self, repo):
             self._bbvfs = repo.vfs
diff -r b862e793ec10 -r d2c0527af364 tests/test-blackbox.t
--- a/tests/test-blackbox.t	Tue Feb 09 15:44:13 2016 +0000
+++ b/tests/test-blackbox.t	Wed Feb 03 17:05:04 2016 +0000
@@ -12,12 +12,9 @@
 
   $ echo a > a
   $ hg add a
-  $ hg id --config blackbox.dirty=True > /dev/null
   $ hg blackbox --config blackbox.dirty=True
   1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a
-  1970/01/01 00:00:00 bob @(unknown) (5000)> add a exited 0 after * seconds (glob)
-  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> id
-  1970/01/01 00:00:00 bob @(unknown) (5000)> id --config blackbox.dirty=True exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> blackbox
 
 incoming change tracking
@@ -52,7 +49,7 @@
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated served branch cache in * seconds (glob)
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote served branch cache with 1 labels and 2 nodes
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> 1 incoming changes - new heads: d02f48003e62
-  1970/01/01 00:00:00 bob @(unknown) (5000)> pull exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pull exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
 
 we must not cause a failure if we cannot write to the log
@@ -114,7 +111,7 @@
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/73f6ee326b27-7612e004-backup.hg
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated base branch cache in * seconds (glob)
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote base branch cache with 1 labels and 2 nodes
-  1970/01/01 00:00:00 bob @(unknown) (5000)> strip tip exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> strip tip exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
 
 extension and python hooks - use the eol extension for a pythonhook
@@ -132,7 +129,7 @@
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> writing .hg/cache/tags2-visible with 0 tags
   1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
   1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> exthook-update: echo hooked finished in * seconds (glob)
-  1970/01/01 00:00:00 bob @(unknown) (5000)> update exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> update exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> blackbox -l 6
 
 log rotation
@@ -182,7 +179,7 @@
   result: None
   $ hg blackbox
   1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox
-  1970/01/01 00:00:00 bob @(unknown) (5000)> blackbox exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> blackbox
 
 cleanup
diff -r b862e793ec10 -r d2c0527af364 tests/test-obsolete-tag-cache.t
--- a/tests/test-obsolete-tag-cache.t	Tue Feb 09 15:44:13 2016 +0000
+++ b/tests/test-obsolete-tag-cache.t	Wed Feb 03 17:05:04 2016 +0000
@@ -71,7 +71,7 @@
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 2 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
 
 Hiding another changeset should cause the filtered hash to change
@@ -91,7 +91,7 @@
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 1/1 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
 
 Resolving tags on an unfiltered repo writes a separate tags cache
@@ -112,5 +112,5 @@
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2 with 3 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> --hidden tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
diff -r b862e793ec10 -r d2c0527af364 tests/test-tags.t
--- a/tests/test-tags.t	Tue Feb 09 15:44:13 2016 +0000
+++ b/tests/test-tags.t	Wed Feb 03 17:05:04 2016 +0000
@@ -141,7 +141,7 @@
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing 48 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/1 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> identify exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
 
 Failure to acquire lock results in no write
@@ -155,7 +155,7 @@
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> not writing .hg/cache/hgtagsfnodes1 because lock cannot be acquired
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/1 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> identify exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
 
   $ fnodescacheexists
@@ -218,7 +218,7 @@
   (branch merge, don't forget to commit)
   $ hg blackbox -l3
   1970/01/01 00:00:00 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28 (5000)> merge 1
-  1970/01/01 00:00:00 bob @(unknown) (5000)> merge 1 exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> merge 1 exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l3
   $ hg id
   c8edf04160c7+b9154636be93+ tip
@@ -359,7 +359,7 @@
   1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> 2/3 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> blackbox -l 6
 
 #if unix-permissions no-root
@@ -380,7 +380,7 @@
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> couldn't write cache/hgtagsfnodes1: [Errno 13] Permission denied: '$TESTTMP/t2/.hg/cache/hgtagsfnodes1'
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/3 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
 
   $ chmod a+w .hg/cache/hgtagsfnodes1
@@ -395,7 +395,7 @@
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/3 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
 
   $ f --size .hg/cache/hgtagsfnodes1
@@ -423,7 +423,7 @@
   1970/01/01 00:00:00 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> 2/3 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> blackbox -l 5
 
   $ f --size .hg/cache/hgtagsfnodes1
@@ -441,7 +441,7 @@
   1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> 2/3 cache hits/lookups in * seconds (glob)
   1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00 bob @(unknown) (5000)> tags exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> blackbox -l 6
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144