Mercurial > hg
view tests/test-progress.t @ 38732:be4984261611
merge: mark file gets as not thread safe (issue5933)
In default installs, this has the effect of disabling the thread-based
worker on Windows when manifesting files in the working directory. My
measurements have shown that with revlog-based repositories, Mercurial
spends a lot of CPU time in revlog code resolving file data. This ends
up incurring a lot of context switching across threads and slows down
`hg update` operations when going from an empty working directory to
the tip of the repo.
On mozilla-unified (246,351 files) on an i7-6700K (4+4 CPUs):
before: 487s wall
after: 360s wall (equivalent to worker.enabled=false)
cpus=2: 379s wall
Even with only 2 threads, the thread pool is still slower.
The introduction of the thread-based worker (02b36e860e0b) states that
it resulted in a "~50%" speedup for `hg sparse --enable-profile` and
`hg sparse --disable-profile`. This disagrees with my measurement
above. I theorize a few reasons for this:
1) Removal of files from the working directory is I/O - not CPU - bound
and should benefit from a thread pool (unless I/O is insanely fast
and the GIL release is near instantaneous). So tests like `hg sparse
--enable-profile` may exercise deletion throughput and aren't good
benchmarks for worker tasks that are CPU heavy.
2) The patch was authored by someone at Facebook. The results were
likely measured against a repository using remotefilelog. And I
believe that revision retrieval during working directory updates with
remotefilelog will often use a remote store, thus being I/O and not
CPU bound. This probably resulted in an overstated performance gain.
Since there appears to be a need to enable the thread-based worker with
some stores, I've made the flagging of file gets as thread safe
configurable. I've made it experimental because I don't want to formalize
a boolean flag for this option and because this attribute is best
captured against the store implementation. But we don't have a proper
store API for this yet. I'd rather cross this bridge later.
It is possible there are revlog-based repositories that do benefit from
a thread-based worker. I didn't do very comprehensive testing. If there
are, we may want to devise a more proper algorithm for whether to use
the thread-based worker, including possibly config options to limit the
number of threads to use. But until I see evidence that justifies
complexity, simplicity wins.
Differential Revision: https://phab.mercurial-scm.org/D3963
| author | Gregory Szorc <gregory.szorc@gmail.com> |
|---|---|
| date | Wed, 18 Jul 2018 09:49:34 -0700 |
| parents | 26523316e4d0 |
| children | af5e2b23040a |
line wrap: on
line source
$ cat > loop.py <<EOF > from __future__ import absolute_import > import time > from mercurial import commands, registrar > > cmdtable = {} > command = registrar.command(cmdtable) > > class incrementingtime(object): > def __init__(self): > self._time = 0.0 > def __call__(self): > self._time += 0.25 > return self._time > time.time = incrementingtime() > > @command(b'loop', > [(b'', b'total', b'', b'override for total'), > (b'', b'nested', False, b'show nested results'), > (b'', b'parallel', False, b'show parallel sets of results')], > b'hg loop LOOPS', > norepo=True) > def loop(ui, loops, **opts): > loops = int(loops) > total = None > if loops >= 0: > total = loops > if opts.get('total', None): > total = int(opts.get('total')) > nested = False > if opts.get('nested', None): > nested = True > loops = abs(loops) > > progress = ui.makeprogress(topiclabel, unit='loopnum', total=total) > other = ui.makeprogress('other', unit='othernum', total=total) > for i in range(loops): > progress.update(i, item=getloopitem(i)) > if opts.get('parallel'): > other.update(i, item='other.%d' % i) > if nested: > nested_steps = 2 > if i and i % 4 == 0: > nested_steps = 5 > nested = ui.makeprogress('nested', unit='nestnum', > total=nested_steps) > for j in range(nested_steps): > nested.update(j, item='nested.%d' % j) > nested.complete() > progress.complete() > > topiclabel = 'loop' > def getloopitem(i): > return 'loop.%d' % i > > EOF $ cp $HGRCPATH $HGRCPATH.orig $ echo "[extensions]" >> $HGRCPATH $ echo "progress=" >> $HGRCPATH $ echo "loop=`pwd`/loop.py" >> $HGRCPATH $ echo "[progress]" >> $HGRCPATH $ echo "format = topic bar number" >> $HGRCPATH $ echo "assume-tty=1" >> $HGRCPATH $ echo "width=60" >> $HGRCPATH test default params, display nothing because of delay $ hg -y loop 3 $ echo "delay=0" >> $HGRCPATH $ echo "refresh=0" >> $HGRCPATH test with delay=0, refresh=0 $ hg -y loop 3 \r (no-eol) (esc) loop [ ] 0/3\r (no-eol) (esc) loop [===============> ] 1/3\r (no-eol) (esc) loop [===============================> ] 2/3\r (no-eol) (esc) \r (no-eol) (esc) no progress with --quiet $ hg -y loop 3 --quiet test plain mode exception $ HGPLAINEXCEPT=progress hg -y loop 1 \r (no-eol) (esc) loop [ ] 0/1\r (no-eol) (esc) \r (no-eol) (esc) test nested short-lived topics (which shouldn't display with nestdelay): $ hg -y loop 3 --nested \r (no-eol) (esc) loop [ ] 0/3\r (no-eol) (esc) loop [===============> ] 1/3\r (no-eol) (esc) loop [===============================> ] 2/3\r (no-eol) (esc) \r (no-eol) (esc) Test nested long-lived topic which has the same name as a short-lived peer. We shouldn't get stuck showing the short-lived inner steps, and should go back to skipping the inner steps when the slow nested step finishes. $ hg -y loop 7 --nested \r (no-eol) (esc) loop [ ] 0/7\r (no-eol) (esc) loop [=====> ] 1/7\r (no-eol) (esc) loop [============> ] 2/7\r (no-eol) (esc) loop [===================> ] 3/7\r (no-eol) (esc) loop [==========================> ] 4/7\r (no-eol) (esc) nested [==========================> ] 3/5\r (no-eol) (esc) nested [===================================> ] 4/5\r (no-eol) (esc) loop [=================================> ] 5/7\r (no-eol) (esc) loop [========================================> ] 6/7\r (no-eol) (esc) \r (no-eol) (esc) $ hg --config progress.changedelay=0 -y loop 3 --nested \r (no-eol) (esc) loop [ ] 0/3\r (no-eol) (esc) nested [ ] 0/2\r (no-eol) (esc) nested [======================> ] 1/2\r (no-eol) (esc) loop [===============> ] 1/3\r (no-eol) (esc) nested [ ] 0/2\r (no-eol) (esc) nested [======================> ] 1/2\r (no-eol) (esc) loop [===============================> ] 2/3\r (no-eol) (esc) nested [ ] 0/2\r (no-eol) (esc) nested [======================> ] 1/2\r (no-eol) (esc) \r (no-eol) (esc) test two topics being printed in parallel (as when we're doing a local --pull clone, where you get the unbundle and bundle progress at the same time): $ hg loop 3 --parallel \r (no-eol) (esc) loop [ ] 0/3\r (no-eol) (esc) loop [===============> ] 1/3\r (no-eol) (esc) loop [===============================> ] 2/3\r (no-eol) (esc) \r (no-eol) (esc) test refresh is taken in account $ hg -y --config progress.refresh=100 loop 3 test format options 1 $ hg -y --config 'progress.format=number topic item+2' loop 2 \r (no-eol) (esc) 0/2 loop lo\r (no-eol) (esc) 1/2 loop lo\r (no-eol) (esc) \r (no-eol) (esc) test format options 2 $ hg -y --config 'progress.format=number item-3 bar' loop 2 \r (no-eol) (esc) 0/2 p.0 [ ]\r (no-eol) (esc) 1/2 p.1 [=======================> ]\r (no-eol) (esc) \r (no-eol) (esc) test format options and indeterminate progress $ hg -y --config 'progress.format=number item bar' loop -- -2 \r (no-eol) (esc) 0 loop.0 [ <=> ]\r (no-eol) (esc) 1 loop.1 [ <=> ]\r (no-eol) (esc) \r (no-eol) (esc) make sure things don't fall over if count > total $ hg -y loop --total 4 6 \r (no-eol) (esc) loop [ ] 0/4\r (no-eol) (esc) loop [===========> ] 1/4\r (no-eol) (esc) loop [=======================> ] 2/4\r (no-eol) (esc) loop [===================================> ] 3/4\r (no-eol) (esc) loop [===============================================>] 4/4\r (no-eol) (esc) loop [ <=> ] 5/4\r (no-eol) (esc) \r (no-eol) (esc) test immediate progress completion $ hg -y loop 0 test delay time estimates #if no-chg $ cp $HGRCPATH.orig $HGRCPATH $ echo "[extensions]" >> $HGRCPATH $ echo "mocktime=$TESTDIR/mocktime.py" >> $HGRCPATH $ echo "progress=" >> $HGRCPATH $ echo "loop=`pwd`/loop.py" >> $HGRCPATH $ echo "[progress]" >> $HGRCPATH $ echo "assume-tty=1" >> $HGRCPATH $ echo "delay=25" >> $HGRCPATH $ echo "width=60" >> $HGRCPATH $ MOCKTIME=11 hg -y loop 8 \r (no-eol) (esc) loop [=========> ] 2/8 1m07s\r (no-eol) (esc) loop [===============> ] 3/8 56s\r (no-eol) (esc) loop [=====================> ] 4/8 45s\r (no-eol) (esc) loop [==========================> ] 5/8 34s\r (no-eol) (esc) loop [================================> ] 6/8 23s\r (no-eol) (esc) loop [=====================================> ] 7/8 12s\r (no-eol) (esc) \r (no-eol) (esc) $ MOCKTIME=10000 hg -y loop 4 \r (no-eol) (esc) loop [ ] 0/4\r (no-eol) (esc) loop [=========> ] 1/4 8h21m\r (no-eol) (esc) loop [====================> ] 2/4 5h34m\r (no-eol) (esc) loop [==============================> ] 3/4 2h47m\r (no-eol) (esc) \r (no-eol) (esc) $ MOCKTIME=1000000 hg -y loop 4 \r (no-eol) (esc) loop [ ] 0/4\r (no-eol) (esc) loop [=========> ] 1/4 5w00d\r (no-eol) (esc) loop [====================> ] 2/4 3w03d\r (no-eol) (esc) loop [=============================> ] 3/4 11d14h\r (no-eol) (esc) \r (no-eol) (esc) $ MOCKTIME=14000000 hg -y loop 4 \r (no-eol) (esc) loop [ ] 0/4\r (no-eol) (esc) loop [=========> ] 1/4 1y18w\r (no-eol) (esc) loop [===================> ] 2/4 46w03d\r (no-eol) (esc) loop [=============================> ] 3/4 23w02d\r (no-eol) (esc) \r (no-eol) (esc) Non-linear progress: $ MOCKTIME='20 20 20 20 20 20 20 20 20 20 500 500 500 500 500 20 20 20 20 20' hg -y loop 20 \r (no-eol) (esc) loop [=> ] 1/20 6m21s\r (no-eol) (esc) loop [===> ] 2/20 6m01s\r (no-eol) (esc) loop [=====> ] 3/20 5m41s\r (no-eol) (esc) loop [=======> ] 4/20 5m21s\r (no-eol) (esc) loop [=========> ] 5/20 5m01s\r (no-eol) (esc) loop [===========> ] 6/20 4m41s\r (no-eol) (esc) loop [=============> ] 7/20 4m21s\r (no-eol) (esc) loop [===============> ] 8/20 4m01s\r (no-eol) (esc) loop [================> ] 9/20 25m40s\r (no-eol) (esc) loop [===================> ] 10/20 1h06m\r (no-eol) (esc) loop [=====================> ] 11/20 1h13m\r (no-eol) (esc) loop [=======================> ] 12/20 1h07m\r (no-eol) (esc) loop [========================> ] 13/20 58m19s\r (no-eol) (esc) loop [===========================> ] 14/20 7m09s\r (no-eol) (esc) loop [=============================> ] 15/20 3m38s\r (no-eol) (esc) loop [===============================> ] 16/20 2m15s\r (no-eol) (esc) loop [=================================> ] 17/20 1m27s\r (no-eol) (esc) loop [====================================> ] 18/20 52s\r (no-eol) (esc) loop [======================================> ] 19/20 25s\r (no-eol) (esc) \r (no-eol) (esc) Time estimates should not fail when there's no end point: $ MOCKTIME=11 hg -y loop -- -4 \r (no-eol) (esc) loop [ <=> ] 2\r (no-eol) (esc) loop [ <=> ] 3\r (no-eol) (esc) \r (no-eol) (esc) #endif test line trimming by '[progress] width', when progress topic contains multi-byte characters, of which length of byte sequence and columns in display are different from each other. $ cp $HGRCPATH.orig $HGRCPATH $ cat >> $HGRCPATH <<EOF > [extensions] > progress= > loop=`pwd`/loop.py > [progress] > assume-tty = 1 > delay = 0 > refresh = 0 > EOF $ rm -f loop.pyc $ cat >> loop.py <<EOF > # use non-ascii characters as topic label of progress > # 2 x 4 = 8 columns, but 3 x 4 = 12 bytes > topiclabel = u'\u3042\u3044\u3046\u3048'.encode('utf-8') > EOF $ cat >> $HGRCPATH <<EOF > [progress] > format = topic number > width= 12 > EOF $ hg --encoding utf-8 -y loop --total 3 3 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 0/3\r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 1/3\r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 2/3\r (no-eol) (esc) \r (no-eol) (esc) test calculation of bar width, when progress topic contains multi-byte characters, of which length of byte sequence and columns in display are different from each other. $ cat >> $HGRCPATH <<EOF > [progress] > format = topic bar > width= 21 > # progwidth should be 9 (= 21 - (8+1) - 3) > EOF $ hg --encoding utf-8 -y loop --total 3 3 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [ ]\r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [==> ]\r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [=====> ]\r (no-eol) (esc) \r (no-eol) (esc) test trimming progress items, when they contain multi-byte characters, of which length of byte sequence and columns in display are different from each other. $ rm -f loop.pyc $ rm -Rf __pycache__ $ cat >> loop.py <<EOF > # use non-ascii characters as loop items of progress > loopitems = [ > u'\u3042\u3044'.encode('utf-8'), # 2 x 2 = 4 columns > u'\u3042\u3044\u3046'.encode('utf-8'), # 2 x 3 = 6 columns > u'\u3042\u3044\u3046\u3048'.encode('utf-8'), # 2 x 4 = 8 columns > ] > def getloopitem(i): > return loopitems[i % len(loopitems)] > EOF $ cat >> $HGRCPATH <<EOF > [progress] > # trim at tail side > format = item+6 > EOF $ hg --encoding utf-8 -y loop --total 3 3 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc) \r (no-eol) (esc) $ cat >> $HGRCPATH <<EOF > [progress] > # trim at left side > format = item-6 > EOF $ hg --encoding utf-8 -y loop --total 3 3 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84 \r (no-eol) (esc) \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc) \xe3\x81\x84\xe3\x81\x86\xe3\x81\x88\r (no-eol) (esc) \r (no-eol) (esc)