Thu, 16 Aug 2018 12:31:52 -0700 treemanifest: introduce lazy loading of subdirs
spectral <spectral@google.com> [Thu, 16 Aug 2018 12:31:52 -0700] rev 39515
treemanifest: introduce lazy loading of subdirs An earlier patch series made it so that what to load was up to the calling code, which works fine until manifests are copied - when they're copied, they're loaded completely and thus we lose the entire benefit. By lazy loading everything, we can avoid having to pass in the matcher to ~every manifest function, and handle copies correctly as well. This changeset doesn't go as far as it could with loading only the necessary subsets, that will happen in later changes in this series; at the moment, except in a few situations, we just load everything the moment we want to interact with treemanifest._dirs. This is thus most likely to be a small slowdown if treemanifests is in use regardless of whether narrow is in use, but hopefully easier to verify correctness and review. This is part of a series of speedups, it is not expected to produce any real speed improvements itself, but the numbers show that it doesn't produce a large speed penalty in any common case, and for the cases it does provide a penalty in, it is not a large absolute amount (even if it is a large percentage amount). Timing numbers according to command: hyperfine --prepare <preparation_script> 'hg status' HGRCPATH points to a file with the following contents: [extensions] narrow = strip = rebase = mozilla-unified (called m-u below) was at revision #468856. regular hash: eb39298e432d treemanifests hash: 0553b7f29eaf large-dir-repo (called l-d-r below) was generated with the following script: #!/bin/bash hg init large-dir-repo mkdir -p large-dir-repo/third_party/rust/log touch large-dir-repo/third_party/rust/log/foo.txt for i in $(seq 1 30000); do d=$(mktemp -d large-dir-repo/third_party/XXXXXXXXX) touch $d/file.txt done hg -R large-dir-repo ci -Am 'rev0' --user test --date '0 0' echo hi > large-dir-repo/third_party/rust/log/bar.txt hg -R large-dir-repo ci -Am 'rev1' --user test --date '0 0' echo hi > large-dir-repo/third_party/rust/log/baz.txt hg -R large-dir-repo ci -Am 'rev2' --user test --date '0 0' for the repos that use narrow, the narrowspec was this: [include] rootfilesin:accessible/jsat rootfilesin:accessible/tests/mochitest/jsat rootfilesin:mobile/android/chrome/content rootfilesin:mobile/android/modules/geckoview rootfilesin:third_party/rust/log [exclude] This narrowspec was chosen due to the size of the third_party/rust directory (this directory was *not* modified in revision #468856 in mozilla-unified), plus all the directories that *were* modified in revision #468856 of mozilla-unified. Importantly, when using narrow, these repos had everything checked out (in the case of large-dir-repo, that means all 30,001 directories), *before* adding the narrowspec. This is to simulate the behavior when using a virtual filesystem that shows everything for the user even if they haven't added it to the narrowspec yet. This is not a supported configuration, and `hg update` and `hg rebase` will not really do the "correct" thing if there are mutations outside of the narrowspec (which is not the case in these tests, due to a carefully crafted narrowspec), but non-mutating commands should behave correctly. I'm not claiming anything less than a 5% speed win as improvements due to this change; these are probably eiter measurement artifacts or constant time improvements. The numbers that aren't changing are shown primarily to prove that this doesn't make anything worse in any case I plan on testing during this series. 'before' is hg from commit 6268fed3 'N' indicates narrow in use 'T' indicates treemanifest in use Please note that these commands and the narrowspec are a little different than the ones in a similar table that I made in a3cabe9415e1. Important: it is my understanding that these numbers below are *not super reliable*, the large slowdowns may be artifacts of some odd interaction between GC and python module/code complexity. Another changeset of mine (D4351) had shown large timing differences when ~empty, uncalled functions were added to match.py, though only when using --color=never or redirecting to /dev/null. We seem to be on some cusp of complexity or code size that is causing, at my best guess (according to linux `perf` benchmarks) GC to alter behavior and cause a 200-400ms difference in timings. I haven't had a chance to replicate these results on another machine. diff --git: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 1.580 s +- 0.034 s | 1.576 s +- 0.022 s | 99.7% m-u | | x | 1.568 s +- 0.025 s | 1.584 s +- 0.044 s | 101.0% m-u | x | | 1.569 s +- 0.031 s | 1.554 s +- 0.025 s | 99.0% m-u | x | x | 107.3 ms +- 1.6 ms | 106.3 ms +- 1.5 ms | 99.1% l-d-r | | | 232.5 ms +- 5.9 ms | 233.5 ms +- 5.3 ms | 100.4% l-d-r | | x | 236.6 ms +- 6.3 ms | 233.6 ms +- 7.0 ms | 98.7% l-d-r | x | | 118.4 ms +- 2.1 ms | 118.4 ms +- 1.4 ms | 100.0% l-d-r | x | x | 116.8 ms +- 1.5 ms | 118.9 ms +- 1.6 ms | 101.8% diff -c . --git: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 354.4 ms +- 16.6 ms | 351.0 ms +- 6.9 ms | 99.0% m-u | | x | 207.2 ms +- 3.0 ms | 206.2 ms +- 2.7 ms | 99.5% m-u | x | | 422.0 ms +- 26.0 ms | 351.2 ms +- 6.4 ms | 83.2% <-- m-u | x | x | 166.7 ms +- 2.1 ms | 169.5 ms +- 4.1 ms | 101.7% l-d-r | | | 98.4 ms +- 4.5 ms | 98.5 ms +- 2.1 ms | 100.1% l-d-r | | x | 5.519 s +- 0.060 s | 5.149 s +- 0.042 s | 93.3% <-- l-d-r | x | | 99.1 ms +- 3.2 ms | 102.6 ms +- 9.7 ms | 103.5% <--? l-d-r | x | x | 994.9 ms +- 10.7 ms | 1.026 s +- 0.012 s | 103.1% <--? rebase -r . --keep -d .^^: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 6.639 s +- 0.168 s | 6.559 s +- 0.097 s | 98.8% m-u | | x | 6.601 s +- 0.143 s | 6.640 s +- 0.207 s | 100.6% m-u | x | | 6.582 s +- 0.098 s | 6.543 s +- 0.098 s | 99.4% m-u | x | x | 678.4 ms +- 57.7 ms | 703.7 ms +- 52.4 ms | 103.7% <--? l-d-r | | | 780.0 ms +- 23.9 ms | 776.0 ms +- 12.6 ms | 99.5% l-d-r | | x | 7.520 s +- 0.255 s | 7.395 s +- 0.044 s | 98.3% l-d-r | x | | 331.9 ms +- 16.5 ms | 327.0 ms +- 3.4 ms | 98.5% l-d-r | x | x | 6.228 s +- 0.113 s | 5.924 s +- 0.044 s | 95.1% status --change . --copies: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 330.8 ms +- 7.2 ms | 329.0 ms +- 7.1 ms | 99.5% m-u | | x | 182.9 ms +- 2.7 ms | 183.5 ms +- 2.7 ms | 100.3% m-u | x | | 330.0 ms +- 7.6 ms | 327.1 ms +- 5.4 ms | 99.1% m-u | x | x | 146.2 ms +- 2.4 ms | 147.1 ms +- 1.3 ms | 100.6% l-d-r | | | 95.3 ms +- 1.4 ms | 95.9 ms +- 1.5 ms | 100.6% l-d-r | | x | 5.157 s +- 0.035 s | 5.166 s +- 0.058 s | 100.2% l-d-r | x | | 99.7 ms +- 3.0 ms | 100.2 ms +- 4.4 ms | 100.5% l-d-r | x | x | 993.6 ms +- 13.1 ms | 1.025 s +- 0.015 s | 103.2% <--? status --copies: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 2.348 s +- 0.031 s | 2.329 s +- 0.019 s | 99.2% m-u | | x | 2.337 s +- 0.026 s | 2.346 s +- 0.034 s | 100.4% m-u | x | | 2.354 s +- 0.015 s | 2.342 s +- 0.021 s | 99.5% m-u | x | x | 120.6 ms +- 4.3 ms | 119.2 ms +- 2.1 ms | 98.8% l-d-r | | | 731.5 ms +- 11.1 ms | 719.6 ms +- 9.8 ms | 98.4% l-d-r | | x | 729.0 ms +- 15.5 ms | 725.7 ms +- 10.6 ms | 99.5% l-d-r | x | | 211.0 ms +- 3.9 ms | 212.8 ms +- 3.7 ms | 100.9% l-d-r | x | x | 211.5 ms +- 4.2 ms | 211.0 ms +- 3.3 ms | 99.8% update $rev^; ~/src/hg/hg{hg}/hg update $rev: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 3.910 s +- 0.055 s | 3.920 s +- 0.075 s | 100.3% m-u | | x | 3.613 s +- 0.056 s | 3.630 s +- 0.056 s | 100.5% m-u | x | | 3.873 s +- 0.055 s | 3.864 s +- 0.049 s | 99.8% m-u | x | x | 400.4 ms +- 7.4 ms | 403.6 ms +- 5.0 ms | 100.8% l-d-r | | | 531.6 ms +- 10.0 ms | 528.8 ms +- 9.6 ms | 99.5% l-d-r | | x | 10.377 s +- 0.049 s | 9.955 s +- 0.046 s | 95.9% l-d-r | x | | 308.3 ms +- 4.4 ms | 306.8 ms +- 3.7 ms | 99.5% l-d-r | x | x | 1.805 s +- 0.015 s | 1.834 s +- 0.020 s | 101.6% Differential Revision: https://phab.mercurial-scm.org/D4366
Fri, 07 Sep 2018 17:54:55 -0400 contrib: use a monotonic timer in catapipe
Boris Feld <boris.feld@octobus.net> [Fri, 07 Sep 2018 17:54:55 -0400] rev 39514
contrib: use a monotonic timer in catapipe As spotted by Gregory, we should use a monotonic timer to get better timings. Differential Revision: https://phab.mercurial-scm.org/D4516
Fri, 07 Sep 2018 17:51:07 -0400 contrib: fix catapipe output argument documentation
Boris Feld <boris.feld@octobus.net> [Fri, 07 Sep 2018 17:51:07 -0400] rev 39513
contrib: fix catapipe output argument documentation Differential Revision: https://phab.mercurial-scm.org/D4515
Thu, 06 Sep 2018 16:59:25 -0400 tracing: trace command function execution
Boris Feld <boris.feld@octobus.net> [Thu, 06 Sep 2018 16:59:25 -0400] rev 39512
tracing: trace command function execution Differential Revision: https://phab.mercurial-scm.org/D4514
Fri, 07 Sep 2018 16:51:51 -0400 extension: add a summary of total loading time per extension
Boris Feld <boris.feld@octobus.net> [Fri, 07 Sep 2018 16:51:51 -0400] rev 39511
extension: add a summary of total loading time per extension Differential Revision: https://phab.mercurial-scm.org/D4513
Thu, 06 Sep 2018 16:49:37 -0400 extensions: trace the total time of running all reposetup callbacks
Boris Feld <boris.feld@octobus.net> [Thu, 06 Sep 2018 16:49:37 -0400] rev 39510
extensions: trace the total time of running all reposetup callbacks Differential Revision: https://phab.mercurial-scm.org/D4512
Thu, 06 Sep 2018 16:21:42 -0400 extensions: trace the total time of running all extsetup callbacks
Boris Feld <boris.feld@octobus.net> [Thu, 06 Sep 2018 16:21:42 -0400] rev 39509
extensions: trace the total time of running all extsetup callbacks Differential Revision: https://phab.mercurial-scm.org/D4511
Thu, 06 Sep 2018 16:20:05 -0400 extensions: trace the total time of running all uisetup callbacks
Boris Feld <boris.feld@octobus.net> [Thu, 06 Sep 2018 16:20:05 -0400] rev 39508
extensions: trace the total time of running all uisetup callbacks Differential Revision: https://phab.mercurial-scm.org/D4510
Mon, 10 Sep 2018 19:36:25 -0700 extensions: add timing for extensions reposetup
Boris Feld <boris.feld@octobus.net> [Mon, 10 Sep 2018 19:36:25 -0700] rev 39507
extensions: add timing for extensions reposetup Differential Revision: https://phab.mercurial-scm.org/D4509
Fri, 07 Sep 2018 11:18:45 -0400 sparse-revlog: set max delta chain length to on thousand
Boris Feld <boris.feld@octobus.net> [Fri, 07 Sep 2018 11:18:45 -0400] rev 39506
sparse-revlog: set max delta chain length to on thousand The new snapshot system used in the sparse-revlog case gave us some small size benefit so far. However its most important property is to gracefully handle harder limit on delta chainlength. Long delta chain has a very detrimental impact on read (and write) performance in revlog. Being able to shorter them provide a great boost. However, shorting delta used to result significantly lower compression ratio. The intermediate snapshots effectively suppress most of this effect (even all in some case). # Effect on the test repository The repository we use for test is not "realistic" but can still show this in action using an unreasonably low chain limit. Limiting the chain length show a sizeable increase but stay under control: +6% for limit=15; +15% for limit=10. Without the snapshot system the increase is significantly bigger: +45% for limit=15; +80% for limit=10. Even slightly larger than without delta chain limit, the resulting size is still smaller than before we started doing snapshots. Here is a table for comparison. *Since the repository is not branchy, the initial sparse-revlog version does not bring much benefit compare to the non-sparse one): chain length limit | none | limit=15 | limit=10 | without sparse-revlog | 62 818 987 | 112 664 615 | 131 222 574 | without snapshot | 74 365 490 | 108 211 410 | 133 857 764 | with snapshot | 59 230 936 | 63 002 924 | 68 415 329 | # Effect On Real Life Repositories The series provides significant benefits on all kind of repositories. Using `hg debugupgraderepo -o redeltaparent --run`, we recomputed delta chain for various repositories with different settings: - delta chain length: unlimited or 1000 limit - sparse-revlog: enabled or disabled - this series: applied or not applied We can observe multiple types of effect: - On very branchy repositories: * The delta chain limit as low impact on the repo size. * Intermediate snapshot greatly reduces manifest size: - pypy: -80% - netbeans: -95% * The delta chain limit is effective, without a size impact: - netbeans average: 613 -> 282 - private #1 average: 1 068 -> 307 - On more linear repository: * Intermediate snapshot limit the impact of delta chain limit: - mozilla: without the series: +360% with the series: +25% * The delta chain limit provides large improvement: - mozilla's average chain length: unlimited: 15 338 limited: 469 * Despite the chain length limit, the manifest size is reduced: - mercurial: -25% - mozilla: -30% It is clear that the use of chains of intermediate snapshots provide large benefits both in storage size and delta chains quality. We should now switch our effort toward making sure the write performance are acceptable. Then, `sparse-revlog` will be a suitable format for all new repository. # Raw Statistic * no-sparse: general delta repository not using sparse-revlog * no-snapshot: sparse-revlog repository not using this series * snapshot: sparse-revlog repository using this series mercurial Manifest Size: limit | none | 1000 ------------|-------------|------------ no-sparse | 8 021 373 | 8 199 366 no-snapshot | 8 103 561 | 8 259 719 snapshot | 6 137 116 | 6 126 433 Manifest Chain length data limit || none || 1000 || value || average | max || average | max || ------------||---------|---------||---------|---------|| no-sparse || 307 | 1456 || 279 | 1000 || no-snapshot || 312 | 1456 || 283 | 1000 || snapshot || 248 | 1208 || 241 | 1000 || Full Store Size limit | none | 1000 ------------|-------------|------------ no-sparse | 51 013 198 | 51 201 574 no-snapshot | 50 930 795 | 51 141 006 snapshot | 48 072 037 | 48 093 572 pypy Manifest Size: limit | none | 1000 ------------|-------------|------------ no-sparse | 193 987 784 | 193 987 784 no-snapshot | 163 171 745 | 163 312 229 snapshot | 34 605 900 | 34 600 750 Manifest Chain length data limit || none || 1000 || value || average | max || average | max || ------------||---------|---------||---------|---------|| no-sparse || 101 | 692 || 101 | 692 || no-snapshot || 151 | 1307 || 148 | 1000 || snapshot || 128 | 1309 || 125 | 1000 || Full Store Size limit | none | 1000 ------------|-------------|------------ no-sparse | 495 931 473 | 495 931 473 no-snapshot | 465 441 017 | 465 581 501 snapshot | 355 467 301 | 355 472 451 Mozilla Manifest Size: limit | none | 1000 ------------|----------------|--------------- no-sparse | 416 757 148 | 1 869 009 668 no-snapshot | 401 592 370 | 1 843 493 795 snapshot | 224 359 521 | 284 615 500 Manifest Chain length data limit || none || 1000 || value || average | max || average | max || ------------||---------|---------||---------|---------|| no-sparse || 15 333 | 58 980 || 468 | 1 000 || no-snapshot || 15 336 | 58 980 || 469 | 1 000 || snapshot || 15 338 | 58 983 || 469 | 1 000 || Full Store Size limit | none | 1000 ------------|----------------|--------------- no-sparse | 2 712 477 887 | 4 164 995 451 no-snapshot | 2 698 887 835 | 4 141 054 304 snapshot | 2 518 130 385 | 2 578 587 596 Netbeans Manifest Size: limit | none | 1000 ------------|----------------|--------------- no-sparse | 4 766 794 101 | 4 870 642 687 no-snapshot | 4 334 806 082 | 4 428 681 309 snapshot | 232 659 666 | 240 330 665 Manifest Chain length data limit || none || 1000 || value || average | max || average | max || ------------||---------|---------||---------|---------|| no-sparse || 597 | 6802 || 254 | 1 000 || no-snapshot || 648 | 6 802 || 305 | 1 000 || snapshot || 613 | 6 804 || 282 | 1 000 || Full Store Size limit | none | 1000 ------------|----------------|--------------- no-sparse | 5 807 347 998 | 5 911 196 584 no-snapshot | 5 375 398 602 | 5 469 273 829 snapshot | 1 282 519 928 | 1 290 190 927 Private repo #1 Manifest Size: limit | none | 1000 ------------|-----------------|--------------- no-sparse | 41 389 010 840 | 41 398 162 091 no-snapshot | 9 737 319 435 | 10 223 773 150 snapshot | 744 215 807 | 747 961 822 Manifest Chain length data limit || none || 1000 || value || average | max || average | max || ------------||---------|---------||---------|---------|| no-sparse || 245 | 8 885 || 81 | 1 000 || no-snapshot || 1 225 | 8 885 || 336 | 1 000 || snapshot || 1 068 | 7 909 || 307 | 1 000 || Full Store Size limit | none | 1000 ------------|----------------|--------------- no-sparse | 49 646 065 126 | 49 655 216 377 no-snapshot | 17 924 862 856 | 18 411 316 571 snapshot | 9 009 024 710 | 9 012 770 725 Private repo #2 We currently have less data available for that repository. * Before is a sparse-revlog repository without this series * After is a sparse-revlog repository with this series + 1000 chain limit Manifest Size: Before: 1 531 485 040 bytes After: 1 091 422 451 bytes Manifest Chain: Before: 2 218 avg; 6 575 Max After: 442 avg; 1 000 Max Full Store Size Before: 15 203 955 615 after: 8 207 180 693
(0) -30000 -10000 -3000 -1000 -300 -100 -10 +10 +100 +300 +1000 +3000 +10000 tip