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)
Test that, when an hg push is interrupted and the remote side receives SIGPIPE,
the remote hg is able to successfully roll back the transaction.
$ hg init -q remote
$ hg clone -q ssh://user@dummy/`pwd`/remote local
$ SIGPIPE_REMOTE_DEBUG_FILE="$TESTTMP/DEBUGFILE"
$ SYNCFILE1="$TESTTMP/SYNCFILE1"
$ SYNCFILE2="$TESTTMP/SYNCFILE2"
$ export SIGPIPE_REMOTE_DEBUG_FILE
$ export SYNCFILE1
$ export SYNCFILE2
$ PYTHONUNBUFFERED=1
$ export PYTHONUNBUFFERED
On the remote end, run hg, piping stdout and stderr through processes that we
know the PIDs of. We will later kill these to simulate an ssh client
disconnecting.
$ remotecmd="$RUNTESTDIR/testlib/sigpipe-remote.py"
In the pretxnchangegroup hook, kill the PIDs recorded above to simulate ssh
disconnecting. Then exit nonzero, to force a transaction rollback.
$ cat >remote/.hg/hgrc <<EOF
> [hooks]
> pretxnchangegroup.00-break-things=sh "$RUNTESTDIR/testlib/wait-on-file" 10 "$SYNCFILE2" "$SYNCFILE1"
> pretxnchangegroup.01-output-things=echo "some remote output to be forward to the closed pipe"
> pretxnchangegroup.02-output-things=echo "some more remote output"
> EOF
$ hg --cwd ./remote tip -T '{node|short}\n'
000000000000
$ cd local
$ echo foo > foo ; hg commit -qAm "commit"
(use quiet to avoid flacky output from the server)
$ hg push --quiet --remotecmd "$remotecmd"
abort: stream ended unexpectedly (got 0 bytes, expected 4)
[255]
$ cat $SIGPIPE_REMOTE_DEBUG_FILE
SIGPIPE-HELPER: Starting
SIGPIPE-HELPER: Redirection in place
SIGPIPE-HELPER: pipes closed in main
SIGPIPE-HELPER: SYNCFILE1 detected
SIGPIPE-HELPER: worker killed
SIGPIPE-HELPER: creating SYNCFILE2
SIGPIPE-HELPER: Shutting down
SIGPIPE-HELPER: Server process terminated with status 255 (no-windows !)
SIGPIPE-HELPER: Server process terminated with status 1 (windows !)
SIGPIPE-HELPER: Shut down
The remote should be left in a good state
$ hg --cwd ../remote tip -T '{node|short}\n'
000000000000
#if windows
XXX-Windows Broken behavior to be fixed
Behavior on Windows is broken and should be fixed. However this is a fairly
corner case situation and no data are being corrupted. This would affect
central repository being hosted on a Windows machine and accessed using ssh.
This was catch as we setup new CI for Windows. Making the test pass on Windows
was enough of a pain that fixing the behavior set aside for now. Dear and
honorable reader, feel free to fix it.
$ hg --cwd ../remote recover
rolling back interrupted transaction
(verify step skipped, run `hg verify` to check your repository content)
#else
$ hg --cwd ../remote recover
no interrupted transaction available
[1]
#endif