tests/test-progress.t
author Brodie Rao <brodie@sf.io>
Mon, 16 Sep 2013 01:08:29 -0700
changeset 20192 38fad5e76ee8
parent 19619 4694ccd5d994
child 21254 51e5c793a9f4
permissions -rw-r--r--
branches: simplify with repo.branchmap().iterbranches() Running hg branches on the PyPy repo (with 996) over a busy NFS server, before this change: $ time hg --profile branches > /dev/null CallCount Recursive Total(s) Inline(s) module:lineno(function) 1069 0 1.2955 1.2955 <open> 1063 0 0.5576 0.5576 <method 'close' of 'file' objects> 4122 0 0.1993 0.0449 mercurial.repoview:161(changelog) 8240 0 0.0771 0.0299 mercurial.changelog:133(tip) 4122 0 0.0422 0.0204 mercurial.localrepo:26(__get__) 8240 0 0.0252 0.0131 <len> 4122 0 0.0060 0.0037 mercurial.repoview:112(filterrevs) 8240 0 0.0028 0.0028 <hash> 3029 0 0.2139 0.0390 mercurial.context:202(__init__) 3029 0 0.1402 0.0339 mercurial.repoview:161(changelog) 3029 0 0.0240 0.0087 mercurial.changelog:183(rev) 9087 0 0.0067 0.0067 <isinstance> 1096 0 0.0025 0.0025 <binascii.unhexlify> 4125 0 0.0015 0.0015 <len> 4229 0 0.0344 0.0344 mercurial.revlog:296(rev) 1061 0 0.0343 0.0343 <method 'seek' of 'file' objects> 1063 0 0.0339 0.0339 <method 'read' of 'file' objects> 40476 16488 0.0479 0.0311 <len> 16488 0 0.0216 0.0168 mercurial.revlog:262(__len__) 8240 0 0.0771 0.0299 mercurial.changelog:133(tip) 8240 0 0.0281 0.0203 mercurial.changelog:190(node) 8240 0 0.0191 0.0095 <len> 1342 0 0.0278 0.0278 <zlib.decompress> 1074 0 2.2143 0.0266 mercurial.changelog:270(read) 1074 0 2.1328 0.0230 mercurial.revlog:907(revision) 1073 0 0.0208 0.0108 mercurial.changelog:28(decodeextra) 2148 0 0.0072 0.0072 <method 'split' of 'str' objects> 2148 0 0.0211 0.0038 mercurial.encoding:61(tolocal) 1074 0 0.0028 0.0028 <method 'index' of 'str' objects> 1061 0 1.9811 0.0237 mercurial.revlog:817(_loadchunk) real 0m2.742s user 0m0.811s sys 0m0.188s After this change: $ time hg --profile branches > /dev/null CallCount Recursive Total(s) Inline(s) module:lineno(function) 2092 0 0.1444 0.0292 mercurial.context:202(__init__) 2092 0 0.0908 0.0216 mercurial.repoview:161(changelog) 2092 0 0.0164 0.0057 mercurial.changelog:183(rev) 6276 0 0.0045 0.0045 <isinstance> 1096 0 0.0024 0.0024 <binascii.unhexlify> 3188 0 0.0013 0.0013 <len> 2218 0 0.0230 0.0230 mercurial.revlog:296(rev) 2111 0 0.1028 0.0218 mercurial.repoview:161(changelog) 4218 0 0.0387 0.0146 mercurial.changelog:133(tip) 2111 0 0.0238 0.0104 mercurial.localrepo:26(__get__) 4218 0 0.0122 0.0062 <len> 2111 0 0.0038 0.0021 mercurial.repoview:112(filterrevs) 4218 0 0.0014 0.0014 <hash> 20240 8444 0.0233 0.0149 <len> 8444 0 0.0110 0.0084 mercurial.revlog:262(__len__) 4218 0 0.0387 0.0146 mercurial.changelog:133(tip) 4218 0 0.0144 0.0103 mercurial.changelog:190(node) 4218 0 0.0097 0.0048 <len> 2398 1 0.0271 0.0115 mercurial.localrepo:26(__get__) 2398 1 0.0146 0.0046 mercurial.scmutil:939(__get__) 2124 0 0.0009 0.0009 mercurial.localrepo:330(unfiltered) 274 0 0.0002 0.0002 mercurial.repoview:192(unfiltered) 4 0 0.1409 0.0112 mercurial.branchmap:19(read) 1096 0 0.1113 0.0028 mercurial.localrepo:407(__contains__) 1098 0 0.0020 0.0020 <method 'split' of 'str' objects> 1097 0 0.0019 0.0019 <binascii.unhexlify> 1096 0 0.0093 0.0018 mercurial.encoding:61(tolocal) 1096 0 0.0010 0.0010 <method 'append' of 'list' objects> 4349 0 0.0150 0.0105 mercurial.changelog:190(node) 4349 0 0.0045 0.0045 mercurial.revlog:317(node) real 0m0.362s user 0m0.329s sys 0m0.024s


  $ cat > loop.py <<EOF
  > from mercurial import commands
  > import time
  > class incrementingtime(object):
  >     def __init__(self):
  >         self._time = 0.0
  >     def __call__(self):
  >         self._time += 0.25
  >         return self._time
  > time.time = incrementingtime()
  > 
  > 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)
  > 
  >     for i in range(loops):
  >         ui.progress('loop', i, 'loop.%d' % i, 'loopnum', total)
  >         if opts.get('parallel'):
  >             ui.progress('other', i, 'other.%d' % i, 'othernum', total)
  >         if nested:
  >             nested_steps = 2
  >             if i and i % 4 == 0:
  >                 nested_steps = 5
  >             for j in range(nested_steps):
  >                 ui.progress(
  >                   'nested', j, 'nested.%d' % j, 'nestnum', nested_steps)
  >             ui.progress(
  >               'nested', None, 'nested.done', 'nestnum', nested_steps)
  >     ui.progress('loop', None, 'loop.done', 'loopnum', total)
  > 
  > commands.norepo += " loop"
  > 
  > cmdtable = {
  >     "loop": (loop, [('', 'total', '', 'override for total'),
  >                     ('', 'nested', False, 'show nested results'),
  >                     ('', 'parallel', False, 'show parallel sets of results'),
  >                    ],
  >              'hg loop LOOPS'),
  > }
  > 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)


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

  $ cat > mocktime.py <<EOF
  > import os
  > import time
  > 
  > class mocktime(object):
  >     def __init__(self, increment):
  >         self.time = 0
  >         self.increment = increment
  >     def __call__(self):
  >         self.time += self.increment
  >         return self.time
  > 
  > def uisetup(ui):
  >     time.time = mocktime(int(os.environ.get('MOCKTIME', '11')))
  > EOF

  $ cp $HGRCPATH.orig $HGRCPATH
  $ echo "[extensions]" >> $HGRCPATH
  $ echo "mocktime=`pwd`/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

  $ 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)

Time estimates should not fail when there's no end point:
  $ hg -y loop -- -4
  \r (no-eol) (esc)
  loop [ <=>                                              ] 2\r (no-eol) (esc)
  loop [  <=>                                             ] 3\r (no-eol) (esc)
                                                              \r (no-eol) (esc)