Mercurial > hg
view tests/test-logtoprocess.t @ 43198:c16fe77e340a
pathcopies: give up any optimization based on `introrev`
Between 8a0136f69027 and d98fb3f42f33, we sped up the search for the
introduction revision during path copies. However, further checking show that
finding the introduction revision is still expensive and that we are better off
without it. So we simply drop it and only rely on the linkrev optimisation.
I ran `perfpathcopies` on 6989 pair of revision in the pypy
repository (`hg perfhelper-pathcopies`. The result is massively in favor of
dropping this condition. The result of the copy tracing are unchanged.
Attempt to use a smaller changes preserving linkrev usage were unsuccessful, it
can return wrong result. The following changesets broke test-mv-cp-st-diff.t
- if not f.isintroducedafter(limit):
+ if limit >= 0 and f.linkrev() < limit:
return None
Here are various numbers (before this changeset/after this changesets)
source destination before after saved-time ratio
worth cases e66f24650daf 695dfb0f493b 1.062843 1.246369 -0.183526 1.172675
c979853a3b6a 8d60fe293e79 1.036985 1.196414 -0.159429 1.153743
22349fa2fc33 fbb1c9fd86c0 0.879926 1.038682 -0.158756 1.180420
682b98f3e672 a4878080a536 0.909952 1.063801 -0.153849 1.169074
5adabc9b9848 920958a93997 0.993622 1.147452 -0.153830 1.154817
worse 1% dbfbfcf077e9 aea8f2fd3593 1.016595 1.082999 -0.066404 1.065320
worse 5% c95f1ced15f2 7d29d5e39734 0.453694 0.471156 -0.017462 1.038488
worse 10% 3e144ed1d5b7 2aef0e942480 0.035140 0.037535 -0.002395 1.068156
worse 25% 321fc60db035 801748ba582a 0.009267 0.009325 -0.000058 1.006259
median 2088ce763fc2 e6991321d78b 0.000665 0.000651 0.000014 0.978947
best 25% 915631a97de6 385b31354be6 0.040743 0.040363 0.000380 0.990673
best 10% ad495c36a765 19c10384d3e7 0.431658 0.411490 0.020168 0.953278
best 5% d13ae7d283ae 813c99f810ac 1.141404 1.075346 0.066058 0.942126
best 1% 81593cb4a496 99ae11866969 1.833297 0.063823 1.769474 0.034813
best cases c3b14617fbd7 743a0fcaa4eb 1101.811740 2.735970 1099.075770 0.002483
c3b14617fbd7 9ba6ab77fd29 1116.753953 2.800729 1113.953224 0.002508
058b99d6e81f 57e249b7a3ea 1246.128485 3.042762 1243.085723 0.002442
9a8c361aab49 0354a250d371 1253.111894 3.085796 1250.026098 0.002463
442dbbc53c68 3ec1002a818c 1261.786294 3.138607 1258.647687 0.002487
As one can see, the average case is not really impacted. However, the worth case
we get after this changeset are much better than the one we had before it. We
have 30 pairs where improvements are above 10 minutes.
This reflect in the combined time for all pairs
before: 26256s
after: 1300s (-95%)
If we remove these pathological 30 cases, we still see a significant improvements:
before: 1631s
after: 1245s (-24%)
author | Pierre-Yves David <pierre-yves.david@octobus.net> |
---|---|
date | Thu, 10 Oct 2019 03:49:33 +0200 |
parents | 44378796c5e5 |
children | 42d2b31cee0b |
line wrap: on
line source
#require no-windows ATTENTION: logtoprocess runs commands asynchronously. Be sure to append "| cat" to hg commands, to wait for the output, if you want to test its output. Otherwise the test will be flaky. Test if logtoprocess correctly captures command-related log calls. $ hg init $ cat > $TESTTMP/foocommand.py << EOF > from __future__ import absolute_import > from mercurial import registrar > cmdtable = {} > command = registrar.command(cmdtable) > configtable = {} > configitem = registrar.configitem(configtable) > configitem(b'logtoprocess', b'foo', > default=None, > ) > @command(b'foobar', []) > def foo(ui, repo): > ui.log(b'foo', b'a message: %s\n', b'spam') > EOF $ cp $HGRCPATH $HGRCPATH.bak $ cat >> $HGRCPATH << EOF > [extensions] > logtoprocess= > foocommand=$TESTTMP/foocommand.py > [logtoprocess] > command=(echo 'logtoprocess command output:'; > echo "\$EVENT"; > echo "\$MSG1") > $TESTTMP/command.log > commandfinish=(echo 'logtoprocess commandfinish output:'; > echo "\$EVENT"; > echo "\$MSG1"; > echo "canonical: \$OPT_CANONICAL_COMMAND") > $TESTTMP/commandfinish.log > foo=(echo 'logtoprocess foo output:'; > echo "\$EVENT"; > echo "\$MSG1") > $TESTTMP/foo.log > EOF Running a command triggers both a ui.log('command') and a ui.log('commandfinish') call. The foo command also uses ui.log. Use sort to avoid ordering issues between the various processes we spawn: $ hg fooba $ sleep 1 $ cat $TESTTMP/command.log | sort command fooba logtoprocess command output: #if no-chg $ cat $TESTTMP/commandfinish.log | sort canonical: foobar commandfinish fooba exited 0 after * seconds (glob) logtoprocess commandfinish output: $ cat $TESTTMP/foo.log | sort a message: spam foo logtoprocess foo output: #endif Confirm that logging blocked time catches stdio properly: $ cp $HGRCPATH.bak $HGRCPATH $ cat >> $HGRCPATH << EOF > [extensions] > logtoprocess= > pager= > [logtoprocess] > uiblocked=echo "\$EVENT stdio \$OPT_STDIO_BLOCKED ms command \$OPT_COMMAND_DURATION ms" > $TESTTMP/uiblocked.log > [ui] > logblockedtimes=True > EOF $ hg log $ sleep 1 $ cat $TESTTMP/uiblocked.log uiblocked stdio [0-9]+.[0-9]* ms command [0-9]+.[0-9]* ms (re) Try to confirm that pager wait on logtoprocess: Add a script that wait on a file to appears for 5 seconds, if it sees it touch another file or die after 5 seconds. If the scripts is awaited by hg, the script will die after the timeout before we could touch the file and the resulting file will not exists. If not, we will touch the file and see it. $ cat >> fakepager.py <<EOF > import sys > printed = False > for line in sys.stdin: > sys.stdout.write(line) > printed = True > if not printed: > sys.stdout.write('paged empty output!\n') > EOF $ cat > $TESTTMP/wait-output.sh << EOF > #!/bin/sh > for i in \`$TESTDIR/seq.py 50\`; do > if [ -f "$TESTTMP/wait-for-touched" ]; > then > touch "$TESTTMP/touched"; > break; > else > sleep 0.1; > fi > done > EOF $ chmod +x $TESTTMP/wait-output.sh $ cat >> $HGRCPATH << EOF > [extensions] > logtoprocess= > pager= > [pager] > pager = "$PYTHON" $TESTTMP/fakepager.py > [logtoprocess] > commandfinish=$TESTTMP/wait-output.sh > EOF $ hg version -q --pager=always Mercurial Distributed SCM (version *) (glob) $ touch $TESTTMP/wait-for-touched $ sleep 0.2 $ test -f $TESTTMP/touched && echo "SUCCESS Pager is not waiting on ltp" || echo "FAIL Pager is waiting on ltp" SUCCESS Pager is not waiting on ltp