view tests/test-progress.t @ 35428:71427ff1dff8

workers: handling exceptions in windows workers This adds handling of exceptions from worker threads and resurfaces them as if the function ran without workers. If any of the threads throws, the main thread kills all running threads giving them 5 sec to handle the interruption and raises the first exception received. We don't have to join threads if is_alive() is false Test Plan: Ran multiple updates/enable/disable sparse profile and things worked well Ran test on CentOS- all tests passing on @ passed here Added a forged exception into the worker code and got it properly resurfaced and the rest of workers killed: P58642088 PS C:\open\<repo>> ..\facebook-hg-rpms\build\hg\hg.exe --config extensions.fsmonitor=! sparse --enable-profile <profile> updating [==> ] 1300/39166 1m57sException in thread Thread-3: Traceback (most recent call last): File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\threading.py", line 801, in __bootstrap_inner self.run() File "C:\open\facebook-hg-rpms\build\hg\mercurial\worker.py", line 244, in run raise e Exception: Forged exception Exception in thread Thread-2: Traceback (most recent call last): File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\threading.py", line 801, in __bootstrap_inner self.run() File "C:\open\facebook-hg-rpms\build\hg\mercurial\worker.py", line 244, in run raise e Exception: Forged exception <...> Traceback (most recent call last): File "C:\open\facebook-hg-rpms\build\hg\hgexe.py", line 41, in <module> dispatch.run() File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 85, in run status = (dispatch(req) or 0) & 255 File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 173, in dispatch ret = _runcatch(req) File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 324, in _runcatch return _callcatch(ui, _runcatchfunc) File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 332, in _callcatch return scmutil.callcatch(ui, func) File "C:\open\facebook-hg-rpms\build\hg\mercurial\scmutil.py", line 154, in callcatch return func() File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 314, in _runcatchfunc return _dispatch(req) File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 951, in _dispatch cmdpats, cmdoptions) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\remotefilelog\__init__.py", line 415, in runcommand return orig(lui, repo, *args, **kwargs) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\undo.py", line 118, in _runcommandwrapper result = orig(lui, repo, cmd, fullargs, *args) File "C:\open\facebook-hg-rpms\build\hg\hgext\journal.py", line 84, in runcommand return orig(lui, repo, cmd, fullargs, *args) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\perftweaks.py", line 268, in _tracksparseprofiles res = runcommand(lui, repo, *args) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\perftweaks.py", line 256, in _trackdirstatesizes res = runcommand(lui, repo, *args) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\copytrace.py", line 144, in _runcommand return orig(lui, repo, cmd, fullargs, ui, *args, **kwargs) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\fbamend\hiddenoverride.py", line 119, in runcommand result = orig(lui, repo, cmd, fullargs, *args) File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 712, in runcommand ret = _runcommand(ui, options, cmd, d) File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 959, in _runcommand return cmdfunc() File "C:\open\facebook-hg-rpms\build\hg\mercurial\dispatch.py", line 948, in <lambda> d = lambda: util.checksignature(func)(ui, *args, **strcmdopt) File "C:\open\facebook-hg-rpms\build\hg\mercurial\util.py", line 1183, in check return func(*args, **kwargs) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\fbsparse.py", line 860, in sparse disableprofile=disableprofile, force=force) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\fbsparse.py", line 949, in _config len, _refresh(ui, repo, oldstatus, oldsparsematch, force)) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\hgext3rd\fbsparse.py", line 1116, in _refresh mergemod.applyupdates(repo, typeactions, repo[None], repo['.'], False) File "C:\open\facebook-hg-rpms\build\hg\hg-python\lib\site-packages\remotefilelog\__init__.py", line 311, in applyupdates return orig(repo, actions, wctx, mctx, overwrite, labels=labels) File "C:\open\facebook-hg-rpms\build\hg\mercurial\merge.py", line 1464, in applyupdates for i, item in prog: File "C:\open\facebook-hg-rpms\build\hg\mercurial\worker.py", line 286, in _windowsworker raise t.exception Exception: Forged exception PS C:\open\ovrsource> Differential Revision: https://phab.mercurial-scm.org/D1459
author Wojciech Lis <wlis@fb.com>
date Mon, 20 Nov 2017 10:27:41 -0800
parents 12b355964de8
children 34592dd3bfa2
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',
  >     [('', 'total', '', 'override for total'),
  >     ('', 'nested', False, 'show nested results'),
  >     ('', 'parallel', False, 'show parallel sets of results')],
  >     '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)
  > 
  >     for i in range(loops):
  >         ui.progress(topiclabel, i, getloopitem(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(topiclabel, None, 'loop.done', 'loopnum', total)
  > 
  > 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)