comparison tests/test-logtoprocess.t @ 30976:e92daf156d5c

ui: provide a mechanism to track and log blocked time

We want to log the time Mercurial spends trapped in things outside
programmatic control. Provide a mechanism to give us both command runtime
and as many different sources of blocking as we deem useful.

30975:22fbca1d11ed

  > command = cmdutil.command(cmdtable)
  > @command('foo', [])
  > def foo(ui, repo):
  >     ui.log('foo', 'a message: %(bar)s\n', bar='spam')
  > EOF
  $ cat >> $HGRCPATH << EOF
  > [extensions]
  > logtoprocess=
  > foocommand=$TESTTMP/foocommand.py
  > [logtoprocess]

  foo exited 0 after * seconds (glob)
  logtoprocess command output:
  logtoprocess commandfinish output:
  logtoprocess foo output:
  spam

30976:e92daf156d5c

  > command = cmdutil.command(cmdtable)
  > @command('foo', [])
  > def foo(ui, repo):
  >     ui.log('foo', 'a message: %(bar)s\n', bar='spam')
  > EOF
  $ cp $HGRCPATH $HGRCPATH.bak
  $ cat >> $HGRCPATH << EOF
  > [extensions]
  > logtoprocess=
  > foocommand=$TESTTMP/foocommand.py
  > [logtoprocess]

  foo exited 0 after * seconds (glob)
  logtoprocess command output:
  logtoprocess commandfinish output:
  logtoprocess foo output:
  spam

Confirm that logging blocked time catches stdio properly:
  $ cp $HGRCPATH.bak $HGRCPATH
  $ cat >> $HGRCPATH << EOF
  > [extensions]
  > logtoprocess=
  > pager=
  > [logtoprocess]
  > uiblocked=echo "\$EVENT command \$OPT_COMMAND_DURATION ms"
  > [ui]
  > logblockedtimes=True
  > EOF

  $ hg log
  uiblocked command [0-9]+.[0-9]* ms (re)