view tests/test-logtoprocess.t @ 36200:deb851914fd7

dirstate: drop explicit files that shouldn't match (BC) (issue4679)

Before, wctx.walk() could include files excluded by -X pattern, which
disagrees with wctx.matches() and ctx.walk()/matches() behavior. This patch
fixes the problem by testing stat results against the matcher if the matcher
may contain false paths.

I have no idea if the fix should be made before the workaround for case-
insensitive filesystems, but that shouldn't matter since match.anypats()
means 'not match.isexact()'.

This patch also makes narrow and sparse extensions to not exclude explicit
paths on walk() because they appear to depend on the buggy behavior.

More detailed analysis about this issue by Martin von Zweigbergk:

"I think it's just an unintended consequence of how the dirstate walk works,
but I'm not sure. The exception for explicit files also bothered me when I
was working on the matcher code a year or so ago. I actually added the
exception to the matcher code because I thought it was always working like
that (not just for dirstate) in a83a7d27911e (match: handle excludes using
new differencematcher, 2017-05-16). It was only recently that Yuya realized
that it used to be inconsistent and that I probably made it consistently bad
because I didn't realize it was inconsistent to start with, see 821d8a5ab4ff
(match: do not weirdly include explicit files excluded by -X option,
2018-01-16)."

.. bc::

   Working-directory commands now respect ``-X PATTERN`` no matter if PATTERN
   matches explicitly-specified FILEs. For example, ``hg add foo -X foo`` no
   longer add the file ``foo``.

#require no-windows

ATTENTION: logtoprocess runs commands asynchronously. Be sure to append "| cat"
to hg commands, to wait for the output, if you want to test its output.
Otherwise the test will be flaky.

Test if logtoprocess correctly captures command-related log calls.

  $ hg init
  $ cat > $TESTTMP/foocommand.py << EOF
  > from __future__ import absolute_import
  > from mercurial import registrar
  > cmdtable = {}
  > command = registrar.command(cmdtable)
  > configtable = {}
  > configitem = registrar.configitem(configtable)
  > configitem('logtoprocess', 'foo',
  >     default=None,
  > )
  > @command(b'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]
  > command=echo 'logtoprocess command output:';
  >     echo "\$EVENT";
  >     echo "\$MSG1";
  >     echo "\$MSG2"
  > commandfinish=echo 'logtoprocess commandfinish output:';
  >     echo "\$EVENT";
  >     echo "\$MSG1";
  >     echo "\$MSG2";
  >     echo "\$MSG3"
  > foo=echo 'logtoprocess foo output:';
  >     echo "\$EVENT";
  >     echo "\$MSG1";
  >     echo "\$OPT_BAR"
  > EOF

Running a command triggers both a ui.log('command') and a
ui.log('commandfinish') call. The foo command also uses ui.log.

Use sort to avoid ordering issues between the various processes we spawn:
  $ hg foo | cat | sort
  
  
  
   (chg !)
  0
  a message: spam
  command
  command (chg !)
  commandfinish
  foo
  foo
  foo
  foo
  foo exited 0 after * seconds (glob)
  logtoprocess command output:
  logtoprocess command output: (chg !)
  logtoprocess commandfinish output:
  logtoprocess foo output:
  serve --cmdserver chgunix * (glob) (chg !)
  serve --cmdserver chgunix * (glob) (chg !)
  spam

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

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