bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

[Alan Mackenzie]

Hello, Stefan and Emacs.

In my development branch, based on master, last updated ~March 2024.

(i) Build emacs.
(ii) make -j17 check.

The ert session this starts goes well, apart from in
lisp/erc/erc-tests.el.  This gets aborted by ert after 62 from 92 tests
have passed.  Test 63 fails for known reasons, a mismatch of two strings
compared with `equal'.

The log file, erc-tests.log, looks like this around the output for test
63:

.........................................................
   passed  60/92  erc--update-user-modes (0.000093 sec)
   passed  61/92  erc--user-modes (0.000053 sec)
   passed  62/92  erc--valid-local-channel-p (0.000071 sec)
Test erc--with-dependent-type-match backtrace:

Aborted: Ran 92 tests, 62 results as expected, 1 unexpected (2024-05-24
15:26:55+0000, 2.791555 sec)

1 unexpected results:
   FAILED  erc--with-dependent-type-match
  UNKNOWN  erc--with-entrypoint-environment
  UNKNOWN  erc-channel-p
  UNKNOWN  erc-channel-user
........................................................

Note that
(i) No error message or backtrace gets printed for test 63.  This is a
  bug.
(ii) The test run gets aborted.  This shouldn't happen, and is a bug.

erc-tests.el runs satisfactorally in an Emacs session, started by M-x
ert, and accepting the default selection t.

-- 
Alan Mackenzie (Nuremberg, Germany).

bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

[J.P.]

Hi Alan,

Alan Mackenzie <acm@muc.de> writes:

> Hello, Stefan and Emacs.
>
> In my development branch, based on master, last updated ~March 2024.
>
> (i) Build emacs.
> (ii) make -j17 check.
>
> The ert session this starts goes well, apart from in
> lisp/erc/erc-tests.el.  This gets aborted by ert after 62 from 92 tests
> have passed.  Test 63 fails for known reasons, a mismatch of two strings
> compared with `equal'.
>
> The log file, erc-tests.log, looks like this around the output for test
> 63:
>
> .........................................................
>    passed  60/92  erc--update-user-modes (0.000093 sec)
>    passed  61/92  erc--user-modes (0.000053 sec)
>    passed  62/92  erc--valid-local-channel-p (0.000071 sec)
> Test erc--with-dependent-type-match backtrace:
>
> Aborted: Ran 92 tests, 62 results as expected, 1 unexpected (2024-05-24
> 15:26:55+0000, 2.791555 sec)
>
> 1 unexpected results:
>    FAILED  erc--with-dependent-type-match
>   UNKNOWN  erc--with-entrypoint-environment
>   UNKNOWN  erc-channel-p
>   UNKNOWN  erc-channel-user

I'm afraid I must claim this as my own handiwork. My apologies.

> ........................................................
>
> Note that
> (i) No error message or backtrace gets printed for test 63.  This is a
>   bug.
> (ii) The test run gets aborted.  This shouldn't happen, and is a bug.

Yes, this is unfortunate.

> erc-tests.el runs satisfactorally in an Emacs session, started by M-x
> ert, and accepting the default selection t.

It seems you have identified the underlying cause:

  https://lists.gnu.org/archive/html/emacs-devel/2024-05/msg01140.html

The test itself is of minimal utility and is therefore rubbish (if not
outright vandalism), so I will remove it unless you'd rather it stick
around until the conversation on the list gets going.

Thanks,
J.P.

bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

[Alan Mackenzie]

Hello, JP.

On Sun, May 26, 2024 at 13:13:43 -0700, J.P. wrote:
> Hi Alan,

> Alan Mackenzie <acm@muc.de> writes:

> > Hello, Stefan and Emacs.

> > In my development branch, based on master, last updated ~March 2024.

> > (i) Build emacs.
> > (ii) make -j17 check.

> > The ert session this starts goes well, apart from in
> > lisp/erc/erc-tests.el.  This gets aborted by ert after 62 from 92 tests
> > have passed.  Test 63 fails for known reasons, a mismatch of two strings
> > compared with `equal'.

> > The log file, erc-tests.log, looks like this around the output for test
> > 63:

> > .........................................................
> >    passed  60/92  erc--update-user-modes (0.000093 sec)
> >    passed  61/92  erc--user-modes (0.000053 sec)
> >    passed  62/92  erc--valid-local-channel-p (0.000071 sec)
> > Test erc--with-dependent-type-match backtrace:

> > Aborted: Ran 92 tests, 62 results as expected, 1 unexpected (2024-05-24
> > 15:26:55+0000, 2.791555 sec)

> > 1 unexpected results:
> >    FAILED  erc--with-dependent-type-match
> >   UNKNOWN  erc--with-entrypoint-environment
> >   UNKNOWN  erc-channel-p
> >   UNKNOWN  erc-channel-user

> I'm afraid I must claim this as my own handiwork. My apologies.

Thanks!  But I think that erc--restore-initialize-priors has triggered
the error rather than containing the error itself.  I don't really think
you should be apologising for this.  ;-)

> > ........................................................

> > Note that
> > (i) No error message or backtrace gets printed for test 63.  This is a
> >   bug.
> > (ii) The test run gets aborted.  This shouldn't happen, and is a bug.

> Yes, this is unfortunate.

> > erc-tests.el runs satisfactorally in an Emacs session, started by M-x
> > ert, and accepting the default selection t.

> It seems you have identified the underlying cause:

>   https://lists.gnu.org/archive/html/emacs-devel/2024-05/msg01140.html

I've been looking at lisp/emacs-lisp/ert.el, and I think that suppressing
the debug output (or rather, not invoking a backtrace dump in batch mode)
is where the problem lies.  However, when I enabled these in my own copy,
they produced an erc.log of over 100 MB.  But that was in my customised
Emacs where I've changed quite a few things always to get a complete
backtrace.  So I'm not sure what is best, here.

> The test itself is of minimal utility and is therefore rubbish (if not
> outright vandalism), so I will remove it unless you'd rather it stick
> around until the conversation on the list gets going.

I think I'd rather the test should stay there a bit longer.  It
highlights problems in pcase.el and ert.el which might get fixed sooner
if the test is still there.  _MIGHT_ (here's hoping!).

> Thanks,
> J.P.

-- 
Alan Mackenzie (Nuremberg, Germany).

bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

[J.P.]

Hi Alan,

Alan Mackenzie <acm@muc.de> writes:

>> It seems you have identified the underlying cause:
>
>>   https://lists.gnu.org/archive/html/emacs-devel/2024-05/msg01140.html
>
> I've been looking at lisp/emacs-lisp/ert.el, and I think that suppressing
> the debug output (or rather, not invoking a backtrace dump in batch mode)
> is where the problem lies.  However, when I enabled these in my own copy,
> they produced an erc.log of over 100 MB.  But that was in my customised
> Emacs where I've changed quite a few things always to get a complete
> backtrace.  So I'm not sure what is best, here.

I too have bumped into failures that don't produce a backtrace, at least
in recent versions. However, the ones I typically see look more like:

  Error in process sentinel
  Make[3] *** [Makefile:184 lisp/erc/erc-*.log] Error 255

  ...

  1 files did not finish:
    lisp/erc/erc-*.log

  Make *** [Makefile:266 check-lisp-erc] Error 2

With these, it seems debug output is being intentionally suppressed on
account of the error originating from some process sentinel or timer.
And when I enable `debug-on-error', a backtrace appears as expected.
This leads me to assume such occurrences are somewhat unrelated to what
you're experiencing. That said, I'm fairly convinced I've encountered
the odd mystery failure with no specified error. And the "aborted" line
in your excerpt does look familiar. Sadly, though, I cannot reliably
reproduce anything similar (yet).

>> The test itself is of minimal utility and is therefore rubbish (if not
>> outright vandalism), so I will remove it unless you'd rather it stick
>> around until the conversation on the list gets going.
>
> I think I'd rather the test should stay there a bit longer.  It
> highlights problems in pcase.el and ert.el which might get fixed sooner
> if the test is still there.  _MIGHT_ (here's hoping!).

Good point. I've added a FIXME to remind myself or some future person to
delete the test once things have settled.

Cheers,
J.P.

bug#71178: Batch ert wrongly aborts a test run, and wrongly fails to say why.

[J.P.]

"J.P." <jp@neverwas.me> writes:

>> I think I'd rather the test should stay there a bit longer.  It
>> highlights problems in pcase.el and ert.el which might get fixed sooner
>> if the test is still there.  _MIGHT_ (here's hoping!).
>
> Good point. I've added a FIXME to remind myself or some future person to
> delete the test once things have settled.

The issue of the large pcase expansion appears to have been addressed by

  16fc5b6c0c7 * pcase.el (\`): Try and handle large patterns better

I have therefore deleted the offending test.

I'm leaving this bug open because its main concern is the absence of
adequate reporting under certain failure conditions. Thanks.