tests/test-logtoprocess.t
author Simon Farnsworth <simonfar@fb.com>
Wed, 15 Feb 2017 13:17:45 -0800
changeset 30976 e92daf156d5c
parent 28901 a368da441b32
child 30978 fdecd24ca4dc
permissions -rw-r--r--
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.
Ignore whitespace changes - Everywhere: Within whitespace: At end of lines:
28901
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     1
Test if logtoprocess correctly captures command-related log calls.
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     2
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     3
  $ hg init
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     4
  $ cat > $TESTTMP/foocommand.py << EOF
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     5
  > from mercurial import cmdutil
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     6
  > from time import sleep
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     7
  > cmdtable = {}
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     8
  > command = cmdutil.command(cmdtable)
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
     9
  > @command('foo', [])
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    10
  > def foo(ui, repo):
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    11
  >     ui.log('foo', 'a message: %(bar)s\n', bar='spam')
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    12
  > EOF
30976
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    13
  $ cp $HGRCPATH $HGRCPATH.bak
28901
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    14
  $ cat >> $HGRCPATH << EOF
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    15
  > [extensions]
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    16
  > logtoprocess=
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    17
  > foocommand=$TESTTMP/foocommand.py
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    18
  > [logtoprocess]
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    19
  > command=echo 'logtoprocess command output:';
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    20
  >     echo "\$EVENT";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    21
  >     echo "\$MSG1";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    22
  >     echo "\$MSG2"
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    23
  > commandfinish=echo 'logtoprocess commandfinish output:';
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    24
  >     echo "\$EVENT";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    25
  >     echo "\$MSG1";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    26
  >     echo "\$MSG2";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    27
  >     echo "\$MSG3"
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    28
  > foo=echo 'logtoprocess foo output:';
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    29
  >     echo "\$EVENT";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    30
  >     echo "\$MSG1";
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    31
  >     echo "\$OPT_BAR"
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    32
  > EOF
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    33
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    34
Running a command triggers both a ui.log('command') and a
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    35
ui.log('commandfinish') call. The foo command also uses ui.log.
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    36
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    37
Use head to ensure we wait for all lines to be produced, and sort to avoid
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    38
ordering issues between the various processes we spawn:
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    39
  $ hg foo | head -n 17 | sort
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    40
  
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    41
  
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    42
  
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    43
  0
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    44
  a message: spam
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    45
  command
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    46
  commandfinish
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    47
  foo
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    48
  foo
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    49
  foo
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    50
  foo
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    51
  foo exited 0 after * seconds (glob)
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    52
  logtoprocess command output:
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    53
  logtoprocess commandfinish output:
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    54
  logtoprocess foo output:
a368da441b32 logtoprocess: new experimental extension
Martijn Pieters <mjpieters@fb.com>
parents:
diff changeset
    55
  spam
30976
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    56
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    57
Confirm that logging blocked time catches stdio properly:
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    58
  $ cp $HGRCPATH.bak $HGRCPATH
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    59
  $ cat >> $HGRCPATH << EOF
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    60
  > [extensions]
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    61
  > logtoprocess=
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    62
  > pager=
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    63
  > [logtoprocess]
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    64
  > uiblocked=echo "\$EVENT command \$OPT_COMMAND_DURATION ms"
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    65
  > [ui]
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    66
  > logblockedtimes=True
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    67
  > EOF
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    68
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    69
  $ hg log
e92daf156d5c ui: provide a mechanism to track and log blocked time
Simon Farnsworth <simonfar@fb.com>
parents: 28901
diff changeset
    70
  uiblocked command [0-9]+.[0-9]* ms (re)