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 () { > grep -E '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 serve Profiling of HTTP requests works $ stats_prof () { > hg --config profiling.type=stat --profile $@ > } $ stats_prof \ > --config profiling.format=text \ > --config profiling.output=../profile.log \ > serve -d \ > -p $HGPORT \ > --pid-file ../hg.pid \ > -A ../access.log \ > --errorlog ../error.log $ cat ../hg.pid >> $DAEMON_PIDS $ hg -q clone -U http://localhost:$HGPORT ../clone $ cat ../error.log A single profile is logged because file logging doesn't append $ grep 'Sample count:' ../profile.log | wc -l \s*1 (re) $ grep 'Total time:' ../profile.log | wc -l \s*1 (re) #endif Install an extension that can sleep and guarantee a profiler has time to run $ cat >> sleepext_with_a_long_filename.py << EOF > import time > from mercurial import registrar > cmdtable = {} > command = registrar.command(cmdtable) > @command(b'sleep', [], b'hg sleep') > def sleep_for_at_least_one_stat_cycle(ui, *args, **kwargs): > t = time.time() # don't use time.sleep because we need CPU time > while time.time() - t < 0.5: > pass > EOF $ cat >> $HGRCPATH << EOF > [extensions] > sleep = `pwd`/sleepext_with_a_long_filename.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_with_a_long_filename.py:*:sleep_for_at_least_one_stat_cycle (glob) $ cat ../out | statprofran $ hg --profile --config profiling.statformat=bymethod sleep 2>../out || cat ../out $ head -n 1 ../out % cumulative self $ cat ../out | statprofran Windows real time tracking is broken, only use CPU #if no-windows $ hg --profile --config profiling.time-track=real --config profiling.statformat=hotpath sleep 2>../out || cat ../out $ cat ../out | statprofran $ grep sleepext_with_a_long_filename.py ../out | head -n 1 .* [0-9.]+% [0-9.]+s sleepext_with_a_long_filename.py:\s*sleep_for_at_least_one_stat_cycle, line \d+:\s+(while|pass).* (re) #endif $ hg --profile --config profiling.time-track=cpu --config profiling.statformat=hotpath sleep 2>../out || cat ../out $ cat ../out | statprofran $ grep sleepext_with_a_long_filename.py ../out | head -n 1 .* [0-9.]+% [0-9.]+s sleepext_with_a_long_filename.py:\s*sleep_for_at_least_one_stat_cycle, line \d+:\s+(while|pass).* (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 < 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 < def extsetup(ui): > ui.write(b'otherextension: loaded\n') > EOF $ hg init b $ cd b $ cat >> .hg/hgrc < [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