discovery: log discovery result in non-trivial cases

We log the discovery summary, the number of roundtrips and the elapsed time.
This is useful to understand where slow push might come from when lloking at
the blackbox.

mercurial/setdiscovery.py

@@ -1,253 +1,256 b''
 # setdiscovery.py - improved discovery of common nodeset for mercurial
 #
 # Copyright 2010 Benoit Boissinot <[e-mail]>
 # and Peter Arrenbrecht <[e-mail]>
 #
 # This software may be used and distributed according to the terms of the
 # GNU General Public License version 2 or any later version.
 """
 Algorithm works in the following way. You have two repository: local and
 remote. They both contains a DAG of changelists.
 
 The goal of the discovery protocol is to find one set of node *common*,
 the set of nodes shared by local and remote.
 
 One of the issue with the original protocol was latency, it could
 potentially require lots of roundtrips to discover that the local repo was a
 subset of remote (which is a very common case, you usually have few changes
 compared to upstream, while upstream probably had lots of development).
 
 The new protocol only requires one interface for the remote repo: `known()`,
 which given a set of changelists tells you if they are present in the DAG.
 
 The algorithm then works as follow:
 
  - We will be using three sets, `common`, `missing`, `unknown`. Originally
  all nodes are in `unknown`.
  - Take a sample from `unknown`, call `remote.known(sample)`
    - For each node that remote knows, move it and all its ancestors to `common`
    - For each node that remote doesn't know, move it and all its descendants
    to `missing`
  - Iterate until `unknown` is empty
 
 There are a couple optimizations, first is instead of starting with a random
 sample of missing, start by sending all heads, in the case where the local
 repo is a subset, you computed the answer in one round trip.
 
 Then you can do something similar to the bisecting strategy used when
 finding faulty changesets. Instead of random samples, you can try picking
 nodes that will maximize the number of nodes that will be
 classified with it (since all ancestors or descendants will be marked as well).
 """
 
 from __future__ import absolute_import
 
 import collections
 import random
 
 from .i18n import _
 from .node import (
     nullid,
     nullrev,
 )
 from . import (
     dagutil,
     error,
     util,
 )
 
 def _updatesample(dag, nodes, sample, quicksamplesize=0):
     """update an existing sample to match the expected size
 
     The sample is updated with nodes exponentially distant from each head of the
     <nodes> set. (H~1, H~2, H~4, H~8, etc).
 
     If a target size is specified, the sampling will stop once this size is
     reached. Otherwise sampling will happen until roots of the <nodes> set are
     reached.
 
     :dag: a dag object from dagutil
     :nodes:  set of nodes we want to discover (if None, assume the whole dag)
     :sample: a sample to update
     :quicksamplesize: optional target size of the sample"""
     # if nodes is empty we scan the entire graph
     if nodes:
         heads = dag.headsetofconnecteds(nodes)
     else:
         heads = dag.heads()
     dist = {}
     visit = collections.deque(heads)
     seen = set()
     factor = 1
     while visit:
         curr = visit.popleft()
         if curr in seen:
             continue
         d = dist.setdefault(curr, 1)
         if d > factor:
             factor *= 2
         if d == factor:
             sample.add(curr)
             if quicksamplesize and (len(sample) >= quicksamplesize):
                 return
         seen.add(curr)
         for p in dag.parents(curr):
             if not nodes or p in nodes:
                 dist.setdefault(p, d + 1)
                 visit.append(p)
 
 def _takequicksample(dag, nodes, size):
     """takes a quick sample of size <size>
 
     It is meant for initial sampling and focuses on querying heads and close
     ancestors of heads.
 
     :dag: a dag object
     :nodes: set of nodes to discover
     :size: the maximum size of the sample"""
     sample = dag.headsetofconnecteds(nodes)
     if size <= len(sample):
         return _limitsample(sample, size)
     _updatesample(dag, None, sample, quicksamplesize=size)
     return sample
 
 def _takefullsample(dag, nodes, size):
     sample = dag.headsetofconnecteds(nodes)
     # update from heads
     _updatesample(dag, nodes, sample)
     # update from roots
     _updatesample(dag.inverse(), nodes, sample)
     assert sample
     sample = _limitsample(sample, size)
     if len(sample) < size:
         more = size - len(sample)
         sample.update(random.sample(list(nodes - sample), more))
     return sample
 
 def _limitsample(sample, desiredlen):
     """return a random subset of sample of at most desiredlen item"""
     if len(sample) > desiredlen:
         sample = set(random.sample(sample, desiredlen))
     return sample
 
 def findcommonheads(ui, local, remote,
                     initialsamplesize=100,
                     fullsamplesize=200,
                     abortwhenunrelated=True):
     '''Return a tuple (common, anyincoming, remoteheads) used to identify
     missing nodes from or in remote.
     '''
     start = util.timer()
 
     roundtrips = 0
     cl = local.changelog
     dag = dagutil.revlogdag(cl)
 
     # early exit if we know all the specified remote heads already
     ui.debug("query 1; heads\n")
     roundtrips += 1
     ownheads = dag.heads()
     sample = _limitsample(ownheads, initialsamplesize)
     # indices between sample and externalized version must match
     sample = list(sample)
     batch = remote.iterbatch()
     batch.heads()
     batch.known(dag.externalizeall(sample))
     batch.submit()
     srvheadhashes, yesno = batch.results()
 
     if cl.tip() == nullid:
         if srvheadhashes != [nullid]:
             return [nullid], True, srvheadhashes
         return [nullid], False, []
 
     # start actual discovery (we note this before the next "if" for
     # compatibility reasons)
     ui.status(_("searching for changes\n"))
 
     srvheads = dag.internalizeall(srvheadhashes, filterunknown=True)
     if len(srvheads) == len(srvheadhashes):
         ui.debug("all remote heads known locally\n")
         return (srvheadhashes, False, srvheadhashes,)
 
     if sample and len(ownheads) <= initialsamplesize and all(yesno):
         ui.note(_("all local heads known remotely\n"))
         ownheadhashes = dag.externalizeall(ownheads)
         return (ownheadhashes, True, srvheadhashes,)
 
     # full blown discovery
 
     # own nodes I know we both know
     # treat remote heads (and maybe own heads) as a first implicit sample
     # response
     common = cl.incrementalmissingrevs(srvheads)
     commoninsample = set(n for i, n in enumerate(sample) if yesno[i])
     common.addbases(commoninsample)
     # own nodes where I don't know if remote knows them
     undecided = set(common.missingancestors(ownheads))
     # own nodes I know remote lacks
     missing = set()
 
     full = False
     while undecided:
 
         if sample:
             missinginsample = [n for i, n in enumerate(sample) if not yesno[i]]
             missing.update(dag.descendantset(missinginsample, missing))
 
             undecided.difference_update(missing)
 
         if not undecided:
             break
 
         if full or common.hasbases():
             if full:
                 ui.note(_("sampling from both directions\n"))
             else:
                 ui.debug("taking initial sample\n")
             samplefunc = _takefullsample
             targetsize = fullsamplesize
         else:
             # use even cheaper initial sample
             ui.debug("taking quick initial sample\n")
             samplefunc = _takequicksample
             targetsize = initialsamplesize
         if len(undecided) < targetsize:
             sample = list(undecided)
         else:
             sample = samplefunc(dag, undecided, targetsize)
             sample = _limitsample(sample, targetsize)
 
         roundtrips += 1
         ui.progress(_('searching'), roundtrips, unit=_('queries'))
         ui.debug("query %i; still undecided: %i, sample size is: %i\n"
                  % (roundtrips, len(undecided), len(sample)))
         # indices between sample and externalized version must match
         sample = list(sample)
         yesno = remote.known(dag.externalizeall(sample))
         full = True
 
         if sample:
             commoninsample = set(n for i, n in enumerate(sample) if yesno[i])
             common.addbases(commoninsample)
             common.removeancestorsfrom(undecided)
 
     # heads(common) == heads(common.bases) since common represents common.bases
     # and all its ancestors
     result = dag.headsetofconnecteds(common.bases)
     # common.bases can include nullrev, but our contract requires us to not
     # return any heads in that case, so discard that
     result.discard(nullrev)
     elapsed = util.timer() - start
     ui.progress(_('searching'), None)
     ui.debug("%d total queries in %.4fs\n" % (roundtrips, elapsed))
+    msg = 'found %d common and %d missing heads, %d roundtrips in %.4fs\n'
+    ui.log('discovery', msg, len(result), len(srvheadhashes), roundtrips,
+           elapsed)
 
     if not result and srvheadhashes != [nullid]:
         if abortwhenunrelated:
             raise error.Abort(_("repository is unrelated"))
         else:
             ui.warn(_("warning: repository is unrelated\n"))
         return ({nullid}, True, srvheadhashes,)
 
     anyincoming = (srvheadhashes != [nullid])
     return dag.externalizeall(result), anyincoming, srvheadhashes

tests/test-setdiscovery.t

@@ -1,405 +1,410 b''
 
 Function to test discovery between two repos in both directions, using both the local shortcut
 (which is currently not activated by default) and the full remotable protocol:
 
   $ testdesc() { # revs_a, revs_b, dagdesc
   >     if [ -d foo ]; then rm -rf foo; fi
   >     hg init foo
   >     cd foo
   >     hg debugbuilddag "$3"
   >     hg clone . a $1 --quiet
   >     hg clone . b $2 --quiet
   >     echo
   >     echo "% -- a -> b tree"
   >     hg -R a debugdiscovery b --verbose --old
   >     echo
   >     echo "% -- a -> b set"
   >     hg -R a debugdiscovery b --verbose --debug --config progress.debug=true
   >     echo
   >     echo "% -- b -> a tree"
   >     hg -R b debugdiscovery a --verbose --old --config
   >     echo
   >     echo "% -- b -> a set"
   >     hg -R b debugdiscovery a --verbose --debug --config progress.debug=true
   >     cd ..
   > }
 
 
 Small superset:
 
   $ testdesc '-ra1 -ra2' '-rb1 -rb2 -rb3' '
   > +2:f +1:a1:b1
   > <f +4 :a2
   > +5 :b2
   > <f +3 :b3'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: 01241442b3c2 66f7d451a68b b5714e113bc0
   common heads: 01241442b3c2 b5714e113bc0
   local is subset
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   all local heads known remotely
   common heads: 01241442b3c2 b5714e113bc0
   local is subset
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 01241442b3c2 b5714e113bc0
   common heads: 01241442b3c2 b5714e113bc0
   remote is subset
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   all remote heads known locally
   common heads: 01241442b3c2 b5714e113bc0
   remote is subset
 
 
 Many new:
 
   $ testdesc '-ra1 -ra2' '-rb' '
   > +2:f +3:a1 +3:b
   > <f +30 :a2'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: bebd167eb94d
   common heads: bebd167eb94d
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   taking initial sample
   searching: 2 queries
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   common heads: bebd167eb94d
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 66f7d451a68b bebd167eb94d
   common heads: bebd167eb94d
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   taking initial sample
   searching: 2 queries
   query 2; still undecided: 2, sample size is: 2
   2 total queries in *.????s (glob)
   common heads: bebd167eb94d
 
 Both sides many new with stub:
 
   $ testdesc '-ra1 -ra2' '-rb' '
   > +2:f +2:a1 +30 :b
   > <f +30 :a2'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: 2dc09a01254d
   common heads: 2dc09a01254d
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   taking initial sample
   searching: 2 queries
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   common heads: 2dc09a01254d
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 2dc09a01254d 66f7d451a68b
   common heads: 2dc09a01254d
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   taking initial sample
   searching: 2 queries
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   common heads: 2dc09a01254d
 
 
 Both many new:
 
   $ testdesc '-ra' '-rb' '
   > +2:f +30 :b
   > <f +30 :a'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: 66f7d451a68b
   common heads: 66f7d451a68b
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   common heads: 66f7d451a68b
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 66f7d451a68b
   common heads: 66f7d451a68b
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   common heads: 66f7d451a68b
 
 
 Both many new skewed:
 
   $ testdesc '-ra' '-rb' '
   > +2:f +30 :b
   > <f +50 :a'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: 66f7d451a68b
   common heads: 66f7d451a68b
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 51, sample size is: 51
   2 total queries in *.????s (glob)
   common heads: 66f7d451a68b
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 66f7d451a68b
   common heads: 66f7d451a68b
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   common heads: 66f7d451a68b
 
 
 Both many new on top of long history:
 
   $ testdesc '-ra' '-rb' '
   > +1000:f +30 :b
   > <f +50 :a'
   
   % -- a -> b tree
   comparing with b
   searching for changes
   unpruned common: 7ead0cba2838
   common heads: 7ead0cba2838
   
   % -- a -> b set
   comparing with b
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 1049, sample size is: 11
   sampling from both directions
   searching: 3 queries
   query 3; still undecided: 31, sample size is: 31
   3 total queries in *.????s (glob)
   common heads: 7ead0cba2838
   
   % -- b -> a tree
   comparing with a
   searching for changes
   unpruned common: 7ead0cba2838
   common heads: 7ead0cba2838
   
   % -- b -> a set
   comparing with a
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 1029, sample size is: 11
   sampling from both directions
   searching: 3 queries
   query 3; still undecided: 15, sample size is: 15
   3 total queries in *.????s (glob)
   common heads: 7ead0cba2838
 
 
 One with >200 heads, which used to use up all of the sample:
 
   $ hg init manyheads
   $ cd manyheads
   $ echo "+300:r @a" >dagdesc
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3 *r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3*r+3" >>dagdesc # 20 heads
   $ echo "@b *r+3" >>dagdesc # one more head
   $ hg debugbuilddag <dagdesc
   reading DAG from stdin
 
   $ hg heads -t --template . | wc -c
   \s*261 (re)
 
   $ hg clone -b a . a
   adding changesets
   adding manifests
   adding file changes
   added 1340 changesets with 0 changes to 0 files (+259 heads)
   updating to branch a
   0 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ hg clone -b b . b
   adding changesets
   adding manifests
   adding file changes
   added 304 changesets with 0 changes to 0 files
   updating to branch b
   0 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
   $ hg -R a debugdiscovery b --debug --verbose --config progress.debug=true
   comparing with b
   query 1; heads
   searching for changes
   taking quick initial sample
   searching: 2 queries
   query 2; still undecided: 1240, sample size is: 100
   sampling from both directions
   searching: 3 queries
   query 3; still undecided: 1140, sample size is: 200
   sampling from both directions
   searching: 4 queries
   query 4; still undecided: \d+, sample size is: 200 (re)
   sampling from both directions
   searching: 5 queries
   query 5; still undecided: \d+, sample size is: 200 (re)
   sampling from both directions
   searching: 6 queries
   query 6; still undecided: \d+, sample size is: \d+ (re)
   6 total queries in *.????s (glob)
   common heads: 3ee37d65064a
 
 Test actual protocol when pulling one new head in addition to common heads
 
   $ hg clone -U b c
   $ hg -R c id -ir tip
   513314ca8b3a
   $ hg -R c up -qr default
   $ touch c/f
   $ hg -R c ci -Aqm "extra head"
   $ hg -R c id -i
   e64a39e7da8b
 
   $ hg serve -R c -p $HGPORT -d --pid-file=hg.pid -A access.log -E errors.log
   $ cat hg.pid >> $DAEMON_PIDS
 
   $ hg -R b incoming http://localhost:$HGPORT/ -T '{node|short}\n'
   comparing with http://localhost:$HGPORT/
   searching for changes
   e64a39e7da8b
 
   $ killdaemons.py
   $ cut -d' ' -f6- access.log | grep -v cmd=known # cmd=known uses random sampling
   "GET /?cmd=capabilities HTTP/1.1" 200 -
   "GET /?cmd=batch HTTP/1.1" 200 - x-hgarg-1:cmds=heads+%3Bknown+nodes%3D513314ca8b3ae4dac8eec56966265b00fcf866db x-hgproto-1:0.1 0.2 comp=*zlib,none,bzip2 (glob)
   "GET /?cmd=getbundle HTTP/1.1" 200 - x-hgarg-1:bundlecaps=HG20%2Cbundle2%3DHG20%250Achangegroup%253D01%252C02%250Adigests%253Dmd5%252Csha1%252Csha512%250Aerror%253Dabort%252Cunsupportedcontent%252Cpushraced%252Cpushkey%250Ahgtagsfnodes%250Alistkeys%250Apushkey%250Aremote-changegroup%253Dhttp%252Chttps&cg=1&common=513314ca8b3ae4dac8eec56966265b00fcf866db&heads=e64a39e7da8b0d54bc63e81169aff001c13b3477 x-hgproto-1:0.1 0.2 comp=*zlib,none,bzip2 (glob)
   "GET /?cmd=listkeys HTTP/1.1" 200 - x-hgarg-1:namespace=phases x-hgproto-1:0.1 0.2 comp=*zlib,none,bzip2 (glob)
   $ cat errors.log
 
   $ cd ..
 
 
 Issue 4438 - test coverage for 3ef893520a85 issues.
 
   $ mkdir issue4438
   $ cd issue4438
 #if false
 generate new bundles:
   $ hg init r1
   $ for i in `python $TESTDIR/seq.py 101`; do hg -R r1 up -qr null && hg -R r1 branch -q b$i && hg -R r1 ci -qmb$i; done
   $ hg clone -q r1 r2
   $ for i in `python $TESTDIR/seq.py 10`; do hg -R r1 up -qr null && hg -R r1 branch -q c$i && hg -R r1 ci -qmc$i; done
   $ hg -R r2 branch -q r2change && hg -R r2 ci -qmr2change
   $ hg -R r1 bundle -qa $TESTDIR/bundles/issue4438-r1.hg
   $ hg -R r2 bundle -qa $TESTDIR/bundles/issue4438-r2.hg
 #else
 use existing bundles:
   $ hg clone -q $TESTDIR/bundles/issue4438-r1.hg r1
   $ hg clone -q $TESTDIR/bundles/issue4438-r2.hg r2
 #endif
 
 Set iteration order could cause wrong and unstable results - fixed in 73cfaa348650:
 
   $ hg -R r1 outgoing r2 -T'{rev} '
   comparing with r2
   searching for changes
   101 102 103 104 105 106 107 108 109 110  (no-eol)
 
 The case where all the 'initialsamplesize' samples already were common would
 give 'all remote heads known locally' without checking the remaining heads -
 fixed in 86c35b7ae300:
 
   $ cat >> $TESTTMP/unrandomsample.py << EOF
   > import random
   > def sample(population, k):
   >     return sorted(population)[:k]
   > random.sample = sample
   > EOF
 
   $ cat >> r1/.hg/hgrc << EOF
   > [extensions]
   > unrandomsample = $TESTTMP/unrandomsample.py
   > EOF
 
-  $ hg -R r1 outgoing r2 -T'{rev} '
+  $ hg -R r1 outgoing r2 -T'{rev} ' --config extensions.blackbox=
   comparing with r2
   searching for changes
   101 102 103 104 105 106 107 108 109 110  (no-eol)
+  $ hg -R r1 --config extensions.blackbox= blackbox
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> outgoing r2 '-T{rev} ' (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> found 101 common and 101 missing heads, 2 roundtrips in *.????s (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> -R r1 outgoing r2 '-T{rev} ' --config 'extensions.blackbox=' exited 0 after *.?? seconds (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> blackbox (glob)
   $ cd ..