phases: rework the logic of _pushdiscoveryphase to bound complexity
This rework the various graph traversal in _pushdiscoveryphase to keep the
complexity in check.
This is done though a couple of things:
- first, limiting the space we have to explore, for example, if we are not in
publishing push, we don't need to consider remote draft roots that are also
draft locally, as there is nothing to be moved there.
- avoid unbounded descendant computation, and use the faster "rev between"
computation.
This provide a massive boost to performance when exchanging with repository with
a massive amount of draft, like mozilla-try:
### data-env-vars.name = mozilla-try-2023-03-22-zstd-sparse-revlog
# benchmark.name = hg.command.push
# bin-env-vars.hg.flavor = default
# bin-env-vars.hg.py-re2-module = default
# benchmark.variants.explicit-rev = all-out-heads
# benchmark.variants.issue6528 = disabled
# benchmark.variants.protocol = ssh
# benchmark.variants.reuse-external-delta-parent = default
## benchmark.variants.revs = any-1-extra-rev
before: 20.346590 seconds
after: 11.232059 seconds (-38.15%, -7.48 seconds)
## benchmark.variants.revs = any-100-extra-rev
before: 24.752051 seconds
after: 15.367412 seconds (-37.91%, -9.38 seconds)
After this changes, the push operation is still quite too slow. Some of this
can be attributed to general phases slowness (reading all the roots from disk
for example) and other know slowness (not using persistent-nodemap, branchmap,
tags, etc. We are also working on them, but with this series, phase discovery
during push no longer showing up in profile and this is a pretty nice and bit
low-hanging fruit out of the way.
### (same case as the above)
# benchmark.variants.revs = any-1-extra-rev
pre-%ln-change: 44.235070
this-changeset: 11.232059 seconds (-74.61%, -33.00 seconds)
# benchmark.variants.revs = any-100-extra-rev
pre-%ln-change: 49.234697
this-changeset: 15.367412 seconds (-68.79%, -33.87 seconds)
Note that with this change, the `hg push` performance is now much closer to the
`hg pull` performance, even it still lagging behind a bit. (and the overall
performance are still too slow).
### data-env-vars.name = mozilla-try-2023-03-22-ds2-pnm
# benchmark.variants.explicit-rev = all-out-heads
# benchmark.variants.issue6528 = disabled
# benchmark.variants.protocol = ssh
# benchmark.variants.pulled-delta-reuse-policy = default
# bin-env-vars.hg.flavor = rust
## benchmark.variants.revs = any-1-extra-rev
hg.command.pull: 6.517450
hg.command.push: 11.219888
## benchmark.variants.revs = any-100-extra-rev
hg.command.pull: 10.160991
hg.command.push: 14.251107
### data-env-vars.name = mozilla-try-2023-03-22-zstd-sparse-revlog
# bin-env-vars.hg.py-re2-module = default
# benchmark.variants.explicit-rev = all-out-heads
# benchmark.variants.issue6528 = disabled
# benchmark.variants.protocol = ssh
# benchmark.variants.pulled-delta-reuse-policy = default
## bin-env-vars.hg.flavor = default
## benchmark.variants.revs = any-1-extra-rev
hg.command.pull: 8.577772
hg.command.push: 11.232059
## bin-env-vars.hg.flavor = default
## benchmark.variants.revs = any-100-extra-rev
hg.command.pull: 13.152976
hg.command.push: 15.367412
## bin-env-vars.hg.flavor = rust
## benchmark.variants.revs = any-1-extra-rev
hg.command.pull: 8.731982
hg.command.push: 11.178751
## bin-env-vars.hg.flavor = rust
## benchmark.variants.revs = any-100-extra-rev
hg.command.pull: 13.184236
hg.command.push: 15.620843
====================================
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"
$ 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
$ cat >> $HGRCPATH << EOF
> [format]
> sparse-revlog = yes
> maxchainlen = 15
> [storage]
> revlog.optimize-delta-parent-choice = yes
> 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:d9032adc8114 (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 "d9032adc8114: commit #5000"
89 other heads for branch "default"
$ 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=58616973
$ 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 : 383 ( 7.66%)
lvl-0 : 3 ( 0.06%)
lvl-1 : 18 ( 0.36%) non-ancestor-bases: 9 (50.00%)
lvl-2 : 62 ( 1.24%) non-ancestor-bases: 58 (93.55%)
lvl-3 : 108 ( 2.16%) non-ancestor-bases: 108 (100.00%)
lvl-4 : 191 ( 3.82%) non-ancestor-bases: 180 (94.24%)
lvl-5 : 1 ( 0.02%) non-ancestor-bases: 1 (100.00%)
deltas : 4618 (92.34%)
revision size : 58616973
snapshot : 9247844 (15.78%)
lvl-0 : 539532 ( 0.92%)
lvl-1 : 1467743 ( 2.50%)
lvl-2 : 1873820 ( 3.20%)
lvl-3 : 2326874 ( 3.97%)
lvl-4 : 3029118 ( 5.17%)
lvl-5 : 10757 ( 0.02%)
deltas : 49369129 (84.22%)
chunks : 5001
0x28 : 5001 (100.00%)
chunks size : 58616973
0x28 : 58616973 (100.00%)
total-stored-content: 1 732 705 361 bytes
avg chain length : 9
max chain length : 15
max chain reach : 27366701
compression ratio : 29
uncompressed data size (min/max/avg) : 346468 / 346472 / 346471
full revision size (min/max/avg) : 179288 / 180786 / 179844
inter-snapshot size (min/max/avg) : 10757 / 169507 / 22916
level-1 (min/max/avg) : 13905 / 169507 / 81541
level-2 (min/max/avg) : 10887 / 83873 / 30222
level-3 (min/max/avg) : 10911 / 43047 / 21545
level-4 (min/max/avg) : 10838 / 21390 / 15859
level-5 (min/max/avg) : 10757 / 10757 / 10757
delta size (min/max/avg) : 9672 / 108072 / 10690
deltas against prev : 3906 (84.58%)
where prev = p1 : 3906 (100.00%)
where prev = p2 : 0 ( 0.00%)
other-ancestor : 0 ( 0.00%)
unrelated : 0 ( 0.00%)
deltas against p1 : 649 (14.05%)
deltas against p2 : 63 ( 1.36%)
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
4971 4970 -1 3 5 4930 snap
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 3 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4329
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=13781
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=173765
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=106516 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4335
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=14385
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=171587
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=105187 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4962
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=18296
DBG-DELTAS-SEARCH: base=4930
DBG-DELTAS-SEARCH: uncompressed-delta-size=30377
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=16872 (BAD)
DBG-DELTAS-SEARCH: ROUND #2 - 2 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4325
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=17384
DBG-DELTAS-SEARCH: base=4318
DBG-DELTAS-SEARCH: uncompressed-delta-size=178121
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=109064 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - refine-down
DBG-DELTAS-SEARCH: CONTENDER: rev=4930 - length=19179
DBG-DELTAS-SEARCH: CANDIDATE: rev=4799
DBG-DELTAS-SEARCH: type=snapshot-2
DBG-DELTAS-SEARCH: size=50213
DBG-DELTAS-SEARCH: base=4623
DBG-DELTAS-SEARCH: uncompressed-delta-size=82661
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=49132 (BAD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - 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 4971 --quiet
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971 --source full
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 3 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4329
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=13781
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=173765
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=106516 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4335
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=14385
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=171587
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=105187 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4962
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=18296
DBG-DELTAS-SEARCH: base=4930
DBG-DELTAS-SEARCH: uncompressed-delta-size=30377
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=16872 (BAD)
DBG-DELTAS-SEARCH: ROUND #2 - 2 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4325
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=17384
DBG-DELTAS-SEARCH: base=4318
DBG-DELTAS-SEARCH: uncompressed-delta-size=178121
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=109064 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - refine-down
DBG-DELTAS-SEARCH: CONTENDER: rev=4930 - length=19179
DBG-DELTAS-SEARCH: CANDIDATE: rev=4799
DBG-DELTAS-SEARCH: type=snapshot-2
DBG-DELTAS-SEARCH: size=50213
DBG-DELTAS-SEARCH: base=4623
DBG-DELTAS-SEARCH: uncompressed-delta-size=82661
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=49132 (BAD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971 --source storage
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 1 candidates - cached-delta
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 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 4971 --source p1
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 3 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4329
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=13781
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=173765
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=106516 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4335
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=14385
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=171587
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=105187 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4962
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=18296
DBG-DELTAS-SEARCH: base=4930
DBG-DELTAS-SEARCH: uncompressed-delta-size=30377
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=16872 (BAD)
DBG-DELTAS-SEARCH: ROUND #2 - 2 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4325
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=17384
DBG-DELTAS-SEARCH: base=4318
DBG-DELTAS-SEARCH: uncompressed-delta-size=178121
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=109064 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - refine-down
DBG-DELTAS-SEARCH: CONTENDER: rev=4930 - length=19179
DBG-DELTAS-SEARCH: CANDIDATE: rev=4799
DBG-DELTAS-SEARCH: type=snapshot-2
DBG-DELTAS-SEARCH: size=50213
DBG-DELTAS-SEARCH: base=4623
DBG-DELTAS-SEARCH: uncompressed-delta-size=82661
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=49132 (BAD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971 --source p2
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 3 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4329
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=13781
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=173765
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=106516 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4335
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=14385
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=171587
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=105187 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4962
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=18296
DBG-DELTAS-SEARCH: base=4930
DBG-DELTAS-SEARCH: uncompressed-delta-size=30377
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=16872 (BAD)
DBG-DELTAS-SEARCH: ROUND #2 - 2 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4325
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=17384
DBG-DELTAS-SEARCH: base=4318
DBG-DELTAS-SEARCH: uncompressed-delta-size=178121
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=109064 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - refine-down
DBG-DELTAS-SEARCH: CONTENDER: rev=4930 - length=19179
DBG-DELTAS-SEARCH: CANDIDATE: rev=4799
DBG-DELTAS-SEARCH: type=snapshot-2
DBG-DELTAS-SEARCH: size=50213
DBG-DELTAS-SEARCH: base=4623
DBG-DELTAS-SEARCH: uncompressed-delta-size=82661
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=49132 (BAD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971 --source prev
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 3 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4329
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=13781
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=173765
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=106516 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4335
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=14385
DBG-DELTAS-SEARCH: base=4325
DBG-DELTAS-SEARCH: uncompressed-delta-size=171587
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=105187 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4962
DBG-DELTAS-SEARCH: type=snapshot-4
DBG-DELTAS-SEARCH: size=18296
DBG-DELTAS-SEARCH: base=4930
DBG-DELTAS-SEARCH: uncompressed-delta-size=30377
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=16872 (BAD)
DBG-DELTAS-SEARCH: ROUND #2 - 2 candidates - search-down
DBG-DELTAS-SEARCH: CANDIDATE: rev=4325
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=17384
DBG-DELTAS-SEARCH: base=4318
DBG-DELTAS-SEARCH: uncompressed-delta-size=178121
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=109064 (BAD)
DBG-DELTAS-SEARCH: CANDIDATE: rev=4930
DBG-DELTAS-SEARCH: type=snapshot-3
DBG-DELTAS-SEARCH: size=39228
DBG-DELTAS-SEARCH: base=4799
DBG-DELTAS-SEARCH: uncompressed-delta-size=33050
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=19179 (GOOD)
DBG-DELTAS-SEARCH: ROUND #3 - 1 candidates - refine-down
DBG-DELTAS-SEARCH: CONTENDER: rev=4930 - length=19179
DBG-DELTAS-SEARCH: CANDIDATE: rev=4799
DBG-DELTAS-SEARCH: type=snapshot-2
DBG-DELTAS-SEARCH: size=50213
DBG-DELTAS-SEARCH: base=4623
DBG-DELTAS-SEARCH: uncompressed-delta-size=82661
DBG-DELTAS-SEARCH: delta-search-time=* (glob)
DBG-DELTAS-SEARCH: DELTA: length=49132 (BAD)
DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=6 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ cd ..