tests/test-profile.t
author Boris Feld <boris.feld@octobus.net>
Thu, 05 Oct 2017 15:25:18 +0200
changeset 34852 d45236f3d38e
parent 34445 5b19f0442043
child 35393 4441705b7111
permissions -rw-r--r--
log: add obsfate by default in changeset printer Having an obsfate by default in log will be useful for users to understand why they have obsolete and unstable changesets. Obsfate will only be shown for obsolete changesets, which only happens if people opt-in to experimental feature. But when obsolete changeset are visible, it is very useful to understand where they are. Having it in log could be sufficient for most people, so they don't have to learn a new command (like obslog which is itself useful in case of divergences). For example, when pulling and working directory parent become obsolete: $ hg pull ... working directory parent is obsolete! (f936c1697205) This message comes from the Evolve extension. Obsfate would comes handy: $ hg log -G o changeset: 2:6f91013c5136 | tag: tip | parent: 0:4ef7b558f3ec | user: Boris Feld <boris.feld@octobus.net> | date: Mon Oct 09 16:00:27 2017 +0200 | summary: A | | @ changeset: 1:f936c1697205 |/ user: Boris Feld <boris.feld@octobus.net> | date: Mon Oct 09 16:00:27 2017 +0200 | obsfate: rewritten using amend as 2:6f91013c5136 | summary: -A | o changeset: 0:feb4dd822b8c user: Boris Feld <boris.feld@octobus.net> date: Tue Oct 09 16:00:00 2017 +0200 summary: ROOT And once we update, we don't have an obsolete changeset in the log anymore so we don't show obsfate anymore, most users won't see obsfate often if they don't have obsolete changeset often: @ changeset: 2:6f91013c5136 | tag: tip | parent: 0:4ef7b558f3ec | user: Boris Feld <boris.feld@octobus.net> | date: Mon Oct 09 16:00:27 2017 +0200 | summary: A | o changeset: 0:feb4dd822b8c user: Boris Feld <boris.feld@octobus.net> date: Tue Oct 09 16:00:00 2017 +0200 summary: ROOT

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, commands
  > cmdtable = {}
  > command = registrar.command(cmdtable)
  > @command(b'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
  $ cat ../out | statprofran

Various statprof formatters work

  $ hg --profile --config profiling.statformat=byline sleep 2>../out
  $ head -n 1 ../out
    %   cumulative      self          
  $ cat ../out | statprofran

  $ hg --profile --config profiling.statformat=bymethod sleep 2>../out
  $ head -n 1 ../out
    %   cumulative      self          
  $ cat ../out | statprofran

  $ hg --profile --config profiling.statformat=hotpath sleep 2>../out
  $ cat ../out | statprofran

  $ hg --profile --config profiling.statformat=json sleep 2>../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
  > @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
  $TESTTMP/b (glob)
  $ HGPROF=fooprof hg root --profile
  fooprof: loaded
  fooprof: start profile
  otherextension: loaded
  $TESTTMP/b (glob)
  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