tests/test-extension-timing.t
author Georges Racinet <gracinet@anybox.fr>
Thu, 29 Nov 2018 09:13:13 +0000
changeset 40811 e13ab4acf555
parent 40440 09a37a5d8f5d
child 40996 6f2510b581a0
permissions -rw-r--r--
rust: peek_mut optim for lazy ancestors This is one of the two optimizations that are also present in the Python code: replacing pairs of pop/push on the BinaryHeap by single updates, hence having it under the hood maintain its consistency (sift) only once. On Mozilla central, the measured gain (see details below) is around 7%. Creating the PeekMut object by calling peek_mut() right away instead of peek() first is less efficient (gain is only 4%, stats not included). Our interpretation is that its creation has a cost which is vasted in the cases where it ends by droping the value (Peekmut::pop() just does self.heap.pop() anyway). On the other hand, the immutable peek() is very fast: it's just taking a reference in the underlying vector. The Python version still has another optimization: if parent(current) == current-1, then the heap doesn't need to maintain its consistency, since we already know that it's bigger than all the others in the heap. Rust's BinaryHeap doesn't allow us to mutate its biggest element with no housekeeping, but we tried it anyway, with a copy of the BinaryHeap implementation with a dedicaded added method: it's not worth the technical debt in our opinion (we measured only a further 1.6% improvement). One possible explanation would be that the sift is really fast anyway in that case, whereas it's not in the case of Python, because it's at least partly done in slow Python code. Still it's possible that replacing BinaryHeap by something more dedicated to discrete ordered types could be faster. Measurements on mozilla-central: Three runs of 'hg perfancestors' on the parent changeset: Moyenne des médianes: 0.100587 ! wall 0.100062 comb 0.100000 user 0.100000 sys 0.000000 (best of 98) ! wall 0.135804 comb 0.130000 user 0.130000 sys 0.000000 (max of 98) ! wall 0.102864 comb 0.102755 user 0.099286 sys 0.003469 (avg of 98) ! wall 0.101486 comb 0.110000 user 0.110000 sys 0.000000 (median of 98) ! wall 0.096804 comb 0.090000 user 0.090000 sys 0.000000 (best of 100) ! wall 0.132235 comb 0.130000 user 0.120000 sys 0.010000 (max of 100) ! wall 0.100258 comb 0.100300 user 0.096000 sys 0.004300 (avg of 100) ! wall 0.098384 comb 0.100000 user 0.100000 sys 0.000000 (median of 100) ! wall 0.099925 comb 0.100000 user 0.100000 sys 0.000000 (best of 98) ! wall 0.133518 comb 0.140000 user 0.130000 sys 0.010000 (max of 98) ! wall 0.102381 comb 0.102449 user 0.098265 sys 0.004184 (avg of 98) ! wall 0.101891 comb 0.090000 user 0.090000 sys 0.000000 (median of 98) Mean of the medians: 0.100587 On the present changeset: ! wall 0.091344 comb 0.090000 user 0.090000 sys 0.000000 (best of 100) ! wall 0.122728 comb 0.120000 user 0.110000 sys 0.010000 (max of 100) ! wall 0.093268 comb 0.093300 user 0.089300 sys 0.004000 (avg of 100) ! wall 0.092567 comb 0.100000 user 0.090000 sys 0.010000 (median of 100) ! wall 0.093294 comb 0.080000 user 0.080000 sys 0.000000 (best of 100) ! wall 0.144887 comb 0.150000 user 0.140000 sys 0.010000 (max of 100) ! wall 0.097708 comb 0.097700 user 0.093400 sys 0.004300 (avg of 100) ! wall 0.094980 comb 0.100000 user 0.090000 sys 0.010000 (median of 100) ! wall 0.091262 comb 0.090000 user 0.080000 sys 0.010000 (best of 100) ! wall 0.123772 comb 0.130000 user 0.120000 sys 0.010000 (max of 100) ! wall 0.093188 comb 0.093200 user 0.089300 sys 0.003900 (avg of 100) ! wall 0.092364 comb 0.100000 user 0.090000 sys 0.010000 (median of 100) Mean of the medians is 0.0933 Differential Revision: https://phab.mercurial-scm.org/D5358

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

Test extension setup timings

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

  $ cd ..

  $ echo 'foobar = !' >> $HGRCPATH