tests/test-extension-timing.t

setdiscovery: stop limiting the number of local head we initially send

In our testing this limitation provides now real gain and instead triggers
pathological discovery timing for some repository with many heads.

See inline documentation for details.

Some timing below:

Mozilla try repository, (~1M revs, ~35K heads), discovery between 2 clones with
100 head missing on each side

before:
! wall 1.492111 comb 1.490000 user 1.450000 sys 0.040000 (best of 20)
! wall 1.813992 comb 1.820000 user 1.700000 sys 0.120000 (max of 20)
! wall 1.574326 comb 1.573500 user 1.522000 sys 0.051500 (avg of 20)
! wall 1.572583 comb 1.570000 user 1.520000 sys 0.050000 (median of 20)

after:
! wall 1.147834 comb 1.150000 user 1.090000 sys 0.060000 (best of 20)
! wall 1.449144 comb 1.450000 user 1.330000 sys 0.120000 (max of 20)
! wall 1.204618 comb 1.202500 user 1.146500 sys 0.056000 (avg of 20)
! wall 1.194407 comb 1.190000 user 1.140000 sys 0.050000 (median of 20)


pypy (~100 heads, 317 heads) discovery between clones with only 42 common heads

before:
! wall 0.031653 comb 0.030000 user 0.030000 sys 0.000000 (best of 25)
! wall 0.055719 comb 0.050000 user 0.040000 sys 0.010000 (max of 25)
! wall 0.038939 comb 0.039600 user 0.038400 sys 0.001200 (avg of 25)
! wall 0.038660 comb 0.050000 user 0.040000 sys 0.010000 (median of 25)

after:
! wall 0.018754 comb 0.020000 user 0.020000 sys 0.000000 (best of 49)
! wall 0.034505 comb 0.040000 user 0.030000 sys 0.010000 (max of 49)
! wall 0.019631 comb 0.019796 user 0.018367 sys 0.001429 (avg of 49)
! wall 0.019132 comb 0.020000 user 0.020000 sys 0.000000 (median of 49)


Private repository (~1M revs, ~3K heads), discovery from a strip subset, about
100 changesets to be pulled.

before:
! wall 1.837729 comb 1.840000 user 1.790000 sys 0.050000 (best of 20)
! wall 2.203468 comb 2.200000 user 2.100000 sys 0.100000 (max of 20)
! wall 2.049355 comb 2.048500 user 2.002500 sys 0.046000 (avg of 20)
! wall 2.035315 comb 2.040000 user 2.000000 sys 0.040000 (median of 20)

after:
! wall 0.136598 comb 0.130000 user 0.110000 sys 0.020000 (best of 20)
! wall 0.330519 comb 0.330000 user 0.260000 sys 0.070000 (max of 20)
! wall 0.157254 comb 0.155500 user 0.123000 sys 0.032500 (avg of 20)
! wall 0.149870 comb 0.140000 user 0.110000 sys 0.030000 (median of 20)


Same private repo, discovery between two clone with 500 different heads on each
side:

before:
! wall 2.372919 comb 2.370000 user 2.320000 sys 0.050000 (best of 20)
! wall 2.622422 comb 2.610000 user 2.510000 sys 0.100000 (max of 20)
! wall 2.450135 comb 2.450000 user 2.402000 sys 0.048000 (avg of 20)
! wall 2.443896 comb 2.450000 user 2.410000 sys 0.040000 (median of 20)

after:
! wall 0.625497 comb 0.620000 user 0.570000 sys 0.050000 (best of 20)
! wall 0.834723 comb 0.820000 user 0.730000 sys 0.090000 (max of 20)
! wall 0.675725 comb 0.675500 user 0.628000 sys 0.047500 (avg of 20)
! wall 0.671614 comb 0.680000 user 0.640000 sys 0.040000 (median of 20)

Test basic extension support

  $ cat > foobar.py <<EOF
  > import os
  > from mercurial import commands, registrar
  > cmdtable = {}
  > command = registrar.command(cmdtable)
  > configtable = {}
  > configitem = registrar.configitem(configtable)
  > configitem(b'tests', b'foo', default=b"Foo")
  > def uisetup(ui):
  >     ui.debug(b"uisetup called [debug]\\n")
  >     ui.write(b"uisetup called\\n")
  >     ui.status(b"uisetup called [status]\\n")
  >     ui.flush()
  > def reposetup(ui, repo):
  >     ui.write(b"reposetup called for %s\\n" % os.path.basename(repo.root))
  >     ui.write(b"ui %s= repo.ui\\n" % (ui == repo.ui and b"=" or b"!"))
  >     ui.flush()
  > @command(b'foo', [], b'hg foo')
  > def foo(ui, *args, **kwargs):
  >     foo = ui.config(b'tests', b'foo')
  >     ui.write(foo)
  >     ui.write(b"\\n")
  > @command(b'bar', [], b'hg bar', norepo=True)
  > def bar(ui, *args, **kwargs):
  >     ui.write(b"Bar\\n")
  > EOF
  $ abspath=`pwd`/foobar.py

  $ mkdir barfoo
  $ cp foobar.py barfoo/__init__.py
  $ barfoopath=`pwd`/barfoo

  $ hg init a
  $ cd a
  $ echo foo > file
  $ hg add file
  $ hg commit -m 'add file'

  $ echo '[extensions]' >> $HGRCPATH
  $ echo "foobar = $abspath" >> $HGRCPATH

  $ filterlog () {
  >   sed -e 's!^[0-9/]* [0-9:]* ([0-9]*)>!YYYY/MM/DD HH:MM:SS (PID)>!'
  > }

Test extension setup timings

  $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1 | filterlog
  YYYY/MM/DD HH:MM:SS (PID)> loading extensions
  YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
  YYYY/MM/DD HH:MM:SS (PID)>   - loading extension: foobar
  YYYY/MM/DD HH:MM:SS (PID)>   > foobar extension loaded in * (glob)
  YYYY/MM/DD HH:MM:SS (PID)>     - validating extension tables: foobar
  YYYY/MM/DD HH:MM:SS (PID)>     - invoking registered callbacks: foobar
  YYYY/MM/DD HH:MM:SS (PID)>     > callbacks completed in * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> > loaded 1 extensions, total time * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
  YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
  YYYY/MM/DD HH:MM:SS (PID)>   - running uisetup for foobar
  uisetup called [debug]
  uisetup called
  uisetup called [status]
  YYYY/MM/DD HH:MM:SS (PID)>   > uisetup for foobar took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
  YYYY/MM/DD HH:MM:SS (PID)>   - running extsetup for foobar
  YYYY/MM/DD HH:MM:SS (PID)>   > extsetup for foobar took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
  YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
  YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> > extension foobar take a total of * to load (glob)
  YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
  YYYY/MM/DD HH:MM:SS (PID)> loading additional extensions
  YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
  YYYY/MM/DD HH:MM:SS (PID)> > loaded 0 extensions, total time * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
  YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
  YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
  YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
  YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
  YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
  YYYY/MM/DD HH:MM:SS (PID)> - executing reposetup hooks
  YYYY/MM/DD HH:MM:SS (PID)>   - running reposetup for foobar
  reposetup called for a
  ui == repo.ui
  YYYY/MM/DD HH:MM:SS (PID)>   > reposetup for foobar took * (glob)
  YYYY/MM/DD HH:MM:SS (PID)> > all reposetup took * (glob)
  Foo

  $ cd ..

  $ echo 'foobar = !' >> $HGRCPATH