changeset 2379:3593442d4a0e

obshashrange: adds blackbox usage in tests This will help track the validation of the cache.
author Pierre-Yves David <pierre-yves.david@octobus.net>
date Tue, 16 May 2017 15:20:53 +0200
parents c143d465c4b8
children 694494619795
files hgext3rd/evolve/obscache.py tests/test-discovery-obshashrange.t
diffstat 2 files changed, 229 insertions(+), 1 deletions(-) [+]
line wrap: on
line diff
--- a/hgext3rd/evolve/obscache.py	Tue May 16 12:45:08 2017 +0200
+++ b/hgext3rd/evolve/obscache.py	Tue May 16 15:20:53 2017 +0200
@@ -452,7 +452,7 @@
         # will be about as fast...
         if not obscache.uptodate(repo):
             if repo.currenttransaction() is None:
-                repo.ui.log('evoext-obscache',
+                repo.ui.log('evoext-cache',
                             'obscache is out of date, '
                             'falling back to slower obsstore version\n')
                 repo.ui.debug('obscache is out of date')
--- a/tests/test-discovery-obshashrange.t	Tue May 16 12:45:08 2017 +0200
+++ b/tests/test-discovery-obshashrange.t	Tue May 16 15:20:53 2017 +0200
@@ -6,6 +6,9 @@
   $ cat << EOF >> $HGRCPATH
   > [extensions]
   > hgext3rd.evolve =
+  > blackbox =
+  > [defaults]
+  > blackbox = -l 100
   > [experimental]
   > obshashrange=1
   > verbose-obsolescence-exchange=1
@@ -27,6 +30,29 @@
   0 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ cd server
   $ hg debugbuilddag '.+7'
+  $ hg blackbox
+  * @0000000000000000000000000000000000000000 (*)> serve --stdio (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R server serve --stdio exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugbuilddag .+7 (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugbuilddag .+7 exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg log -G
   o  7 4de32a90b66c r7 tip
   |
@@ -57,6 +83,45 @@
   dddddddddddddddddddddddddddddddddddddddd c8d03c1b5e94af74b772900c58259d2e08917735 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee 4de32a90b66cd083ebf3c00b41277aa7abca51dd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
 
+  $ hg blackbox
+  * @0000000000000000000000000000000000000000 (*)> log -G (glob)
+  * @0000000000000000000000000000000000000000 (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
+  * @0000000000000000000000000000000000000000 (*)> log -G exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' (glob)
+  * @0000000000000000000000000000000000000000 (*)> writing .hg/cache/tags2 with 0 tags (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa 66f7d451a68b85ed82ff5fcc254daf50c74144bd (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa 66f7d451a68b85ed82ff5fcc254daf50c74144bd exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r2)' (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r2)' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete cccccccccccccccccccccccccccccccccccccccc bebd167eb94d257ace0e814aeb98e6972ed2970d (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete cccccccccccccccccccccccccccccccccccccccc bebd167eb94d257ace0e814aeb98e6972ed2970d exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r5)' (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r5)' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete dddddddddddddddddddddddddddddddddddddddd c8d03c1b5e94af74b772900c58259d2e08917735 (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete dddddddddddddddddddddddddddddddddddddddd c8d03c1b5e94af74b772900c58259d2e08917735 exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r7)' (glob)
+  * @0000000000000000000000000000000000000000 (*)> log --hidden --template '{node}\n' --rev 'desc(r7)' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee 4de32a90b66cd083ebf3c00b41277aa7abca51dd (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee 4de32a90b66cd083ebf3c00b41277aa7abca51dd exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobshashrange --subranges --rev tip
            rev         node        index         size        depth      obshash
              7 4de32a90b66c            0            8            8 38d1e7ad86ea
@@ -88,10 +153,29 @@
   added 5 changesets with 0 changes to 0 files
   3 new obsolescence markers
   (run 'hg update' to get a working copy)
+  $ hg -R ../server blackbox
+  * @0000000000000000000000000000000000000000 (*)> debugobshashrange --subranges --rev tip (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobshashrange --subranges --rev tip exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> serve --stdio (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R server serve --stdio exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm ../server/.hg/blackbox.log
   $ hg -R ../server/ debugobsolete --rev ::4 | sort
   aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   cccccccccccccccccccccccccccccccccccccccc bebd167eb94d257ace0e814aeb98e6972ed2970d 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
+  $ rm ../server/.hg/blackbox.log
+  $ hg blackbox
+  * @0000000000000000000000000000000000000000 (*)> pull --rev 4 (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> 5 incoming changes - new heads: bebd167eb94d (glob)
+  * @0000000000000000000000000000000000000000 (*)> pull --rev 4 exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobsolete | sort
   aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
@@ -117,6 +201,18 @@
   remote: adding file changes
   remote: added 1 changesets with 1 changes to 1 files (+1 heads)
   remote: 1 new obsolescence markers
+  $ hg -R ../server blackbox
+  * @0000000000000000000000000000000000000000 (*)> serve --stdio (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> 1 incoming changes - new heads: 45f8b879de92 (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R server serve --stdio exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm ../server/.hg/blackbox.log
 
 testing push with extra local markers
 =====================================
@@ -145,6 +241,15 @@
   no changes found
   remote: 2 new obsolescence markers
   [1]
+  $ hg -R ../server blackbox
+  * @0000000000000000000000000000000000000000 (*)> serve --stdio (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R server serve --stdio exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm ../server/.hg/blackbox.log
   $ hg -R ../server/ debugobsolete --rev ::tip | sort
   111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
@@ -152,6 +257,45 @@
   bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   cccccccccccccccccccccccccccccccccccccccc bebd167eb94d257ace0e814aeb98e6972ed2970d 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   ffffffffffffffffffffffffffffffffffffffff 45f8b879de922f6a6e620ba04205730335b6fc7e 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
+  $ hg blackbox
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> up (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> up exited 0 after *.?? seconds (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> add foo (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> add foo exited 0 after *.?? seconds (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> commit -m foo (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> updated served branch cache in *.???? seconds (glob)
+  * @bebd167eb94d257ace0e814aeb98e6972ed2970d (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> commit -m foo exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev . (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev . exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete ffffffffffffffffffffffffffffffffffffffff 45f8b879de922f6a6e620ba04205730335b6fc7e (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete ffffffffffffffffffffffffffffffffffffffff 45f8b879de922f6a6e620ba04205730335b6fc7e exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log -G (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log -G exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> writing .hg/cache/tags2 with 0 tags (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete 111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete 111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r3)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r3)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete 22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete 22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push exited 1 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobsolete | sort
   111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
@@ -190,6 +334,22 @@
   3 new obsolescence markers
   (run 'hg heads' to see heads, 'hg merge' to merge)
 
+  $ hg -R ../server blackbox
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete --rev '::tip' (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R ../server/ debugobsolete --rev '::tip' exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete aaaaaaa11111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R ../server debugobsolete aaaaaaa11111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> debugobsolete bbbbbbb2222222222bbbbbbbbbbbbb2222222222 bebd167eb94d257ace0e814aeb98e6972ed2970d (glob)
+  * @0000000000000000000000000000000000000000 (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R ../server debugobsolete bbbbbbb2222222222bbbbbbbbbbbbb2222222222 bebd167eb94d257ace0e814aeb98e6972ed2970d exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> serve --stdio (glob)
+  * @0000000000000000000000000000000000000000 (*)> -R server serve --stdio exited 0 after *.?? seconds (glob)
+  * @0000000000000000000000000000000000000000 (*)> blackbox (glob)
+  $ rm ../server/.hg/blackbox.log
   $ hg -R ../server/ debugobsolete --rev '::6' | sort
   111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
@@ -199,6 +359,23 @@
   bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb 01241442b3c2bf3211e593b549c655ea65b295e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   cccccccccccccccccccccccccccccccccccccccc bebd167eb94d257ace0e814aeb98e6972ed2970d 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   dddddddddddddddddddddddddddddddddddddddd c8d03c1b5e94af74b772900c58259d2e08917735 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
+  $ hg blackbox
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log -G (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log -G exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r 6 (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated served branch cache in *.???? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 2 incoming changes - new heads: f69452c5b1af (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r 6 exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobsolete --rev '::6' | sort
   111111111111111aaaaaaaaa1111111111111111 66f7d451a68b85ed82ff5fcc254daf50c74144bd 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
   22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 0 (Thu Jan 01 00:00:00 1970 +0000) {'user': 'test'}
@@ -241,6 +418,24 @@
   OBSEXC: looking for common markers in 7 nodes
   OBSEXC: request obsmarkers for 2 common nodes
   2 new obsolescence markers
+  $ hg blackbox
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete --rev '::6' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> alias 'debugobsolete' expands to 'debugobsolete -d '0 0'' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete --rev '::6' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> writing .hg/cache/tags2 with 0 tags (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r1)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r3)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r3)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r6)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r6)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r f69452c5b1af6cbaaa56ef50cf94fff5bcc6ca23 (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r f69452c5b1af6cbaaa56ef50cf94fff5bcc6ca23 exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobshashrange --subranges --rev 'heads(all())'
            rev         node        index         size        depth      obshash
              7 f69452c5b1af            0            7            7 000000000000
@@ -270,6 +465,17 @@
   OBSEXC: looking for common markers in 5 nodes
   OBSEXC: request obsmarkers for 1 common nodes
   1 new obsolescence markers
+  $ hg blackbox
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(foo)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(foo)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r bebd167eb94d257ace0e814aeb98e6972ed2970d (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r bebd167eb94d257ace0e814aeb98e6972ed2970d exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobshashrange --subranges --rev 'heads(all())'
            rev         node        index         size        depth      obshash
              7 f69452c5b1af            0            7            7 000000000000
@@ -303,6 +509,20 @@
   (run 'hg update' to get a working copy)
   $ hg rollback
   repository tip rolled back to revision 7 (undo pull)
+  $ hg blackbox
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated served branch cache in *.???? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 1 incoming changes - new heads: 4de32a90b66c (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> rollback (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated base branch cache in *.???? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> wrote base branch cache with 1 labels and 2 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> rollback exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobshashrange --subranges --rev 'heads(all())'
            rev         node        index         size        depth      obshash
              7 f69452c5b1af            0            7            7 000000000000
@@ -331,6 +551,14 @@
   added 1 changesets with 0 changes to 0 files
   1 new obsolescence markers
   (run 'hg update' to get a working copy)
+  $ hg blackbox
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 1 incoming changes - new heads: 4de32a90b66c (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull exited 0 after *.?? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
+  $ rm .hg/blackbox.log
   $ hg debugobshashrange --subranges --rev 'heads(all())'
            rev         node        index         size        depth      obshash
              8 4de32a90b66c            0            8            8 c7f1f7e9925b