perf: clear vfs audit_cache before each run
When generating a stream clone, we spend a large amount of time auditing path.
Before this changes, the first run was warming the vfs cache for the other
runs, leading to a large runtime difference and a "faulty" reported timing for
the operation.
We now clear this important cache between run to get a more realistic timing.
Below are some example of median time change when clearing these cases. The
maximum time for a run did not changed significantly.
### data-env-vars.name = mozilla-central-2018-08-01-zstd-sparse-revlog
# benchmark.name = hg.perf.exchange.stream.generate
# bin-env-vars.hg.flavor = default
# bin-env-vars.hg.py-re2-module = default
# benchmark.variants.version = latest
no-clearing: 17.289905
cache-clearing: 21.587965 (+24.86%, +4.30)
## data-env-vars.name = mozilla-central-2024-03-22-zstd-sparse-revlog
no-clearing: 32.670748
cache-clearing: 40.467095 (+23.86%, +7.80)
## data-env-vars.name = mozilla-try-2019-02-18-zstd-sparse-revlog
no-clearing: 37.838858
cache-clearing: 46.072749 (+21.76%, +8.23)
## data-env-vars.name = mozilla-unified-2024-03-22-zstd-sparse-revlog
no-clearing: 32.969395
cache-clearing: 39.646209 (+20.25%, +6.68)
In addition, this significantly reduce the timing difference between the
performance command, from the perf extensions and a `real `hg bundle` call
producing a stream bundle. Some significant differences remain especially on
the "mozilla-try" repositories, but they are now smaller.
Note that some of that difference will actually not be
attributable to the stream generation (like maybe phases or branch map
computation).
Below are some benchmarks done on a currently draft changeset fixing some
unrelated slowness in `hg bundle` (34a78972af409d1ff37c29e60f6ca811ad1a457d)
### data-env-vars.name = mozilla-central-2018-08-01-zstd-sparse-revlog
# bin-env-vars.hg.flavor = default
# bin-env-vars.hg.py-re2-module = default
hg.perf.exchange.stream.generate: 21.587965
hg.command.bundle: 24.301799 (+12.57%, +2.71)
## data-env-vars.name = mozilla-central-2024-03-22-zstd-sparse-revlog
hg.perf.exchange.stream.generate: 40.467095
hg.command.bundle: 44.831317 (+10.78%, +4.36)
## data-env-vars.name = mozilla-unified-2024-03-22-zstd-sparse-revlog
hg.perf.exchange.stream.generate: 39.646209
hg.command.bundle: 45.395258 (+14.50%, +5.75)
## data-env-vars.name = mozilla-try-2019-02-18-zstd-sparse-revlog
hg.perf.exchange.stream.generate: 46.072749
hg.command.bundle: 55.882608 (+21.29%, +9.81)
## data-env-vars.name = mozilla-try-2023-03-22-zlib-general-delta
hg.perf.exchange.stream.generate: 334.716708
hg.command.bundle: 377.856767 (+12.89%, +43.14)
## data-env-vars.name = mozilla-try-2023-03-22-zstd-sparse-revlog
hg.perf.exchange.stream.generate: 302.972301
hg.command.bundle: 326.098755 (+7.63%, +23.13)
#require no-windows
$ . "$TESTDIR/remotefilelog-library.sh"
$ hg init master
$ cd master
$ cat >> .hg/hgrc <<EOF
> [remotefilelog]
> server=True
> EOF
$ echo x > x
$ echo z > z
$ hg commit -qAm x1
$ echo x2 > x
$ echo z2 > z
$ hg commit -qAm x2
$ hg bookmark foo
$ cd ..
# prefetch a revision w/ a sparse checkout
$ hgcloneshallow ssh://user@dummy/master shallow --noupdate
streaming all changes
3 files to transfer, 527 bytes of data (no-zstd !)
transferred 527 bytes in * seconds (* */sec) (glob) (no-zstd !)
3 files to transfer, 534 bytes of data (zstd no-rust !)
transferred 534 bytes in * seconds (* */sec) (glob) (zstd no-rust !)
5 files to transfer, 660 bytes of data (zstd rust !)
transferred 660 bytes in * seconds (*/sec) (glob) (zstd rust !)
searching for changes
no changes found
$ cd shallow
$ printf "[extensions]\nsparse=\n" >> .hg/hgrc
$ hg debugsparse -I x
$ hg prefetch -r 0
1 files fetched over 1 fetches - (1 misses, 0.00% hit ratio) over *s (glob)
$ hg cat -r 0 x
x
$ hg debugsparse -I z
$ hg prefetch -r 0
1 files fetched over 1 fetches - (1 misses, 0.00% hit ratio) over *s (glob)
$ hg cat -r 0 z
z
# prefetch sparse only on pull when configured
$ printf "[remotefilelog]\npullprefetch=bookmark()\n" >> .hg/hgrc
$ hg strip tip
saved backup bundle to $TESTTMP/shallow/.hg/strip-backup/876b1317060d-b2e91d8d-backup.hg (glob)
2 files fetched over 2 fetches - (2 misses, 0.00% hit ratio) over *s (glob)
$ hg debugsparse --delete z
$ clearcache
$ hg pull
pulling from ssh://user@dummy/master
searching for changes
adding changesets
adding manifests
adding file changes
updating bookmark foo
added 1 changesets with 0 changes to 0 files
new changesets 876b1317060d
(run 'hg update' to get a working copy)
prefetching file contents
1 files fetched over 1 fetches - (1 misses, 0.00% hit ratio) over *s (glob)
# Dont consider filtered files when doing copy tracing
## Push an unrelated commit
$ cd ../
$ hgcloneshallow ssh://user@dummy/master shallow2
streaming all changes
3 files to transfer, 527 bytes of data (no-zstd !)
transferred 527 bytes in * seconds (*) (glob) (no-zstd !)
3 files to transfer, 534 bytes of data (zstd no-rust !)
transferred 534 bytes in * seconds (* */sec) (glob) (zstd no-rust !)
5 files to transfer, 660 bytes of data (zstd rust !)
transferred 660 bytes in * seconds (*/sec) (glob) (zstd rust !)
searching for changes
no changes found
updating to branch default
2 files updated, 0 files merged, 0 files removed, 0 files unresolved
1 files fetched over 1 fetches - (1 misses, 0.00% hit ratio) over *s (glob)
$ cd shallow2
$ printf "[extensions]\nsparse=\n" >> .hg/hgrc
$ hg up -q 0
2 files fetched over 1 fetches - (2 misses, 0.00% hit ratio) over *s (glob)
$ touch a
$ hg ci -Aqm a
$ hg push -q -f
## Pull the unrelated commit and rebase onto it - verify unrelated file was not
pulled
$ cd ../shallow
$ hg up -q 1
$ hg pull -q
$ hg debugsparse -I z
$ clearcache
$ hg prefetch -r '. + .^' -I x -I z
4 files fetched over 1 fetches - (4 misses, 0.00% hit ratio) over * (glob)
$ hg rebase -d 2 --keep
rebasing 1:876b1317060d foo "x2"