delta-find: add debug information about reuse of cached data
This will help us to understand the behavior of find-delta during a pull.
--- a/mercurial/revlogutils/deltas.py Tue Nov 08 18:05:19 2022 -0500
+++ b/mercurial/revlogutils/deltas.py Tue Nov 15 18:08:56 2022 +0100
@@ -1147,7 +1147,13 @@
if deltainfo is not None:
prev = deltainfo.base
- if p1 in candidaterevs or p2 in candidaterevs:
+ if (
+ cachedelta is not None
+ and len(candidaterevs) == 1
+ and cachedelta[0] in candidaterevs
+ ):
+ round_type = b"cached-delta"
+ elif p1 in candidaterevs or p2 in candidaterevs:
round_type = b"parents"
elif prev is not None and all(c < prev for c in candidaterevs):
round_type = b"refine-down"
@@ -1246,10 +1252,19 @@
if self._write_debug is not None:
end = util.timer()
+ assert deltainfo is not None # please pytype
+ used_cached = (
+ cachedelta is not None
+ and dbg_try_rounds == 1
+ and dbg_try_count == 1
+ and deltainfo.base == cachedelta[0]
+ )
dbg = {
'duration': end - start,
'revision': target_rev,
+ 'delta-base': deltainfo.base,
'search_round_count': dbg_try_rounds,
+ 'using-cached-base': used_cached,
'delta_try_count': dbg_try_count,
'type': dbg_type,
'p1-chain-len': p1_chain_len,
@@ -1283,7 +1298,9 @@
b"DBG-DELTAS:"
b" %-12s"
b" rev=%d:"
- b" search-rounds=%d"
+ b" delta-base=%d"
+ b" is-cached=%d"
+ b" - search-rounds=%d"
b" try-count=%d"
b" - delta-type=%-6s"
b" snap-depth=%d"
@@ -1295,6 +1312,8 @@
msg %= (
dbg["target-revlog"],
dbg["revision"],
+ dbg["delta-base"],
+ dbg["using-cached-base"],
dbg["search_round_count"],
dbg["delta_try_count"],
dbg["type"],
--- a/tests/test-bundle.t Tue Nov 08 18:05:19 2022 -0500
+++ b/tests/test-bundle.t Tue Nov 15 18:08:56 2022 +0100
@@ -1048,17 +1048,17 @@
> --config storage.revlog.reuse-external-delta=no \
> --config storage.revlog.reuse-external-delta-parent=no
adding changesets
- DBG-DELTAS: CHANGELOG: rev=0: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: CHANGELOG: rev=1: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: CHANGELOG: rev=2: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: CHANGELOG: rev=0: delta-base=0 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: CHANGELOG: rev=1: delta-base=1 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: CHANGELOG: rev=2: delta-base=2 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
adding manifests
- DBG-DELTAS: MANIFESTLOG: rev=0: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: MANIFESTLOG: rev=1: search-rounds=1 try-count=1 - delta-type=delta snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: MANIFESTLOG: rev=2: search-rounds=1 try-count=1 - delta-type=delta snap-depth=0 - p1-chain-length=1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: MANIFESTLOG: rev=0: delta-base=0 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: MANIFESTLOG: rev=1: delta-base=0 is-cached=1 - search-rounds=1 try-count=1 - delta-type=delta snap-depth=0 - p1-chain-length=0 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: MANIFESTLOG: rev=2: delta-base=1 is-cached=1 - search-rounds=1 try-count=1 - delta-type=delta snap-depth=0 - p1-chain-length=1 p2-chain-length=-1 - duration=* (glob)
adding file changes
- DBG-DELTAS: FILELOG:a: rev=0: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: FILELOG:b: rev=0: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
- DBG-DELTAS: FILELOG:c: rev=0: search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:a: rev=0: delta-base=0 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:b: rev=0: delta-base=0 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:c: rev=0: delta-base=0 is-cached=0 - search-rounds=0 try-count=0 - delta-type=full snap-depth=0 - p1-chain-length=-1 p2-chain-length=-1 - duration=* (glob)
added 3 changesets with 3 changes to 3 files
new changesets 4fe08cd4693e:4652c276ac4f (3 drafts)
(run 'hg update' to get a working copy)
--- a/tests/test-sparse-revlog.t Tue Nov 08 18:05:19 2022 -0500
+++ b/tests/test-sparse-revlog.t Tue Nov 15 18:08:56 2022 +0100
@@ -189,7 +189,7 @@
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: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ cat << EOF >>.hg/hgrc
> [storage]
@@ -198,7 +198,7 @@
> EOF
$ hg debug-delta-find SPARSE-REVLOG-TEST-FILE 4971 --quiet
- DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - 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 - 2 candidates - search-down
@@ -231,10 +231,10 @@
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: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - 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 - search-down
+ 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
@@ -242,7 +242,7 @@
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: search-rounds=1 try-count=1 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=1 - search-rounds=1 try-count=1 - 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 p1
DBG-DELTAS-SEARCH: SEARCH rev=4971
DBG-DELTAS-SEARCH: ROUND #1 - 2 candidates - search-down
@@ -275,7 +275,7 @@
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: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - 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 - 2 candidates - search-down
@@ -308,7 +308,7 @@
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: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - 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 - 2 candidates - search-down
@@ -341,6 +341,6 @@
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: search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
+ DBG-DELTAS: FILELOG:SPARSE-REVLOG-TEST-FILE: rev=4971: delta-base=4930 is-cached=0 - search-rounds=3 try-count=3 - delta-type=snapshot snap-depth=4 - p1-chain-length=15 p2-chain-length=-1 - duration=* (glob)
$ cd ..