##// END OF EJS Templates
test-logtoprocess: use cat to wait for outputs...
Jun Wu -
r30991:3844b329 default
parent child Browse files
Show More
@@ -1,70 +1,73 b''
1 ATTENTION: logtoprocess runs commands asynchronously. Be sure to append "| cat"
2 to hg commands, to wait for the output, if you want to test its output.
3 Otherwise the test will be flaky.
4
1 Test if logtoprocess correctly captures command-related log calls.
5 Test if logtoprocess correctly captures command-related log calls.
2
6
3 $ hg init
7 $ hg init
4 $ cat > $TESTTMP/foocommand.py << EOF
8 $ cat > $TESTTMP/foocommand.py << EOF
5 > from mercurial import cmdutil
9 > from mercurial import cmdutil
6 > from time import sleep
10 > from time import sleep
7 > cmdtable = {}
11 > cmdtable = {}
8 > command = cmdutil.command(cmdtable)
12 > command = cmdutil.command(cmdtable)
9 > @command('foo', [])
13 > @command('foo', [])
10 > def foo(ui, repo):
14 > def foo(ui, repo):
11 > ui.log('foo', 'a message: %(bar)s\n', bar='spam')
15 > ui.log('foo', 'a message: %(bar)s\n', bar='spam')
12 > EOF
16 > EOF
13 $ cp $HGRCPATH $HGRCPATH.bak
17 $ cp $HGRCPATH $HGRCPATH.bak
14 $ cat >> $HGRCPATH << EOF
18 $ cat >> $HGRCPATH << EOF
15 > [extensions]
19 > [extensions]
16 > logtoprocess=
20 > logtoprocess=
17 > foocommand=$TESTTMP/foocommand.py
21 > foocommand=$TESTTMP/foocommand.py
18 > [logtoprocess]
22 > [logtoprocess]
19 > command=echo 'logtoprocess command output:';
23 > command=echo 'logtoprocess command output:';
20 > echo "\$EVENT";
24 > echo "\$EVENT";
21 > echo "\$MSG1";
25 > echo "\$MSG1";
22 > echo "\$MSG2"
26 > echo "\$MSG2"
23 > commandfinish=echo 'logtoprocess commandfinish output:';
27 > commandfinish=echo 'logtoprocess commandfinish output:';
24 > echo "\$EVENT";
28 > echo "\$EVENT";
25 > echo "\$MSG1";
29 > echo "\$MSG1";
26 > echo "\$MSG2";
30 > echo "\$MSG2";
27 > echo "\$MSG3"
31 > echo "\$MSG3"
28 > foo=echo 'logtoprocess foo output:';
32 > foo=echo 'logtoprocess foo output:';
29 > echo "\$EVENT";
33 > echo "\$EVENT";
30 > echo "\$MSG1";
34 > echo "\$MSG1";
31 > echo "\$OPT_BAR"
35 > echo "\$OPT_BAR"
32 > EOF
36 > EOF
33
37
34 Running a command triggers both a ui.log('command') and a
38 Running a command triggers both a ui.log('command') and a
35 ui.log('commandfinish') call. The foo command also uses ui.log.
39 ui.log('commandfinish') call. The foo command also uses ui.log.
36
40
37 Use head to ensure we wait for all lines to be produced, and sort to avoid
41 Use sort to avoid ordering issues between the various processes we spawn:
38 ordering issues between the various processes we spawn:
42 $ hg foo | cat | sort
39 $ hg foo | head -n 17 | sort
40
43
41
44
42
45
43 0
46 0
44 a message: spam
47 a message: spam
45 command
48 command
46 commandfinish
49 commandfinish
47 foo
50 foo
48 foo
51 foo
49 foo
52 foo
50 foo
53 foo
51 foo exited 0 after * seconds (glob)
54 foo exited 0 after * seconds (glob)
52 logtoprocess command output:
55 logtoprocess command output:
53 logtoprocess commandfinish output:
56 logtoprocess commandfinish output:
54 logtoprocess foo output:
57 logtoprocess foo output:
55 spam
58 spam
56
59
57 Confirm that logging blocked time catches stdio properly:
60 Confirm that logging blocked time catches stdio properly:
58 $ cp $HGRCPATH.bak $HGRCPATH
61 $ cp $HGRCPATH.bak $HGRCPATH
59 $ cat >> $HGRCPATH << EOF
62 $ cat >> $HGRCPATH << EOF
60 > [extensions]
63 > [extensions]
61 > logtoprocess=
64 > logtoprocess=
62 > pager=
65 > pager=
63 > [logtoprocess]
66 > [logtoprocess]
64 > uiblocked=echo "\$EVENT stdio \$OPT_STDIO_BLOCKED ms command \$OPT_COMMAND_DURATION ms"
67 > uiblocked=echo "\$EVENT stdio \$OPT_STDIO_BLOCKED ms command \$OPT_COMMAND_DURATION ms"
65 > [ui]
68 > [ui]
66 > logblockedtimes=True
69 > logblockedtimes=True
67 > EOF
70 > EOF
68
71
69 $ hg log
72 $ hg log | cat
70 uiblocked stdio [0-9]+.[0-9]* ms command [0-9]+.[0-9]* ms (re)
73 uiblocked stdio [0-9]+.[0-9]* ms command [0-9]+.[0-9]* ms (re)
General Comments 0
You need to be logged in to leave comments. Login now