bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Matt Armstrong]

This is a follow up to bug#59028.

A good number of Emacs tests exercise parts of Emacs that call
`message'.

When ERT runs tests interactively the `message' output is not normally
visible in the "*ert*" buffer.  In fact ERT arranges for the messages to
not even appear in the minibuffer as they happen.  They are instead
available on demand with the
`ert-results-pop-to-messages-for-test-at-point' command, bound to 'm' in
"*ert*".

When ERT runs tests in batch mode, messages are printed to the console
intermixed with ERT's progress messages.

Idea: hide `message' output when running in batch mode, printing them
only for failed tests.

Rationale: for passing tests the output is not useful.  For failing
tests it can be useful as a kind of trace, so the writing tests that
avoid all calls to `message' is not necessarily the best option.

This would also remove the need for a long game of whack-a-mole to
suppress such output, which leads to specific fixes like Eli's commit:

0a26b26217 (Reduce buffer-tests noisiness even more, 2022-11-16)


In GNU Emacs 29.0.50 (build 9, x86_64-pc-linux-gnu, GTK+ Version
 3.24.34, cairo version 1.16.0) of 2022-11-07 built on naz
Repository revision: d04433b96215d7d3387573f19cc315de86f2341a
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12201003
System Description: Debian GNU/Linux bookworm/sid

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Eli Zaretskii]

> From: Matt Armstrong <matt@rfc20.org>
> Date: Wed, 16 Nov 2022 10:52:11 -0800
> 
> A good number of Emacs tests exercise parts of Emacs that call
> `message'.

Are you sure?  Many Emacs features display text that doesn't go
through 'message'.

> Idea: hide `message' output when running in batch mode, printing them
> only for failed tests.

We have set-message-function that could be used for this purpose, I
think?  If indeed 'message' is the culprit.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Stefan Kangas]

Eli Zaretskii <eliz@gnu.org> writes:

>> A good number of Emacs tests exercise parts of Emacs that call
>> `message'.
>
> Are you sure?  Many Emacs features display text that doesn't go
> through 'message'.
>
>> Idea: hide `message' output when running in batch mode, printing them
>> only for failed tests.
>
> We have set-message-function that could be used for this purpose, I
> think?  If indeed 'message' is the culprit.

Is there any way to capture and stop *all* output in the terminal for
passing tests?  Like `set-batch-output-function', or something to that
effect.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Matt Armstrong]

Eli Zaretskii <eliz@gnu.org> writes:

>> From: Matt Armstrong <matt@rfc20.org>
>> Date: Wed, 16 Nov 2022 10:52:11 -0800
>>
>> A good number of Emacs tests exercise parts of Emacs that call
>> `message'.
>
> Are you sure?  Many Emacs features display text that doesn't go
> through 'message'.
>
>> Idea: hide `message' output when running in batch mode, printing them
>> only for failed tests.
>
> We have set-message-function that could be used for this purpose, I
> think?  If indeed 'message' is the culprit.

It looks like the set-message-function(s) hooks are bypassed in
non-interactive mode.  In that case message3_nolog in xdisp.c calls
message_to_stderr, instead of calling set_message.  It is set_message
that ultimately uses the set-message-function machinery.

After looking at this more I agree with your suspicions.  It looks like
good amount of C level code calls various message functions without
going through Fmessage.  Also, I spot no easy way to modify ert.el to
temporarily redirect stderr elsewhere.  In noninteractive mode Emacs
seems hard coded to print to stderr.

I proposed this thinking it would be an easy and simple change.  At this
point I'm thinking the effort and complexity here isn't worth it.  If
nobody else wants to champion this idea I'll go ahead and close it.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Matt Armstrong]

Stefan Kangas <stefankangas@gmail.com> writes:

> Eli Zaretskii <eliz@gnu.org> writes:
>
>>> A good number of Emacs tests exercise parts of Emacs that call
>>> `message'.
>>
>> Are you sure?  Many Emacs features display text that doesn't go
>> through 'message'.
>>
>>> Idea: hide `message' output when running in batch mode, printing them
>>> only for failed tests.
>>
>> We have set-message-function that could be used for this purpose, I
>> think?  If indeed 'message' is the culprit.
>
> Is there any way to capture and stop *all* output in the terminal for
> passing tests?  Like `set-batch-output-function', or something to that
> effect.

The call sequence to look at is:

message3_nolog:xdisp.c ->
   message_to_stderr:xdisp.c ->
   errwrite:sysdep.c

There is errstream:sysdep.c, which is where any temporary redirection of
error output could go, but there is no existing way to change it
temporarily from lisp or even C.  Further, we'd probably want to save
the output somewhere in case the test did fail (or we trust the
*Message* buffer...not sure if that is there in batch mode?).

A concern I have is suppressing useful diagnostic errors.  E.g. at any
point emacs_abort() can run kill-emacs hooks which can call `message'.
Is it worth the complexity of adding temporary output redirections, to
clean up test output, at the risk of making this kind of thing harder to
debug?

A simple approach is to run each test in an isolated subprocess, but
that would be much slower.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Eli Zaretskii]

> From: Stefan Kangas <stefankangas@gmail.com>
> Date: Wed, 16 Nov 2022 16:12:36 -0800
> Cc: 59317@debbugs.gnu.org
> 
> Is there any way to capture and stop *all* output in the terminal for
> passing tests?  Like `set-batch-output-function', or something to that
> effect.

No, not that I know of.  We have several functions that will write to
the terminal in batch mode, and they use different low-level
interfaces to do that.  Also, some of the output goes to stdout and
some to stderr.  You can always redirect these two streams to files,
of course.

Besides, we don't want to stop _everything_: the messages that
announce the tests that passed and the time it took to run each test
are useful and should not be shut up.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Eli Zaretskii]

> From: Matt Armstrong <matt@rfc20.org>
> Cc: 59317@debbugs.gnu.org
> Date: Wed, 16 Nov 2022 21:51:46 -0800
> 
> It looks like the set-message-function(s) hooks are bypassed in
> non-interactive mode.  In that case message3_nolog in xdisp.c calls
> message_to_stderr, instead of calling set_message.  It is set_message
> that ultimately uses the set-message-function machinery.
> 
> After looking at this more I agree with your suspicions.  It looks like
> good amount of C level code calls various message functions without
> going through Fmessage.  Also, I spot no easy way to modify ert.el to
> temporarily redirect stderr elsewhere.  In noninteractive mode Emacs
> seems hard coded to print to stderr.
> 
> I proposed this thinking it would be an easy and simple change.  At this
> point I'm thinking the effort and complexity here isn't worth it.  If
> nobody else wants to champion this idea I'll go ahead and close it.

The only idea I have is to mock-out the relevant functions in the
test.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Stefan Kangas]

Eli Zaretskii <eliz@gnu.org> writes:

> No, not that I know of.  We have several functions that will write to
> the terminal in batch mode, and they use different low-level
> interfaces to do that.  Also, some of the output goes to stdout and
> some to stderr.  You can always redirect these two streams to files,
> of course.
>
> Besides, we don't want to stop _everything_: the messages that
> announce the tests that passed and the time it took to run each test
> are useful and should not be shut up.

I was thinking of temporarily setting stdout and stderr to a buffer
(maybe using something like open_memstream) for the duration of each
individual test, and then print the content of that buffer only if the
test failed.

Maybe it's not worth the effort, though.  I'm also not sure how to do
the above portably.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Michael Albinus]

Matt Armstrong <matt@rfc20.org> writes:

Hi Matt,

> When ERT runs tests interactively the `message' output is not normally
> visible in the "*ert*" buffer.  In fact ERT arranges for the messages to
> not even appear in the minibuffer as they happen.  They are instead
> available on demand with the
> `ert-results-pop-to-messages-for-test-at-point' command, bound to 'm' in
> "*ert*".
>
> When ERT runs tests in batch mode, messages are printed to the console
> intermixed with ERT's progress messages.
>
> Idea: hide `message' output when running in batch mode, printing them
> only for failed tests.
>
> Rationale: for passing tests the output is not useful.  For failing
> tests it can be useful as a kind of trace, so the writing tests that
> avoid all calls to `message' is not necessarily the best option.

Besides the other arguments already given in this thread, I'd like to
emphasize that messages are useful even in batch mode, for successful
tests. This is the only way to study ert tests in batch mode, for
example on our CI/CD machines hydra and emba.

If messages shall be suppressed, this must be controlled by a user
option. However, I'm not in favor to do it at all.

Best regards, Michael.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Stefan Kangas]

Michael Albinus <michael.albinus@gmx.de> writes:

> Besides the other arguments already given in this thread, I'd like to
> emphasize that messages are useful even in batch mode, for successful
> tests. This is the only way to study ert tests in batch mode, for
> example on our CI/CD machines hydra and emba.

It would be less than useful in CI, indeed.

But in interactive sessions, and when running tests manually with
e.g. M-x compile, it helps to have less noise, to find the relevant
failures faster.

> If messages shall be suppressed, this must be controlled by a user
> option. However, I'm not in favor to do it at all.

Agreed.  Perhaps an environment variable could also be provided, so that
it is easier to control from the command line?

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Michael Albinus]

Stefan Kangas <stefankangas@gmail.com> writes:

Hi Stefan,
>> Besides the other arguments already given in this thread, I'd like to
>> emphasize that messages are useful even in batch mode, for successful
>> tests. This is the only way to study ert tests in batch mode, for
>> example on our CI/CD machines hydra and emba.
>
> It would be less than useful in CI, indeed.
>
> But in interactive sessions, and when running tests manually with
> e.g. M-x compile, it helps to have less noise, to find the relevant
> failures faster.

Maybe, although the messages in interactive mode go to a special *ERT
Messages* buffer.

Btw, there are test cases which depend on proper messages. See for
example autorevert-tests.el. For those tests, messages must not be
suppressed at all.

>> If messages shall be suppressed, this must be controlled by a user
>> option. However, I'm not in favor to do it at all.
>
> Agreed.  Perhaps an environment variable could also be provided, so that
> it is easier to control from the command line?

Sure. There are already several $EMACS_TEST_* environment variables, see
test/README.

Best regards, Michael.

bug#59317: 29.0.50; Feature idea: suppress `message' output in ert batch test output

[Matt Armstrong]

Michael Albinus <michael.albinus@gmx.de> writes:

> Stefan Kangas <stefankangas@gmail.com> writes:
>
> Hi Stefan,
>>> Besides the other arguments already given in this thread, I'd like to
>>> emphasize that messages are useful even in batch mode, for successful
>>> tests. This is the only way to study ert tests in batch mode, for
>>> example on our CI/CD machines hydra and emba.
>>
>> It would be less than useful in CI, indeed.
>>
>> But in interactive sessions, and when running tests manually with
>> e.g. M-x compile, it helps to have less noise, to find the relevant
>> failures faster.
>
> Maybe, although the messages in interactive mode go to a special *ERT
> Messages* buffer.

I believe Stefan's idea as running something like "make check" through
M-x compile, so the tests run in batch mode with output in *Compilation*
buffers.

As an implementation note, the *ERT Messages* buffer is not where
`message' output goes during a test.  Instead, the `ert-test' function
notes the `point-max-marker' of the *Messages* buffer, then runs the
test, and then extracts with `buffer-substring' the region of *Messages*
between that marker and its (point-max).  It then squirrels that string
away in a test result data structure.  Notably, ert doesn't suppress
message output in any way during a test.  They still appear in the
minibuffer, go to *Messages*, etc.


> Btw, there are test cases which depend on proper messages. See for
> example autorevert-tests.el. For those tests, messages must not be
> suppressed at all.

The way I imagine it, any lisp level introspection, mocking, etc., would
still work.


>>> If messages shall be suppressed, this must be controlled by a user
>>> option. However, I'm not in favor to do it at all.
>>
>> Agreed.  Perhaps an environment variable could also be provided, so
>> that it is easier to control from the command line?
>
> Sure. There are already several $EMACS_TEST_* environment variables,
> see test/README.

Good to know.