test-sparse-revlog: make the large bundle generation more robust and useful

We do the following:
- adding a `--lazy` flag that skip the bundle generation if it already has the
  right content.
- adding a `--validate` flag that make sure the generated bundle match the
  expected content

Generate it on the fly with all this flag during the tests.

tests/artifacts/scripts/generate-churning-bundle.py

@@ -1,281 +1,318
 #!/usr/bin/env python3
 #
 # generate-branchy-bundle - generate a branch for a "large" branchy repository
 #
 # Copyright 2018 Octobus, [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.
 #
 # This script generates a repository suitable for testing delta computation
 # strategies.
 #
 # The repository update a single "large" file with many updates. One fixed part
 # of the files always get updated while the rest of the lines get updated over
 # time. This update happens over many topological branches, some getting merged
 # back.
+#
+# --lazy     will skip generating the file if one exist with the right content
+#            already.
+# --validate make sure the generated bundle has the expected content.
 
 
 import hashlib
 import os
 import shutil
 import subprocess
 import sys
 import tempfile
 
 import mercurial.context
 import mercurial.hg
 import mercurial.ui
 
 BUNDLE_NAME = 'big-file-churn.hg'
 
 # constants for generating the repository
 NB_CHANGESET = 5000
 PERIOD_MERGING = 8
 PERIOD_BRANCHING = 7
 MOVE_BACK_MIN = 3
 MOVE_BACK_RANGE = 5
 
 # constants for generating the large file we keep updating
 #
 # At each revision, the beginning on the file change,
 # and set of other lines changes too.
 FILENAME = 'SPARSE-REVLOG-TEST-FILE'
 NB_LINES = 10500
 ALWAYS_CHANGE_LINES = 500
 OTHER_CHANGES = 300
 
 
 def build_graph():
     heads = {0}
     graph = {0: (None, None)}
     for idx in range(1, NB_CHANGESET + 1):
         p, _ = parents = [idx - 1, None]
         if (idx % PERIOD_BRANCHING) == 0:
             back = MOVE_BACK_MIN + (idx % MOVE_BACK_RANGE)
             for _ in range(back):
                 p = graph.get(p, (p,))[0]
                 parents[0] = p
         if (idx % PERIOD_MERGING) == 0:
             parents[1] = min(heads)
         for p in parents:
             heads.discard(p)
         heads.add(idx)
         graph[idx] = tuple(parents)
     return graph
 
 
 GRAPH = build_graph()
 
 
 def nextcontent(previous_content):
     """utility to produce a new file content from the previous one"""
     return hashlib.md5(previous_content).hexdigest().encode('ascii')
 
 
 def filecontent(iteridx, oldcontent):
     """generate a new file content
 
     The content is generated according the iteration index and previous
     content"""
 
     # initial call
     if iteridx == 0:
         current = b''
     else:
         current = b"%d" % iteridx
 
     for idx in range(NB_LINES):
         do_change_line = True
         if oldcontent is not None and ALWAYS_CHANGE_LINES < idx:
             do_change_line = not ((idx - iteridx) % OTHER_CHANGES)
 
         if do_change_line:
             to_write = current + b'\n'
             current = nextcontent(current)
         else:
             to_write = oldcontent[idx]
         yield to_write
 
 
 def merge_content(base, left, right):
     """merge two file content to produce a new one
 
     use unambiguous update on each side when possible, and produce a new line
     whenever a merge is needed. Similar to what the manifest would do.
     """
     for old, left, right in zip(base, left, right):
         if old == left and old == right:
             yield old
         elif old == left and old != right:
             yield right
         elif old != left and old == right:
             yield left
         else:
             yield nextcontent(left + right)
 
 
 def ancestors(graph, rev):
     """return the set of ancestors of revision <rev>"""
     to_proceed = {rev}
     seen = set(to_proceed)
     while to_proceed:
         current = to_proceed.pop()
         for p in graph[current]:
             if p is None:
                 continue
             if p in seen:
                 continue
             to_proceed.add(p)
             seen.add(p)
     return seen
 
 
 def gca(graph, left, right):
     """find the greater common ancestors of left and right
 
     Note that the algorithm is stupid and N² when run on all merge, however
     this should not be a too much issue given the current scale.
     """
     return max(ancestors(graph, left) & ancestors(graph, right))
 
 
 def make_one_content_fn(idx, base, left, right):
     """build a function that build the content on demand
 
     The dependency are kept are reference to make sure they are not
     garbage-collected until we use them. Once we computed the current content,
     we make sure to drop their reference to allow them to be garbage collected.
     """
 
     def content_fn(idx=idx, base=base, left=left, right=right):
         if left is None:
             new = filecontent(idx, None)
         elif base is None:
             new = filecontent(idx, left())
         else:
             merged = merge_content(base(), left(), right())
             new = filecontent(idx, list(merged))
         return list(new)
 
     del idx
     del base
     del left
     del right
 
     value = None
     cf = [content_fn]
     del content_fn
 
     def final_fn():
         nonlocal value
         if value is None:
             content_fn = cf.pop()
             value = list(content_fn())
             del content_fn
         return value
 
     return final_fn
 
 
 def build_content_graph(graph):
     """produce file content for all revision
 
     The content will be generated on demande and cached. Cleanup the
     dictionnary are you use it to reduce memory usage.
     """
     content = {}
     for idx, (p1, p2) in graph.items():
         base = left = right = None
         if p1 is not None:
             left = content[p1]
             if p2 is not None:
                 right = content[p2]
                 base_rev = gca(graph, p1, p2)
                 base = content[base_rev]
         content[idx] = make_one_content_fn(idx, base, left, right)
     return content
 
 
 CONTENT = build_content_graph(GRAPH)
 
 
 def hg(command, *args):
     """call a mercurial command with appropriate config and argument"""
     env = os.environ.copy()
     if 'CHGHG' in env:
         full_cmd = ['chg']
     else:
         full_cmd = ['hg']
     full_cmd.append('--quiet')
     full_cmd.append(command)
     if command == 'commit':
         # reproducible commit metadata
         full_cmd.extend(['--date', '0 0', '--user', 'test'])
     elif command == 'merge':
         # avoid conflicts by picking the local variant
         full_cmd.extend(['--tool', ':merge-local'])
     full_cmd.extend(args)
     env['HGRCPATH'] = ''
     return subprocess.check_call(full_cmd, env=env)
 
 
 def write_repo(path):
     """write repository content in memory"""
     repo = mercurial.hg.repository(
         mercurial.ui.ui.load(),
         path=path.encode('utf-8'),
     )
     nodemap = {None: repo.nodeconstants.nullid}
     with repo.lock(), repo.transaction(b'bundle-generation'):
         for idx, (p1, p2) in GRAPH.items():
             if sys.stdout.isatty():
                 print("generating commit #%d/%d" % (idx, NB_CHANGESET))
 
             file_fn = lambda repo, memctx, path: mercurial.context.memfilectx(
                 repo,
                 memctx,
                 path,
                 data=b''.join(CONTENT.pop(idx)()),
             )
 
             mc = mercurial.context.memctx(
                 repo,
                 (nodemap[p1], nodemap[p2]),
                 b'commit #%d' % idx if idx else b'initial commit',
                 [FILENAME.encode('ascii')],
                 file_fn,
                 user=b"test",
                 date=(0, 0),
             )
             nodemap[idx] = repo.commitctx(mc)
 
 
-def run(target):
+def compute_md5(target):
+    with open(target, 'rb') as bundle:
+        data = bundle.read()
+        return hashlib.md5(data).hexdigest()
+
+
+def write_md5(target, md5):
+    with open(target + '.md5', 'wb') as md5file:
+        md5file.write(md5.encode('ascii') + b'\n')
+
+
+def read_md5(target):
+    with open(target + '.md5', 'rb') as md5file:
+        return md5file.read().strip().decode('ascii')
+
+
+def up_to_date_target(target):
+    """return true if the file already exist at the right"""
+    try:
+        found = compute_md5(target)
+        expected = read_md5(target)
+    except OSError:
+        return False
+    return found == expected
+
+
+def run(target, validate=False):
     tmpdir = tempfile.mkdtemp(prefix='tmp-hg-test-big-file-bundle-')
     try:
         os.chdir(tmpdir)
         hg(
             'init',
             '--config',
             'format.maxchainlen=%d' % NB_CHANGESET,
         )
         write_repo(tmpdir)
         hg('bundle', '--all', target, '--config', 'devel.bundle.delta=p1')
-        with open(target, 'rb') as bundle:
-            data = bundle.read()
-            digest = hashlib.md5(data).hexdigest()
-        with open(target + '.md5', 'wb') as md5file:
-            md5file.write(digest.encode('ascii') + b'\n')
-        if sys.stdout.isatty():
-            print('bundle generated at "%s" md5: %s' % (target, digest))
-
+        digest = compute_md5(target)
+        if not validate:
+            write_md5(target, digest)
+        else:
+            expected = read_md5(target)
+            if expected != digest:
+                msg = "bundle generated does not match the expected content\n"
+                msg += "    expected: %s\n" % expected
+                msg += "    got:      %s" % digest
+                print(msg, file=sys.stderr)
+                return 1
     finally:
         shutil.rmtree(tmpdir)
     return 0
 
 
 if __name__ == '__main__':
     orig = os.path.realpath(os.path.dirname(sys.argv[0]))
     target = os.path.join(orig, os.pardir, 'cache', BUNDLE_NAME)
-    sys.exit(run(target))
+    lazy = '--lazy' in sys.argv[1:]
+    validate = '--validate' in sys.argv[1:]
+    if lazy and up_to_date_target(target):
+        sys.exit(0)
+    sys.exit(run(target, validate=validate))

tests/test-sparse-revlog.t

@@ -1,520 +1,524
 ====================================
 Test delta choice with sparse revlog
 ====================================
 
 Sparse-revlog usually shows the most gain on Manifest. However, it is simpler
 to general an appropriate file, so we test with a single file instead. The
 goal is to observe intermediate snapshot being created.
 
 We need a large enough file. Part of the content needs to be replaced
 repeatedly while some of it changes rarely.
 
   $ bundlepath="$TESTDIR/artifacts/cache/big-file-churn.hg"
 
+#if pure
   $ expectedhash=`cat "$bundlepath".md5`
-
-#if slow
-
-  $ if [ ! -f "$bundlepath" ]; then
-  >     "$TESTDIR"/artifacts/scripts/generate-churning-bundle.py > /dev/null
-  > fi
-
-#else
-
   $ if [ ! -f "$bundlepath" ]; then
   >     echo 'skipped: missing artifact, run "'"$TESTDIR"'/artifacts/scripts/generate-churning-bundle.py"'
   >     exit 80
   > fi
-
-#endif
-
   $ currenthash=`f -M "$bundlepath" | cut -d = -f 2`
   $ if [ "$currenthash" != "$expectedhash" ]; then
   >     echo 'skipped: outdated artifact, md5 "'"$currenthash"'" expected "'"$expectedhash"'" run "'"$TESTDIR"'/artifacts/scripts/generate-churning-bundle.py"'
   >     exit 80
   > fi
+#else
+
+#if slow
+  $ LAZY_GEN=""
+
+#else
+  $ LAZY_GEN="--lazy"
+#endif
+
+#endif
+
+If the validation fails, either something is broken or the expected md5 need updating.
+To update the md5, invoke the script without --validate
+
+  $ "$TESTDIR"/artifacts/scripts/generate-churning-bundle.py --validate $LAZY_GEN > /dev/null
 
   $ cat >> $HGRCPATH << EOF
   > [format]
   > sparse-revlog = yes
   > maxchainlen = 15
   > revlog-compression=zlib
   > [storage]
   > revlog.optimize-delta-parent-choice = yes
   > revlog.reuse-external-delta-parent = no
   > revlog.reuse-external-delta = no
   > EOF
   $ hg init sparse-repo
   $ cd sparse-repo
   $ hg unbundle $bundlepath
   adding changesets
   adding manifests
   adding file changes
   added 5001 changesets with 5001 changes to 1 files (+89 heads)
   new changesets 9706f5af64f4:e4eee5e41c37 (5001 drafts)
   (run 'hg heads' to see heads, 'hg merge' to merge)
   $ hg up
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   updated to "e4eee5e41c37: commit #5000"
   89 other heads for branch "default"
 
 Sanity check the graph shape
 
   $ hg log -T '{rev} {p1rev} {p2rev}\n' --rev '0:100'
   0 -1 -1
   1 0 -1
   2 1 -1
   3 2 -1
   4 3 -1
   5 4 -1
   6 5 -1
   7 1 -1
   8 7 6
   9 8 -1
   10 9 -1
   11 10 -1
   12 11 -1
   13 12 -1
   14 1 -1
   15 14 -1
   16 15 13
   17 16 -1
   18 17 -1
   19 18 -1
   20 19 -1
   21 16 -1
   22 21 -1
   23 22 -1
   24 23 20
   25 24 -1
   26 25 -1
   27 26 -1
   28 21 -1
   29 28 -1
   30 29 -1
   31 30 -1
   32 31 27
   33 32 -1
   34 33 -1
   35 31 -1
   36 35 -1
   37 36 -1
   38 37 -1
   39 38 -1
   40 39 34
   41 40 -1
   42 36 -1
   43 42 -1
   44 43 -1
   45 44 -1
   46 45 -1
   47 46 -1
   48 47 41
   49 36 -1
   50 49 -1
   51 50 -1
   52 51 -1
   53 52 -1
   54 53 -1
   55 54 -1
   56 51 48
   57 56 -1
   58 57 -1
   59 58 -1
   60 59 -1
   61 60 -1
   62 61 -1
   63 56 -1
   64 63 55
   65 64 -1
   66 65 -1
   67 66 -1
   68 67 -1
   69 68 -1
   70 66 -1
   71 70 -1
   72 71 62
   73 72 -1
   74 73 -1
   75 74 -1
   76 75 -1
   77 71 -1
   78 77 -1
   79 78 -1
   80 79 69
   81 80 -1
   82 81 -1
   83 82 -1
   84 71 -1
   85 84 -1
   86 85 -1
   87 86 -1
   88 87 76
   89 88 -1
   90 89 -1
   91 86 -1
   92 91 -1
   93 92 -1
   94 93 -1
   95 94 -1
   96 95 83
   97 96 -1
   98 91 -1
   99 98 -1
   100 99 -1
 
 sanity check the change pattern
 
   $ hg log --stat -r 0:3
   changeset:   0:9706f5af64f4
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     initial commit
   
    SPARSE-REVLOG-TEST-FILE |  10500 ++++++++++++++++++++++++++++++++++++++++++++++
    1 files changed, 10500 insertions(+), 0 deletions(-)
   
   changeset:   1:724907deaa5e
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     commit #1
   
    SPARSE-REVLOG-TEST-FILE |  1068 +++++++++++++++++++++++-----------------------
    1 files changed, 534 insertions(+), 534 deletions(-)
   
   changeset:   2:62c41bce3e5d
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     commit #2
   
    SPARSE-REVLOG-TEST-FILE |  1068 +++++++++++++++++++++++-----------------------
    1 files changed, 534 insertions(+), 534 deletions(-)
   
   changeset:   3:348a9cbd6959
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     commit #3
   
    SPARSE-REVLOG-TEST-FILE |  1068 +++++++++++++++++++++++-----------------------
    1 files changed, 534 insertions(+), 534 deletions(-)
   
 
   $ f -s .hg/store/data/*.d
   .hg/store/data/_s_p_a_r_s_e-_r_e_v_l_o_g-_t_e_s_t-_f_i_l_e.d: size=81370673
   $ hg debugrevlog *
   format : 1
   flags  : generaldelta
   
   revisions     :     5001
       merges    :      625 (12.50%)
       normal    :     4376 (87.50%)
   revisions     :     5001
       empty     :        0 ( 0.00%)
                      text  :        0 (100.00%)
                      delta :        0 (100.00%)
       snapshot  :      360 ( 7.20%)
         lvl-0   :             11 ( 0.22%)
         lvl-1   :             50 ( 1.00%)  non-ancestor-bases:       41 (82.00%)
         lvl-2   :            128 ( 2.56%)  non-ancestor-bases:      119 (92.97%)
         lvl-3   :            122 ( 2.44%)  non-ancestor-bases:      111 (90.98%)
         lvl-4   :             49 ( 0.98%)  non-ancestor-bases:       46 (93.88%)
       deltas    :     4641 (92.80%)
   revision size : 81370673
       snapshot  : 16282100 (20.01%)
         lvl-0   :        2188012 ( 2.69%)
         lvl-1   :        4848143 ( 5.96%)
         lvl-2   :        5366175 ( 6.59%)
         lvl-3   :        3085157 ( 3.79%)
         lvl-4   :         794613 ( 0.98%)
       deltas    : 65088573 (79.99%)
   
   chunks        :     5001
       0x78 (x)  :     5001 (100.00%)
   chunks size   : 81370673
       0x78 (x)  : 81370673 (100.00%)
   
   
   total-stored-content: 1 717 863 086 bytes
   
   avg chain length  :        8
   max chain length  :       15
   max chain reach   : 18326506
   compression ratio :       21
   
   uncompressed data size (min/max/avg) : 339930 / 346471 / 343503
   full revision size (min/max/avg)     : 196682 / 201129 / 198910
   inter-snapshot size (min/max/avg)    : 11620 / 172223 / 40384
       level-1   (min/max/avg)          : 14329 / 172223 / 96962
       level-2   (min/max/avg)          : 11664 / 86421 / 41923
       level-3   (min/max/avg)          : 11620 / 42674 / 25288
       level-4   (min/max/avg)          : 11631 / 21209 / 16216
   delta size (min/max/avg)             : 10610 / 190651 / 14024
   
   deltas against prev  : 3916 (84.38%)
       where prev = p1  : 3916     (100.00%)
       where prev = p2  :    0     ( 0.00%)
       other-ancestor   :    0     ( 0.00%)
       unrelated        :    0     ( 0.00%)
   deltas against p1    :  667 (14.37%)
   deltas against p2    :   58 ( 1.25%)
   deltas against ancs  :    0 ( 0.00%)
   deltas against other :    0 ( 0.00%)
 
 
 Test `debug-delta-find`
 -----------------------
 
   $ ls -1
   SPARSE-REVLOG-TEST-FILE
   $ hg debugdeltachain SPARSE-REVLOG-TEST-FILE | grep snap | tail -1
      4996    4995      -1      11        3     4947    snap
   $ LAST_SNAP=`hg debugdeltachain SPARSE-REVLOG-TEST-FILE | grep snap | tail -1| sed 's/^ \+//'| cut -d ' ' -f 1`
   $ echo Last Snapshot: $LAST_SNAP
   Last Snapshot: 4996
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4964
   DBG-DELTAS-SEARCH:     type=snapshot-3
   DBG-DELTAS-SEARCH:     size=15153
   DBG-DELTAS-SEARCH:     base=4958
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36297 (BAD)
   DBG-DELTAS-SEARCH: ROUND #2 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4958
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=30977
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36578 (BAD)
   DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #4 - 1 candidates - refine-down
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4667
   DBG-DELTAS-SEARCH:     type=snapshot-0
   DBG-DELTAS-SEARCH:     size=196699
   DBG-DELTAS-SEARCH:     base=-1
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=281309
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=165408 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #5 - 1 candidates - refine-up
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4954
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=58198
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=92195
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=54601 (BAD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
 
   $ cat << EOF >>.hg/hgrc
   > [storage]
   > revlog.optimize-delta-parent-choice = no
   > revlog.reuse-external-delta = yes
   > EOF
 
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --quiet
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --source full
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4964
   DBG-DELTAS-SEARCH:     type=snapshot-3
   DBG-DELTAS-SEARCH:     size=15153
   DBG-DELTAS-SEARCH:     base=4958
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36297 (BAD)
   DBG-DELTAS-SEARCH: ROUND #2 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4958
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=30977
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36578 (BAD)
   DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #4 - 1 candidates - refine-down
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4667
   DBG-DELTAS-SEARCH:     type=snapshot-0
   DBG-DELTAS-SEARCH:     size=196699
   DBG-DELTAS-SEARCH:     base=-1
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=281309
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=165408 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #5 - 1 candidates - refine-up
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4954
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=58198
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=92195
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=54601 (BAD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --source storage
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - cached-delta
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=1 - search-rounds=1 try-count=1 - delta-type=delta  snap-depth=-1 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --source p1
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4964
   DBG-DELTAS-SEARCH:     type=snapshot-3
   DBG-DELTAS-SEARCH:     size=15153
   DBG-DELTAS-SEARCH:     base=4958
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36297 (BAD)
   DBG-DELTAS-SEARCH: ROUND #2 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4958
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=30977
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36578 (BAD)
   DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #4 - 1 candidates - refine-down
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4667
   DBG-DELTAS-SEARCH:     type=snapshot-0
   DBG-DELTAS-SEARCH:     size=196699
   DBG-DELTAS-SEARCH:     base=-1
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=281309
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=165408 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #5 - 1 candidates - refine-up
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4954
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=58198
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=92195
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=54601 (BAD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --source p2
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4964
   DBG-DELTAS-SEARCH:     type=snapshot-3
   DBG-DELTAS-SEARCH:     size=15153
   DBG-DELTAS-SEARCH:     base=4958
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36297 (BAD)
   DBG-DELTAS-SEARCH: ROUND #2 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4958
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=30977
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36578 (BAD)
   DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #4 - 1 candidates - refine-down
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4667
   DBG-DELTAS-SEARCH:     type=snapshot-0
   DBG-DELTAS-SEARCH:     size=196699
   DBG-DELTAS-SEARCH:     base=-1
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=281309
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=165408 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #5 - 1 candidates - refine-up
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4954
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=58198
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=92195
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=54601 (BAD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
   $ hg debug-delta-find SPARSE-REVLOG-TEST-FILE $LAST_SNAP --source prev
   DBG-DELTAS-SEARCH: SEARCH rev=4996
   DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4964
   DBG-DELTAS-SEARCH:     type=snapshot-3
   DBG-DELTAS-SEARCH:     size=15153
   DBG-DELTAS-SEARCH:     base=4958
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36297 (BAD)
   DBG-DELTAS-SEARCH: ROUND #2 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4958
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=30977
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=61571
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=36578 (BAD)
   DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - search-down
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4947
   DBG-DELTAS-SEARCH:     type=snapshot-1
   DBG-DELTAS-SEARCH:     size=164878
   DBG-DELTAS-SEARCH:     base=4667
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=87938
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=52101 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #4 - 1 candidates - refine-down
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4667
   DBG-DELTAS-SEARCH:     type=snapshot-0
   DBG-DELTAS-SEARCH:     size=196699
   DBG-DELTAS-SEARCH:     base=-1
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=281309
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=165408 (GOOD)
   DBG-DELTAS-SEARCH: ROUND #5 - 1 candidates - refine-up
   DBG-DELTAS-SEARCH:   CONTENDER: rev=4947 - length=52101
   DBG-DELTAS-SEARCH:   CANDIDATE: rev=4954
   DBG-DELTAS-SEARCH:     type=snapshot-2
   DBG-DELTAS-SEARCH:     size=58198
   DBG-DELTAS-SEARCH:     base=4947
   DBG-DELTAS-SEARCH:     uncompressed-delta-size=92195
   DBG-DELTAS-SEARCH:     delta-search-time=* (glob)
   DBG-DELTAS-SEARCH:     DELTA: length=54601 (BAD)
   DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4996: delta-base=4947 is-cached=0 - search-rounds=5 try-count=5 - delta-type=snapshot snap-depth=2 - p1-chain-length=15 p2-chain-length=-1 - duration=*.?????? (glob)
 
   $ cd ..