blackbox: log working directory version
Without this, while you could see the list of commands run,
it wasn't possible to identify what they were doing, because commads
could rely on revsets (including remote input which varies over time).
--- a/hgext/blackbox.py Mon Feb 08 03:37:26 2016 +0000
+++ b/hgext/blackbox.py Tue Feb 09 19:16:06 2016 +0000
@@ -35,6 +35,8 @@
import re
from mercurial.i18n import _
+from mercurial.node import hex
+
from mercurial import (
cmdutil,
util,
@@ -64,6 +66,12 @@
del filehandles[path]
fp.close()
+def hexfn(node):
+ if node is None:
+ return None
+ else:
+ return hex(node)
+
def wrapui(ui):
class blackboxui(ui.__class__):
@util.propertycache
@@ -131,17 +139,27 @@
user = util.getuser()
pid = str(util.getpid())
formattedmsg = msg[0] % msg[1:]
+ rev = '(unknown)'
+ if util.safehasattr(self, '_bbrepo'):
+ ctx = self._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]))
try:
- fp.write('%s %s (%s)> %s' %
- (date, user, pid, formattedmsg))
+ fp.write('%s %s @%s (%s)> %s' %
+ (date, user, rev, pid, formattedmsg))
fp.flush()
except IOError as err:
self.debug('warning: cannot write to blackbox.log: %s\n' %
err.strerror)
- lastfp = fp
+ if not lastfp or util.safehasattr(self, '_bbrepo'):
+ lastfp = fp
def setrepo(self, repo):
self._bbvfs = repo.vfs
+ self._bbrepo = repo
ui.__class__ = blackboxui
--- a/tests/test-blackbox.t Mon Feb 08 03:37:26 2016 +0000
+++ b/tests/test-blackbox.t Tue Feb 09 19:16:06 2016 +0000
@@ -12,10 +12,13 @@
$ echo a > a
$ hg add a
+ $ hg id > /dev/null
$ hg blackbox
- 1970/01/01 00:00:00 bob (5000)> add a
- 1970/01/01 00:00:00 bob (5000)> add a exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox
+ 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 exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox
incoming change tracking
@@ -45,12 +48,12 @@
added 1 changesets with 1 changes to 1 files
(run 'hg update' to get a working copy)
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> pull
- 1970/01/01 00:00:00 bob (5000)> updated served branch cache in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> wrote served branch cache with 1 labels and 2 nodes
- 1970/01/01 00:00:00 bob (5000)> 1 incoming changes - new heads: d02f48003e62
- 1970/01/01 00:00:00 bob (5000)> pull exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pull
+ 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)> blackbox -l 6
we must not cause a failure if we cannot write to the log
@@ -107,12 +110,12 @@
0 files updated, 0 files merged, 1 files removed, 0 files unresolved
saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob)
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> strip tip
- 1970/01/01 00:00:00 bob (5000)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/73f6ee326b27-7612e004-backup.hg (glob)
- 1970/01/01 00:00:00 bob (5000)> updated base branch cache in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> wrote base branch cache with 1 labels and 2 nodes
- 1970/01/01 00:00:00 bob (5000)> strip tip exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @73f6ee326b27d820b0472f1a825e3a50f3dc489b (5000)> strip tip
+ 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)> blackbox -l 6
extension and python hooks - use the eol extension for a pythonhook
@@ -125,12 +128,12 @@
1 files updated, 0 files merged, 0 files removed, 0 files unresolved
1 other heads for branch "default"
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> update
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 0 tags
- 1970/01/01 00:00:00 bob (5000)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> exthook-update: echo hooked finished in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> update exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> update
+ 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)> blackbox -l 6
log rotation
@@ -151,7 +154,7 @@
$ hg init blackboxtest3
$ cd blackboxtest3
$ hg blackbox
- 1970/01/01 00:00:00 bob (5000)> blackbox
+ 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox
$ mv .hg/blackbox.log .hg/blackbox.log-
$ mkdir .hg/blackbox.log
$ sed -e 's/\(.*test1.*\)/#\1/; s#\(.*commit2.*\)#os.rmdir(".hg/blackbox.log")\nos.rename(".hg/blackbox.log-", ".hg/blackbox.log")\n\1#' $TESTDIR/test-dispatch.py > ../test-dispatch.py
@@ -178,9 +181,9 @@
result: None
$ hg blackbox
- 1970/01/01 00:00:00 bob (5000)> blackbox
- 1970/01/01 00:00:00 bob (5000)> blackbox exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> 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 @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> blackbox
cleanup
$ cd ..
--- a/tests/test-obsolete-tag-cache.t Mon Feb 08 03:37:26 2016 +0000
+++ b/tests/test-obsolete-tag-cache.t Tue Feb 09 19:16:06 2016 +0000
@@ -68,11 +68,11 @@
55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
$ hg blackbox -l 5
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> 2/2 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 2 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 5
+ 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)> blackbox -l 5
Hiding another changeset should cause the filtered hash to change
@@ -88,11 +88,11 @@
042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
$ hg blackbox -l 5
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> 1/1 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 5
+ 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)> blackbox -l 5
Resolving tags on an unfiltered repo writes a separate tags cache
@@ -109,8 +109,8 @@
d75775ffbc6bca1794d300f5571272879bd280da test2
$ hg blackbox -l 5
- 1970/01/01 00:00:00 bob (5000)> --hidden tags
- 1970/01/01 00:00:00 bob (5000)> 2/2 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2 with 3 tags
- 1970/01/01 00:00:00 bob (5000)> --hidden tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 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)> blackbox -l 5
--- a/tests/test-tags.t Mon Feb 08 03:37:26 2016 +0000
+++ b/tests/test-tags.t Tue Feb 09 19:16:06 2016 +0000
@@ -137,12 +137,12 @@
$ hg identify
b9154636be93 tip
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> identify
- 1970/01/01 00:00:00 bob (5000)> writing 48 bytes to cache/hgtagsfnodes1
- 1970/01/01 00:00:00 bob (5000)> 0/1 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> identify exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
+ 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)> blackbox -l 6
Failure to acquire lock results in no write
@@ -151,12 +151,12 @@
$ hg identify
b9154636be93 tip
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> identify
- 1970/01/01 00:00:00 bob (5000)> not writing .hg/cache/hgtagsfnodes1 because lock cannot be acquired
- 1970/01/01 00:00:00 bob (5000)> 0/1 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> identify exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
+ 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)> blackbox -l 6
$ fnodescacheexists
no fnodes cache
@@ -351,12 +351,12 @@
bar 1:78391a272241
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> writing 24 bytes to cache/hgtagsfnodes1
- 1970/01/01 00:00:00 bob (5000)> 2/3 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags
+ 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)> blackbox -l 6
#if unix-permissions no-root
Errors writing to .hgtags fnodes cache are silently ignored
@@ -372,12 +372,12 @@
bar 1:78391a272241
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> couldn't write cache/hgtagsfnodes1: [Errno 13] Permission denied: '$TESTTMP/t2/.hg/cache/hgtagsfnodes1' (glob)
- 1970/01/01 00:00:00 bob (5000)> 2/3 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
+ 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)> blackbox -l 6
$ chmod a+w .hg/cache/hgtagsfnodes1
@@ -387,12 +387,12 @@
bar 1:78391a272241
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> writing 24 bytes to cache/hgtagsfnodes1
- 1970/01/01 00:00:00 bob (5000)> 2/3 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
+ 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)> blackbox -l 6
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=168
@@ -416,11 +416,11 @@
bar 1:78391a272241
$ hg blackbox -l 5
- 1970/01/01 00:00:00 bob (5000)> writing 24 bytes to cache/hgtagsfnodes1
- 1970/01/01 00:00:00 bob (5000)> 2/3 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 5
+ 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)> blackbox -l 5
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=120
@@ -433,12 +433,12 @@
bar 1:78391a272241
$ hg blackbox -l 6
- 1970/01/01 00:00:00 bob (5000)> tags
- 1970/01/01 00:00:00 bob (5000)> writing 24 bytes to cache/hgtagsfnodes1
- 1970/01/01 00:00:00 bob (5000)> 2/3 cache hits/lookups in * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> writing .hg/cache/tags2-visible with 1 tags
- 1970/01/01 00:00:00 bob (5000)> tags exited 0 after * seconds (glob)
- 1970/01/01 00:00:00 bob (5000)> blackbox -l 6
+ 1970/01/01 00:00:00 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags
+ 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)> blackbox -l 6
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=144