mirror of
https://github.com/facebook/sapling.git
synced 2024-10-07 15:27:13 +03:00
d1e86f5ae3
The statprof sampling profiler runs with significantly less overhead. Its data is therefore more useful. Furthermore, its default output shows the hotpath by default, which I've found to be way more useful than the default profiler's function time table. There is one behavioral regression with this change worth noting: the statprof profiler currently doesn't profile individual hgweb requests like lsprof does. This is because the current implementation of statprof only profiles the thread that started profiling. The ability for lsprof to profile individual hgweb requests is relatively new and likely not widely used. Furthermore, I have plans to modify statprof to support profiling multiple threads. I expect that change to go through several iterations. I'm submitting this patch first so there is more time to test statprof. Perfect is the enemy of good.
96 lines
2.4 KiB
Turing
96 lines
2.4 KiB
Turing
test --time
|
|
|
|
$ hg --time help -q help 2>&1 | grep time > /dev/null
|
|
$ hg init a
|
|
$ cd a
|
|
|
|
#if lsprof
|
|
|
|
test --profile
|
|
|
|
$ 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 cmdutil, commands
|
|
> cmdtable = {}
|
|
> command = cmdutil.command(cmdtable)
|
|
> @command('sleep', [], '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
|
|
$ grep Sample ../out
|
|
Sample count: \d+ (re)
|
|
|
|
Various statprof formatters work
|
|
|
|
$ hg --profile --config profiling.statformat=byline sleep 2>../out
|
|
$ head -n 1 ../out
|
|
% cumulative self
|
|
$ grep Sample ../out
|
|
Sample count: \d+ (re)
|
|
|
|
$ hg --profile --config profiling.statformat=bymethod sleep 2>../out
|
|
$ head -n 1 ../out
|
|
% cumulative self
|
|
$ grep Sample ../out
|
|
Sample count: \d+ (re)
|
|
|
|
$ hg --profile --config profiling.statformat=hotpath sleep 2>../out
|
|
$ grep Sample ../out
|
|
Sample count: \d+ (re)
|
|
|
|
$ hg --profile --config profiling.statformat=json sleep 2>../out
|
|
$ cat ../out
|
|
\[\[\d+.* (re)
|
|
|
|
$ cd ..
|