Mercurial > hg
view tests/test-profile.t @ 46017:068307b638f4
statprof: fix off-by-one-line error in output
martinvonz claims they thought that this was intentional, but couldn't remember
the reasoning for it. I can't understand why it would be preferable, and I
didn't see anything in the comments in the file about why this would be useful,
so I'm hopefully not breaking anything by "fixing" it.
### Old output
```
| 100.0% 0.01s dispatch.py: run line 43: dispatch.run()
| 100.0% 0.01s dispatch.py: dispatch line 115: status = dispatch(req)
| 100.0% 0.01s dispatch.py: _runcatch line 266: ret = _runcatch(req) or 0
| 100.0% 0.01s dispatch.py: _callcatch line 442: return _callcatch(ui, _runc...
| 100.0% 0.01s scmutil.py: callcatch line 451: return scmutil.callcatch(ui...
| 100.0% 0.01s dispatch.py: _runcatchfunc line 155: return func()
| 100.0% 0.01s dispatch.py: _dispatch line 432: return _dispatch(req)
| 100.0% 0.01s hg.py: repository line 1179: repo = hg.repository(
| 100.0% 0.01s hg.py: _peerorrepo line 221: peer = _peerorrepo(
| 100.0% 0.01s util.py: __getattribute__ line 188: obj = _peerlookup(path).ins...
| 100.0% 0.01s localrepo.py: makelocalrepositoryline 3227: return makelocalrepository(...
| 100.0% 0.01s localrepo.py: __init__ line 683: return cls(
| 100.0% 0.01s util.py: __getattribute__ line 1262: self._extrafilterid = repov...
| 100.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 245: self.__spec__.loader.exec_m...
| 100.0% 0.01s <frozen importlib._bootstrap_external>: get_codeline 779:
| 100.0% 0.01s <frozen importlib._bootstrap_external>: path_statsline 868:
| 100.0% 0.01s <frozen importlib._bootstrap_external>: _path_statline 1012:
```
### New output
```
| 100.0% 0.01s hg: <module> line 43: dispatch.run()
| 100.0% 0.01s dispatch.py: run line 115: status = dispatch(req)
| 100.0% 0.01s dispatch.py: dispatch line 266: ret = _runcatch(req) or 0
| 100.0% 0.01s dispatch.py: _runcatch line 442: return _callcatch(ui, _runc...
| 100.0% 0.01s dispatch.py: _callcatch line 451: return scmutil.callcatch(ui...
| 100.0% 0.01s scmutil.py: callcatch line 155: return func()
| 100.0% 0.01s dispatch.py: _runcatchfunc line 432: return _dispatch(req)
| 100.0% 0.01s dispatch.py: _dispatch line 1179: repo = hg.repository(
| 100.0% 0.01s hg.py: repository line 221: peer = _peerorrepo(
| 100.0% 0.01s hg.py: _peerorrepo line 188: obj = _peerlookup(path).ins...
| 100.0% 0.01s localrepo.py: instance line 3227: return makelocalrepository(...
| 100.0% 0.01s localrepo.py: makelocalrepositoryline 683: return cls(
| 100.0% 0.01s localrepo.py: __init__ line 1262: self._extrafilterid = repov...
| 100.0% 0.01s util.py: __getattribute__ line 245: self.__spec__.loader.exec_m...
| 100.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 779:
| 100.0% 0.01s <frozen importlib._bootstrap_external>: get_codeline 868:
| 100.0% 0.01s <frozen importlib._bootstrap_external>: path_statsline 1012:
| 100.0% 0.01s <frozen importlib._bootstrap_external>: _path_statline 87:
```
Differential Revision: https://phab.mercurial-scm.org/D9510
author | Kyle Lippincott <spectral@google.com> |
---|---|
date | Wed, 02 Dec 2020 15:38:05 -0800 |
parents | ede4a1bf14bd |
children | 8b0a3ff5ed12 |
line wrap: on
line source
test --time $ hg --time help -q help 2>&1 | grep time > /dev/null $ hg init a $ cd a Function to check that statprof ran $ statprofran () { > egrep 'Sample count:|No samples recorded' > /dev/null > } test --profile $ hg st --profile 2>&1 | statprofran Abreviated version $ hg st --prof 2>&1 | statprofran In alias $ hg --config "alias.profst=status --profile" profst 2>&1 | statprofran #if lsprof $ prof='hg --config profiling.type=ls --profile' $ $prof st 2>../out $ grep CallCount ../out > /dev/null || cat ../out $ $prof --config profiling.output=../out st $ grep CallCount ../out > /dev/null || cat ../out $ $prof --config profiling.output=blackbox --config extensions.blackbox= st $ grep CallCount .hg/blackbox.log > /dev/null || cat .hg/blackbox.log $ $prof --config profiling.format=text st 2>../out $ grep CallCount ../out > /dev/null || cat ../out $ echo "[profiling]" >> $HGRCPATH $ echo "format=kcachegrind" >> $HGRCPATH $ $prof st 2>../out $ grep 'events: Ticks' ../out > /dev/null || cat ../out $ $prof --config profiling.output=../out st $ grep 'events: Ticks' ../out > /dev/null || cat ../out #endif #if lsprof serve Profiling of HTTP requests works $ $prof --config profiling.format=text --config profiling.output=../profile.log serve -d -p $HGPORT --pid-file ../hg.pid -A ../access.log $ cat ../hg.pid >> $DAEMON_PIDS $ hg -q clone -U http://localhost:$HGPORT ../clone A single profile is logged because file logging doesn't append $ grep CallCount ../profile.log | wc -l \s*1 (re) #endif Install an extension that can sleep and guarantee a profiler has time to run $ cat >> sleepext.py << EOF > import time > from mercurial import registrar > cmdtable = {} > command = registrar.command(cmdtable) > @command(b'sleep', [], b'hg sleep') > def sleep(ui, *args, **kwargs): > time.sleep(0.1) > EOF $ cat >> $HGRCPATH << EOF > [extensions] > sleep = `pwd`/sleepext.py > EOF statistical profiler works $ hg --profile sleep 2>../out $ cat ../out | statprofran Various statprof formatters work $ hg --profile --config profiling.statformat=byline sleep 2>../out || cat ../out $ grep -v _path_stat ../out | head -n 3 % cumulative self time seconds seconds name * sleepext.py:*:sleep (glob) $ cat ../out | statprofran $ hg --profile --config profiling.statformat=bymethod sleep 2>../out || cat ../out $ head -n 1 ../out % cumulative self $ cat ../out | statprofran $ hg --profile --config profiling.statformat=hotpath sleep 2>../out || cat ../out $ cat ../out | statprofran $ grep sleepext.py ../out .* [0-9.]+% [0-9.]+s sleepext.py:\s*sleep line 7: time\.sleep.* (re) $ hg --profile --config profiling.statformat=json sleep 2>../out || cat ../out $ cat ../out \[\[-?\d+.* (re) statprof can be used as a standalone module $ "$PYTHON" -m mercurial.statprof hotpath must specify --file to load [1] $ cd .. #if no-chg profiler extension could be loaded before other extensions $ cat > fooprof.py <<EOF > from __future__ import absolute_import > import contextlib > import sys > @contextlib.contextmanager > def profile(ui, fp): > print('fooprof: start profile') > sys.stdout.flush() > yield > print('fooprof: end profile') > sys.stdout.flush() > def extsetup(ui): > ui.write(b'fooprof: loaded\n') > EOF $ cat > otherextension.py <<EOF > from __future__ import absolute_import > def extsetup(ui): > ui.write(b'otherextension: loaded\n') > EOF $ hg init b $ cd b $ cat >> .hg/hgrc <<EOF > [extensions] > other = $TESTTMP/otherextension.py > fooprof = $TESTTMP/fooprof.py > EOF $ hg root otherextension: loaded fooprof: loaded $TESTTMP/b $ HGPROF=fooprof hg root --profile fooprof: loaded fooprof: start profile otherextension: loaded $TESTTMP/b fooprof: end profile $ HGPROF=other hg root --profile 2>&1 | head -n 2 otherextension: loaded unrecognized profiler 'other' - ignored $ HGPROF=unknown hg root --profile 2>&1 | head -n 1 unrecognized profiler 'unknown' - ignored $ cd .. #endif