2010-09-26 22:44:49 +04:00
|
|
|
test --time
|
|
|
|
|
2012-06-12 16:18:18 +04:00
|
|
|
$ hg --time help -q help 2>&1 | grep time > /dev/null
|
2010-09-26 22:44:49 +04:00
|
|
|
$ hg init a
|
|
|
|
$ cd a
|
|
|
|
|
2017-07-31 22:43:26 +03:00
|
|
|
Function to check that statprof ran
|
|
|
|
$ statprofran () {
|
|
|
|
> egrep 'Sample count:|No samples recorded' > /dev/null
|
|
|
|
> }
|
2012-06-10 15:01:40 +04:00
|
|
|
|
2010-09-26 22:44:49 +04:00
|
|
|
test --profile
|
|
|
|
|
2017-07-31 22:43:26 +03:00
|
|
|
$ hg st --profile 2>&1 | statprofran
|
2017-06-09 14:36:07 +03:00
|
|
|
|
|
|
|
Abreviated version
|
|
|
|
|
2017-07-31 22:43:26 +03:00
|
|
|
$ hg st --prof 2>&1 | statprofran
|
2017-06-09 14:36:07 +03:00
|
|
|
|
|
|
|
In alias
|
|
|
|
|
2017-07-31 22:43:26 +03:00
|
|
|
$ hg --config "alias.profst=status --profile" profst 2>&1 | statprofran
|
2017-06-09 14:36:07 +03:00
|
|
|
|
|
|
|
#if lsprof
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ prof='hg --config profiling.type=ls --profile'
|
|
|
|
|
|
|
|
$ $prof st 2>../out
|
2012-06-10 15:01:40 +04:00
|
|
|
$ grep CallCount ../out > /dev/null || cat ../out
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof --config profiling.output=../out st
|
2012-06-10 15:01:40 +04:00
|
|
|
$ grep CallCount ../out > /dev/null || cat ../out
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof --config profiling.output=blackbox --config extensions.blackbox= st
|
2015-09-08 21:39:52 +03:00
|
|
|
$ grep CallCount .hg/blackbox.log > /dev/null || cat .hg/blackbox.log
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof --config profiling.format=text st 2>../out
|
2012-06-10 15:01:40 +04:00
|
|
|
$ grep CallCount ../out > /dev/null || cat ../out
|
|
|
|
|
|
|
|
$ echo "[profiling]" >> $HGRCPATH
|
|
|
|
$ echo "format=kcachegrind" >> $HGRCPATH
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof st 2>../out
|
2012-06-10 15:01:40 +04:00
|
|
|
$ grep 'events: Ticks' ../out > /dev/null || cat ../out
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof --config profiling.output=../out st
|
2012-06-10 15:01:40 +04:00
|
|
|
$ grep 'events: Ticks' ../out > /dev/null || cat ../out
|
|
|
|
|
2016-08-15 04:37:24 +03:00
|
|
|
#endif
|
|
|
|
|
|
|
|
#if lsprof serve
|
|
|
|
|
|
|
|
Profiling of HTTP requests works
|
|
|
|
|
2016-08-17 18:52:15 +03:00
|
|
|
$ $prof --config profiling.format=text --config profiling.output=../profile.log serve -d -p $HGPORT --pid-file ../hg.pid -A ../access.log
|
2016-08-15 04:37:24 +03:00
|
|
|
$ 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)
|
|
|
|
|
2012-06-10 15:01:40 +04:00
|
|
|
#endif
|
2012-06-11 03:40:51 +04:00
|
|
|
|
2016-11-05 06:50:38 +03:00
|
|
|
Install an extension that can sleep and guarantee a profiler has time to run
|
|
|
|
|
|
|
|
$ cat >> sleepext.py << EOF
|
|
|
|
> import time
|
2016-01-09 17:07:20 +03:00
|
|
|
> from mercurial import registrar, commands
|
2016-11-05 06:50:38 +03:00
|
|
|
> cmdtable = {}
|
2016-01-09 17:07:20 +03:00
|
|
|
> command = registrar.command(cmdtable)
|
2017-06-25 05:50:05 +03:00
|
|
|
> @command(b'sleep', [], 'hg sleep')
|
2016-11-05 06:50:38 +03:00
|
|
|
> def sleep(ui, *args, **kwargs):
|
|
|
|
> time.sleep(0.1)
|
|
|
|
> EOF
|
|
|
|
|
|
|
|
$ cat >> $HGRCPATH << EOF
|
|
|
|
> [extensions]
|
|
|
|
> sleep = `pwd`/sleepext.py
|
|
|
|
> EOF
|
|
|
|
|
|
|
|
statistical profiler works
|
|
|
|
|
2016-11-05 07:44:25 +03:00
|
|
|
$ hg --profile sleep 2>../out
|
2017-07-31 22:43:26 +03:00
|
|
|
$ cat ../out | statprofran
|
2016-11-05 06:50:38 +03:00
|
|
|
|
|
|
|
Various statprof formatters work
|
|
|
|
|
2016-11-05 07:44:25 +03:00
|
|
|
$ hg --profile --config profiling.statformat=byline sleep 2>../out
|
2016-11-05 06:50:38 +03:00
|
|
|
$ head -n 1 ../out
|
|
|
|
% cumulative self
|
2017-07-31 22:43:26 +03:00
|
|
|
$ cat ../out | statprofran
|
2016-11-05 06:50:38 +03:00
|
|
|
|
2016-11-05 07:44:25 +03:00
|
|
|
$ hg --profile --config profiling.statformat=bymethod sleep 2>../out
|
2016-11-05 06:50:38 +03:00
|
|
|
$ head -n 1 ../out
|
|
|
|
% cumulative self
|
2017-07-31 22:43:26 +03:00
|
|
|
$ cat ../out | statprofran
|
2016-11-05 06:50:38 +03:00
|
|
|
|
2016-11-05 07:44:25 +03:00
|
|
|
$ hg --profile --config profiling.statformat=hotpath sleep 2>../out
|
2017-07-31 22:43:26 +03:00
|
|
|
$ cat ../out | statprofran
|
2016-11-05 06:50:38 +03:00
|
|
|
|
2016-11-05 07:44:25 +03:00
|
|
|
$ hg --profile --config profiling.statformat=json sleep 2>../out
|
2016-11-05 06:50:38 +03:00
|
|
|
$ cat ../out
|
2017-04-20 16:45:45 +03:00
|
|
|
\[\[-?\d+.* (re)
|
2016-11-05 06:50:38 +03:00
|
|
|
|
2018-02-02 23:17:46 +03:00
|
|
|
#if normal-layout
|
2017-01-19 09:45:07 +03:00
|
|
|
statprof can be used as a standalone module
|
|
|
|
|
|
|
|
$ $PYTHON -m mercurial.statprof hotpath
|
|
|
|
must specify --file to load
|
|
|
|
[1]
|
2018-02-02 23:17:46 +03:00
|
|
|
#endif
|
2017-01-19 09:45:07 +03:00
|
|
|
|
2012-06-11 03:40:51 +04:00
|
|
|
$ cd ..
|
2017-05-22 11:17:49 +03:00
|
|
|
|
2017-10-03 05:10:32 +03:00
|
|
|
#if no-chg
|
2017-05-22 11:17:49 +03:00
|
|
|
profiler extension could be loaded before other extensions
|
|
|
|
|
|
|
|
$ cat > fooprof.py <<EOF
|
|
|
|
> from __future__ import absolute_import
|
|
|
|
> import contextlib
|
|
|
|
> @contextlib.contextmanager
|
|
|
|
> def profile(ui, fp):
|
|
|
|
> print('fooprof: start profile')
|
|
|
|
> yield
|
|
|
|
> print('fooprof: end profile')
|
|
|
|
> def extsetup(ui):
|
|
|
|
> ui.write('fooprof: loaded\n')
|
|
|
|
> EOF
|
|
|
|
|
|
|
|
$ cat > otherextension.py <<EOF
|
|
|
|
> from __future__ import absolute_import
|
|
|
|
> def extsetup(ui):
|
|
|
|
> ui.write('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
|
2017-12-11 06:50:57 +03:00
|
|
|
$TESTTMP/b
|
2017-05-22 11:17:49 +03:00
|
|
|
$ HGPROF=fooprof hg root --profile
|
|
|
|
fooprof: loaded
|
|
|
|
fooprof: start profile
|
|
|
|
otherextension: loaded
|
2017-12-11 06:50:57 +03:00
|
|
|
$TESTTMP/b
|
2017-05-22 11:17:49 +03:00
|
|
|
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 ..
|
2017-10-03 05:10:32 +03:00
|
|
|
#endif
|