GNU bug report logs - #50629
28.0.50; hard to debug an uncaught error with ert

Previous Next

Package: emacs;

Reported by: Mike Kupfer <mkupfer <at> alum.berkeley.edu>

Date: Thu, 16 Sep 2021 23:29:02 UTC

Severity: normal

Merged with 58941

Found in versions 28.0.50, 28.1.90

To reply to this bug, email your comments to 50629 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Thu, 16 Sep 2021 23:29:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to Mike Kupfer <mkupfer <at> alum.berkeley.edu>:
New bug report received and forwarded. Copy sent to bug-gnu-emacs <at> gnu.org. (Thu, 16 Sep 2021 23:29:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Mike Kupfer <mkupfer <at> alum.berkeley.edu>
To: bug-gnu-emacs <at> gnu.org
Subject: 28.0.50; hard to debug an uncaught error with ert
Date: Thu, 16 Sep 2021 16:28:08 -0700
(This is similar to bug#49805, but I'm filing a new bug in case this
issue needs a different resolution than #49805.)

Consider the following stripped-down test case:

$ emacs -Q -batch -l ert -eval '(ert-deftest f () (defun foo () (bar)) (defun bar () (error "bar")) (should (equal 42 (foo))))' -f ert-run-tests-batch-and-exit

It produces

-----8<-----8<-----
Running 1 tests (2021-09-16 15:55:17-0700)
Test f backtrace:
  signal(error ("bar"))
  apply(signal (error ("bar")))
  (setq value-2 (apply fn-0 args-1))
  (unwind-protect (setq value-2 (apply fn-0 args-1)) (setq form-descri
  (if (unwind-protect (setq value-2 (apply fn-0 args-1)) (setq form-de
  (let (form-description-4) (if (unwind-protect (setq value-2 (apply f
  (let ((value-2 'ert-form-evaluation-aborted-3)) (let (form-descripti
  (let* ((fn-0 (function equal)) (args-1 (condition-case err (let ((si
  (lambda nil (defalias 'foo (function (lambda nil (bar)))) (defalias 
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name f :documentation nil :body (lambda ni
  ert-run-or-rerun-test(#s(ert--stats :selector t :tests [#s(ert-test 
  ert-run-tests(t #f(compiled-function (event-type &rest event-args) #
  ert-run-tests-batch(nil)
  ert-run-tests-batch-and-exit()
  command-line-1(("-l" "ert" "-eval" "(ert-deftest f () (defun foo () 
  command-line()
  normal-top-level()
Test f condition:
    (error "bar")
   FAILED  1/1  f

Ran 1 tests, 0 results as expected, 1 unexpected (2021-09-16 15:55:17-0700)

1 unexpected results:
   FAILED  f
----->8----->8-----

Knowing that error "bar" was raised is helpful, but in a more realistic
test scenario, it can take some time to figure out where the error was
raised.  Setting debug-on-error to t doesn't help (does ert hijack the
normal error handling mechanisms?).  The only way I know of to track it
down is to run the test multiple times, and use #'message at key points
in the code to record execution progress.

I ran into this while running some (not-yet-integrated) ert tests for
MH-E.  The message in the *ert* buffer looked like

  F mh-folder-completion-function-10-plus-slash-abs-folder
      Test ‘mh-folder-completion-function’ with ‘+/abso-folder’.
      (args-out-of-range "folder/bar" 44 nil)

The backtrace produced by ert was over 1MB long, and I was unable to use
it to determine where the error was coming from.

Here are two suggestions for how to make this better.

1. When ert detects an uncaught error, capture the backtrace at that
time and include the backtrace in the results.

2. Provide a way for an interactive user to disable whatever ert is
doing that lets it capture errors and drive on.  Instead, just let the
error be raised, and let the user use the Lisp debugger to investigate.


In GNU Emacs 28.0.50 (build 2, x86_64-pc-linux-gnu, X toolkit, cairo version 1.16.0, Xaw scroll bars)
 of 2021-09-02 built on deb10
Repository revision: 6885c62a104dcf52378860d8f951dbdce52b73c5
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12004000
System Description: Debian GNU/Linux 10 (buster)

Configured using:
 'configure --prefix=/usr/new'

Configured features:
CAIRO FREETYPE GIF GLIB GMP GNUTLS GSETTINGS HARFBUZZ JPEG LIBSELINUX
LIBXML2 MODULES NOTIFY INOTIFY PDUMPER PNG SECCOMP SOUND THREADS TIFF
TOOLKIT_SCROLL_BARS X11 XDBE XIM XPM LUCID ZLIB

Important settings:
  value of $LC_TIME: C
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8-unix

Major mode: ERT-Results

Minor modes in effect:
  shell-dirtrack-mode: t
  delete-selection-mode: t
  global-eldoc-mode: t
  mouse-wheel-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  buffer-read-only: t
  indent-tabs-mode: t
  transient-mark-mode: t

Load-path shadows:
None found.

Features:
(shadow mh-mime mh-identity mh-tool-bar mh-letter mh-show goto-addr
gnus-cite gnus-art mm-uu mml2015 gnus-sum shr kinsoku svg dom browse-url
url url-proxy url-privacy url-expand url-methods url-history url-cookie
url-domsuf url-util url-parse url-vars gnus-group gnus-undo gnus-start
gnus-dbus dbus xml gnus-cloud nnimap nnmail mail-source utf7 netrc nnoo
parse-time iso8601 gnus-spec gnus-int gnus-win gnus-range mh-xface
mh-comp mh-scan mh-gnus mm-view mml-smime smime dig mailcap emacsbug
eieio-opt speedbar ezimage dframe shortdoc apropos thingatpt help-fns
radix-tree mule-util jka-compr info misearch multi-isearch ediff-vers
ediff ediff-merg ediff-mult ediff-wind ediff-diff ediff-help ediff-init
ediff-util smerge-mode diff whitespace cl-extra gnus nnheader wid-edit
mdk-mail smtpmail sendmail message rmc puny rfc822 mml mml-sec epa
derived epg rfc6068 epg-config gnus-util rmail rmail-loaddefs
auth-source eieio eieio-core eieio-loaddefs password-cache json map
text-property-search time-date subr-x mm-decode mm-bodies mm-encode
mail-parse rfc2231 rfc2047 rfc2045 mm-util ietf-drums mail-prsvr
mail-utils gmm-utils mailheader cl-macs mh-utils mh-e mh-compat
mailabbrev mh-buffers mh-loaddefs ert pp ewoc debug backtrace help-mode
find-func vc-git diff-mode bug-reference dired-aux dired-x seq gv dired
dired-loaddefs server noutline outline easy-mmode cc-mode cc-fonts
cc-guess cc-menus cc-cmds cc-styles cc-align cc-engine cc-vars cc-defs
byte-opt bytecomp byte-compile cconv shell pcomplete comint ansi-color
ring xcscope advice delsel cl-seq vc vc-dispatcher timeclock cl-loaddefs
cl-lib mdk-hacks iso-transl tooltip eldoc electric uniquify ediff-hook
vc-hooks lisp-float-type mwheel term/x-win x-win term/common-win x-dnd
tool-bar dnd fontset image regexp-opt fringe tabulated-list replace
newcomment text-mode elisp-mode lisp-mode prog-mode register page
tab-bar menu-bar rfn-eshadow isearch easymenu timer select scroll-bar
mouse jit-lock font-lock syntax font-core term/tty-colors frame
minibuffer cl-generic cham georgian utf-8-lang misc-lang vietnamese
tibetan thai tai-viet lao korean japanese eucjp-ms cp51932 hebrew greek
romanian slovak czech european ethiopic indian cyrillic chinese
composite charscript charprop case-table epa-hook jka-cmpr-hook help
simple abbrev obarray cl-preloaded nadvice button loaddefs faces
cus-face macroexp files window text-properties overlay sha1 md5 base64
format env code-pages mule custom widget hashtable-print-readable
backquote threads inotify dynamic-setting system-font-setting
font-render-setting cairo x-toolkit x multi-tty make-network-process
emacs)

Memory information:
((conses 16 314657 10561)
 (symbols 48 22275 4)
 (strings 32 75491 1172)
 (string-bytes 1 2515695)
 (vectors 16 38901)
 (vector-slots 8 438662 8550)
 (floats 8 300 273)
 (intervals 56 27726 0)
 (buffers 992 25))




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Fri, 26 Aug 2022 11:42:01 GMT) Full text and rfc822 format available.

Message #8 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Cc: 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Fri, 26 Aug 2022 13:41:23 +0200
Mike Kupfer <mkupfer <at> alum.berkeley.edu> writes:

> Knowing that error "bar" was raised is helpful, but in a more realistic
> test scenario, it can take some time to figure out where the error was
> raised.  Setting debug-on-error to t doesn't help (does ert hijack the
> normal error handling mechanisms?).

(I'm going through old bug reports that unfortunately weren't resolved
at the time.)

I'm not that familiar with ert internals, but yes, I think that's
basically what ert does -- it hijacks the error/debug reporting system
to implement the `should' macros.

I've briefly poked at this now, but without any success in getting
better backtraces for actual errors (which would indeed be very nice to
have).

Anybody more familiar with ert.el know how this can be achieved?




Added tag(s) moreinfo. Request was from Lars Ingebrigtsen <larsi <at> gnus.org> to control <at> debbugs.gnu.org. (Fri, 26 Aug 2022 11:42:02 GMT) Full text and rfc822 format available.

Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Fri, 26 Aug 2022 13:53:02 GMT) Full text and rfc822 format available.

Message #13 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: 50629 <at> debbugs.gnu.org, Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Fri, 26 Aug 2022 15:52:47 +0200
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> Mike Kupfer <mkupfer <at> alum.berkeley.edu> writes:
>
>> Knowing that error "bar" was raised is helpful, but in a more realistic
>> test scenario, it can take some time to figure out where the error was
>> raised.  Setting debug-on-error to t doesn't help (does ert hijack the
>> normal error handling mechanisms?).
>
> (I'm going through old bug reports that unfortunately weren't resolved
> at the time.)
>
> I'm not that familiar with ert internals, but yes, I think that's
> basically what ert does -- it hijacks the error/debug reporting system
> to implement the `should' macros.
>
> I've briefly poked at this now, but without any success in getting
> better backtraces for actual errors (which would indeed be very nice to
> have).
>
> Anybody more familiar with ert.el know how this can be achieved?

Not exactly this, I guess, but maybe as source of an idea?

diff --git a/lisp/emacs-lisp/ert.el b/lisp/emacs-lisp/ert.el
index 047b0069bb..1ffa0b5929 100644
--- a/lisp/emacs-lisp/ert.el
+++ b/lisp/emacs-lisp/ert.el
@@ -1495,6 +1495,8 @@ ert-run-tests-batch
                  (let ((print-escape-newlines t)
                        (print-level ert-batch-print-level)
                        (print-length ert-batch-print-length))
+                   (ert--pp-with-indentation-and-newline
+                    (ert-test-result-with-condition-should-forms result))
                    (ert--pp-with-indentation-and-newline
                     (ert-test-result-with-condition-condition result)))
                  (goto-char (1- (point-max)))

leads to output

Test f condition:
    (((should
       (equal 42
	      (foo)))
      :form
      (signal void-function
	      (bar))))
(void-function bar)




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 13:22:02 GMT) Full text and rfc822 format available.

Message #16 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: 50629 <at> debbugs.gnu.org, Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 15:20:55 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

>> Anybody more familiar with ert.el know how this can be achieved?
>
> Not exactly this, I guess, but maybe as source of an idea?

[...]

> +                   (ert--pp-with-indentation-and-newline
> +                    (ert-test-result-with-condition-should-forms result))
>                     (ert--pp-with-indentation-and-newline
>                      (ert-test-result-with-condition-condition result)))
>                   (goto-char (1- (point-max)))
>
> leads to output
>
> Test f condition:
>     (((should
>        (equal 42
> 	      (foo)))
>       :form
>       (signal void-function
> 	      (bar))))
> (void-function bar)

Hm, yes...  But it'd be really useful to have the complete backtrace
instead of just the signal form, because the errors that this would be
most helpful for are often way down in the call stack.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 13:45:01 GMT) Full text and rfc822 format available.

Message #19 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 15:44:12 +0200
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> Hm, yes...  But it'd be really useful to have the complete backtrace
> instead of just the signal form, because the errors that this would be
> most helpful for are often way down in the call stack.

The backtrace we have already.  It's the "unreadable" stuff that ERT
prints.  It's hard to make sense of because of the macrology involved.
If you macroexpand the ert-deftest form that Mike provided, you'll see
what I mean.

And that's also what one will see in a debugger.  (There's an
ert-debug-on-error, BTW.  I think someone asked.)

Don't know, maybe you could change ert-deftest to expand into something
more readable?




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 13:53:01 GMT) Full text and rfc822 format available.

Message #22 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 15:52:45 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> The backtrace we have already.  It's the "unreadable" stuff that ERT
> prints.

No, that's not the backtrace (that we're interested in).

With this example:

emake; ./src/emacs -Q -batch -l ert -eval '(ert-deftest f () (setq debug-on-error t) (defun foo () (bar)) (defun bar () (zot)) (should (equal 42 (foo))))' -f ert-run-tests-batch-and-exit

We'd like to see a backtrace that mentions that zot was called by bar,
and that bar was called by foo.  Instead we get:

Test f backtrace:
  signal(void-function (zot))
  apply(signal (void-function (zot)))
  (setq value-2 (apply fn-0 args-1))
  (unwind-protect (setq value-2 (apply fn-0 args-1)) (setq form-descri

Note that there's no mention of foo or bar.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 14:07:01 GMT) Full text and rfc822 format available.

Message #25 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 16:06:14 +0200
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:
>
>> The backtrace we have already.  It's the "unreadable" stuff that ERT
>> prints.
>
> No, that's not the backtrace (that we're interested in).
>
> With this example:
>
> emake; ./src/emacs -Q -batch -l ert -eval '(ert-deftest f () (setq
> debug-on-error t) (defun foo () (bar)) (defun bar () (zot)) (should
> (equal 42 (foo))))' -f ert-run-tests-batch-and-exit
>
> We'd like to see a backtrace that mentions that zot was called by bar,
> and that bar was called by foo.  Instead we get:
>
> Test f backtrace:
>   signal(void-function (zot))
>   apply(signal (void-function (zot)))
>   (setq value-2 (apply fn-0 args-1))
>   (unwind-protect (setq value-2 (apply fn-0 args-1)) (setq form-descri
>
> Note that there's no mention of foo or bar.

That's what I meant with macrology.  Please macroexpand and look at
what's actually executed.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 14:30:02 GMT) Full text and rfc822 format available.

Message #28 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 16:29:04 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> That's what I meant with macrology.  Please macroexpand and look at
> what's actually executed.

This is what macroexpand-all says is executed:

(progn
  (ert-set-test
   'f
   (record 'ert-test 'f
	   nil #'(lambda ()
		   (defalias 'foo #'(lambda ()
				      (bar)))
		   (defalias 'bar #'(lambda ()
				      (zot)))
		   (let* ((fn-573 #'equal)
			  (args-574 (condition-case err (let ( foo)
							  (list 42 (foo)))
				      (error (progn
					       (setq fn-573 #'signal)
					       (list (car err) (cdr err)))))))
		     (let ((value-575 'ert-form-evaluation-aborted-576))
		       (let ( form-description-577)
			 (if (unwind-protect (setq value-575 (apply fn-573 args-574))
			       (setq form-description-577
				     (nconc (list '(should (equal 42 (foo))))
					    (list :form
						  (cons fn-573 args-574))
					    (if (eql value-575
						     'ert-form-evaluation-aborted-576) ()
					      (list :value value-575))
					    (if (eql value-575
						     'ert-form-evaluation-aborted-576) ()
					      (let* ((-explainer- (and t (ert--get-explainer 'equal))))
						(if -explainer- (list :explanation
								      (apply
								       -explainer-
								       args-574))
						  nil)))))
			       (ert--signal-should-execution form-description-577)) ()
			   (ert-fail form-description-577)))
		       value-575)))
	   nil
	   ':passed
	   'nil
	   nil))
  'f)

The foo->bar->zot calling sequence is preserved.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 14:39:02 GMT) Full text and rfc822 format available.

Message #31 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Mike Kupfer <mkupfer <at> alum.berkeley.edu>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Gerd Möllmann <gerd.moellmann <at> gmail.com>,
 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 07:38:41 -0700
Lars Ingebrigtsen wrote:

> The foo->bar->zot calling sequence is preserved.

Er, where?  (Or did you mean to write that it's not preserved?)

mike




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 14:41:02 GMT) Full text and rfc822 format available.

Message #34 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Cc: Gerd Möllmann <gerd.moellmann <at> gmail.com>,
 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 16:40:25 +0200
Mike Kupfer <mkupfer <at> alum.berkeley.edu> writes:

>> The foo->bar->zot calling sequence is preserved.
>
> Er, where?  (Or did you mean to write that it's not preserved?)

It's preserved in the code, and not in the backtrace.

So, yes, and no.  😀




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sat, 27 Aug 2022 15:14:02 GMT) Full text and rfc822 format available.

Message #37 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sat, 27 Aug 2022 17:13:15 +0200
On 22-08-27 16:29 , Lars Ingebrigtsen wrote:
> 			  (args-574 (condition-case err (let ( foo)
> 							  (list 42 (foo)))

Sorry, you are right, but then the condition-case "swallows" the error.
Not sure what can be done about that.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 01:21:02 GMT) Full text and rfc822 format available.

Message #40 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Ihor Radchenko <yantar92 <at> gmail.com>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Lars Ingebrigtsen <larsi <at> gnus.org>, 50629 <at> debbugs.gnu.org,
 Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 09:21:33 +0800
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> On 22-08-27 16:29 , Lars Ingebrigtsen wrote:
>> 			  (args-574 (condition-case err (let ( foo)
>> 							  (list 42 (foo)))
>
> Sorry, you are right, but then the condition-case "swallows" the error.
> Not sure what can be done about that.

condition-case-unless-debug?

-- 
Ihor Radchenko,
Org mode contributor,
Learn more about Org mode at https://orgmode.org/.
Support Org development at https://liberapay.com/org-mode,
or support my work at https://liberapay.com/yantar92




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 09:28:01 GMT) Full text and rfc822 format available.

Message #43 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Ihor Radchenko <yantar92 <at> gmail.com>
Cc: Lars Ingebrigtsen <larsi <at> gnus.org>, Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 11:27:01 +0200
Ihor Radchenko <yantar92 <at> gmail.com> writes:

> Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:
>
>> On 22-08-27 16:29 , Lars Ingebrigtsen wrote:
>>> 			  (args-574 (condition-case err (let ( foo)
>>> 							  (list 42 (foo)))
>>
>> Sorry, you are right, but then the condition-case "swallows" the error.
>> Not sure what can be done about that.
>
> condition-case-unless-debug?

Well, that's a nice fretwork :-)

When I expand the er-deftest form I get something like this

(progn
  (ert-set-test 'f
		(record 'ert-test 'f nil
			#'(lambda nil
			    (setq debug-on-error t)
			    (defalias 'foo
			      #'(lambda nil
				  (bar)))
			    (defalias 'bar
			      #'(lambda nil
				  (zot)))
			    (let*
				((fn-339 #'equal)
				 (args-340
				  (condition-case err
				      (let
					  ((signal-hook-function #'ert--should-signal-hook))
					(list 42
					      (foo)))
				    (error
				     (progn
				       (setq fn-339 #'signal)
				       (list
					(car err)
					(cdr err)))))))
...

Note the binding of signal-hook-function, which is missing from Lars'
expansion result, where is says

		   (let* ((fn-573 #'equal)
			  (args-574 (condition-case err (let ( foo)
							  (list 42 (foo)))
				      (error (progn
					       (setq fn-573 #'signal)
					       (list (car err) (cdr
			  err)))))))

I can't explain that.

Anyway, let's assume that signal-hook-function is set. and the test is
run.  This is done in ert--run-test-internal.  That function binds
debug-on-error to t, and debugger to a lambda invoking
ert--run-test-debugger.

When our error is signaled, ert--should-signal-hook does nothing because
the error is not one of (ert-test-failed ert-test-skipped).  So
ert--run-test-debugger is not run during the original signal.  Not from
the signal-hook-function, because it doesn't want to, and not otherwise
because of the condition-case.

Instead, this part of the test expansion comes into play:

			      (let
				  ((value-341 'ert-form-evaluation-aborted-342))
				(let
				    (form-description-343)
				  (if
				      (unwind-protect
					  (setq value-341
						(apply fn-339 args-340))

Note that fn-339 has been set to signal in the condition-case.  Since
debug-on-error is t, the apply in the last line calls signal and we land
in ert--run-test-debugger.  The debugger than records the backtrace,
which is of course not the original backtrace.

So, what can we do?

I assume there is a good reason that the signal hook function doesn't
invoke the debugger?  Or in other words, what breaks when the debugger
is always invoked, which it would with condition-case-unless-error?
(That would be when ert-fail or ert-skip are used in tests.)

I don't know.

Interestingly with condition-case-unless I get one less error with make
check:

With condition-case-unless-debug:
SUMMARY OF TEST RESULTS
-----------------------
Files examined: 445
Ran 6582 tests, 6410 results as expected, 7 unexpected, 165 skipped
5 files contained unexpected results:
  lisp/subr-tests.log
  lisp/ls-lisp-tests.log
  lisp/emacs-lisp/ert-tests.log
  lisp/emacs-lisp/edebug-tests.log

With condition-case:
SUMMARY OF TEST RESULTS
-----------------------
Files examined: 445
Ran 6582 tests, 6409 results as expected, 8 unexpected, 165 skipped
6 files contained unexpected results:
  src/process-tests.log
  lisp/subr-tests.log
  lisp/ls-lisp-tests.log
  lisp/emacs-lisp/ert-tests.log
  lisp/emacs-lisp/edebug-tests.log
  lisp/emacs-lisp/cl-lib-tests.log

Could others try this on their platforms/with their test suites?

From 8154955c5ff056d60b6bcd0b4b2dd234c33f0a75 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Gerd=20M=C3=B6llmann?= <gerd <at> gnu.org>
Date: Sun, 28 Aug 2022 11:23:00 +0200
Subject: [PATCH] Let ERT test definitions use condition-case-unless-debug

* lisp/emacs-lisp/ert.el (ert--expand-should-1): Use
condition-case-unless-debug in test expansion (bug#50629).
---
 lisp/emacs-lisp/ert.el | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/lisp/emacs-lisp/ert.el b/lisp/emacs-lisp/ert.el
index 047b0069bb..a8fe14aa6d 100644
--- a/lisp/emacs-lisp/ert.el
+++ b/lisp/emacs-lisp/ert.el
@@ -319,7 +319,9 @@ ert--expand-should-1
               (value (gensym "value-"))
               (default-value (gensym "ert-form-evaluation-aborted-")))
           `(let* ((,fn (function ,fn-name))
-                  (,args (condition-case err
+                  ;; Use condition-case-unless-debug to let the debugger record
+                  ;; the original backtrace when a signal occurs.
+                  (,args (condition-case-unless-debug err
                              (let ((signal-hook-function #'ert--should-signal-hook))
                                (list ,@arg-forms))
                            (error (progn (setq ,fn #'signal)
-- 
2.37.2





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 10:04:01 GMT) Full text and rfc822 format available.

Message #46 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 Ihor Radchenko <yantar92 <at> gmail.com>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 12:03:07 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> Interestingly with condition-case-unless I get one less error with make
> check:

Are you sure you removed all the .elc files under test first?  Since
this is a change in an ert macro, you have to do that to get meaningful
results.

Anyway, that condition-case is presumably there to allow checking for
failures?  I.e., the :expected stuff.

Instead of altering removing the condition-case there, wouldn't it be
possible to output the backtrace explicitly in the handler?





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 10:32:01 GMT) Full text and rfc822 format available.

Message #49 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 Ihor Radchenko <yantar92 <at> gmail.com>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 12:31:20 +0200
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:
>
>> Interestingly with condition-case-unless I get one less error with make
>> check:
>
> Are you sure you removed all the .elc files under test first?  Since
> this is a change in an ert macro, you have to do that to get meaningful
> results.

I did a make -C test clean, but now that you say it I checked, and make
clean does not remove elcs.  Which I personally find surprising.

I'll check with elcs removed between runs later.

> Anyway, that condition-case is presumably there to allow checking for
> failures?  I.e., the :expected stuff.

Ok.

> Instead of altering removing the condition-case there, wouldn't it be
> possible to output the backtrace explicitly in the handler?

You mean the signal-hook-function?  It is invoked, so one can do
something there.  If it would invoke the debugger, that would also work,
I think, but I haven't checked.  Directly outputting something there is
probably not a good idea.  If anything it should record the backtrace in
ERT result structs, like ERT's debugger function.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 10:44:01 GMT) Full text and rfc822 format available.

Message #52 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: 50629 <at> debbugs.gnu.org, Ihor Radchenko <yantar92 <at> gmail.com>,
 Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 12:43:18 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> Lars Ingebrigtsen <larsi <at> gnus.org> writes:
>> Are you sure you removed all the .elc files under test first?  Since
>> this is a change in an ert macro, you have to do that to get meaningful
>> results.

> I'll check with elcs removed between runs later.

Before I forget this, I did it rather now, and indeed I see more errors
with condition-case-unless-debug.  The output with condition-case shows
only 2 errors

Ran 6582 tests, 6415 results as expected, 2 unexpected, 165 skipped




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Sun, 28 Aug 2022 12:27:01 GMT) Full text and rfc822 format available.

Message #55 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: 50629 <at> debbugs.gnu.org, Ihor Radchenko <yantar92 <at> gmail.com>,
 Mike Kupfer <mkupfer <at> alum.berkeley.edu>
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Sun, 28 Aug 2022 14:25:54 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> You mean the signal-hook-function?  It is invoked, so one can do
> something there.  If it would invoke the debugger, that would also work,
> I think, but I haven't checked.

I take that back after trying it.

I'll let this rest, maybe I get some other idea.

(I think using only a debugger function like now and neither a
signal-hook-function nor condition-case could work better, but for that
one has to rewrite a lot, and that's a bit too much programming for me,
ATM.)




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Mon, 29 Aug 2022 14:47:02 GMT) Full text and rfc822 format available.

Message #58 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 Ihor Radchenko <yantar92 <at> gmail.com>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Mon, 29 Aug 2022 16:46:21 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

>> Instead of altering removing the condition-case there, wouldn't it be
>> possible to output the backtrace explicitly in the handler?
>
> You mean the signal-hook-function?  It is invoked, so one can do
> something there.

No, I was thinking in the

			  (args-574 (condition-case err (let ( foo)
							  (list 42 (foo)))
				      (error (progn
					       (setq fn-573 #'signal)

`error' handler here...




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Mon, 29 Aug 2022 15:21:02 GMT) Full text and rfc822 format available.

Message #61 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Gerd Möllmann <gerd.moellmann <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 Ihor Radchenko <yantar92 <at> gmail.com>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Mon, 29 Aug 2022 17:20:03 +0200
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:
>> You mean the signal-hook-function?  It is invoked, so one can do
>> something there.
>
> No, I was thinking in the
>
> 			  (args-574 (condition-case err (let ( foo)
> 							  (list 42 (foo)))
> 				      (error (progn
> 					       (setq fn-573 #'signal)
>
> `error' handler here...

I'm afraid that's too late.  The stack frames of the error have already
been unwound when we are back in the condition-case.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#50629; Package emacs. (Mon, 29 Aug 2022 15:29:02 GMT) Full text and rfc822 format available.

Message #64 received at 50629 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Gerd Möllmann <gerd.moellmann <at> gmail.com>
Cc: Mike Kupfer <mkupfer <at> alum.berkeley.edu>,
 Ihor Radchenko <yantar92 <at> gmail.com>, 50629 <at> debbugs.gnu.org
Subject: Re: bug#50629: 28.0.50; hard to debug an uncaught error with ert
Date: Mon, 29 Aug 2022 17:28:44 +0200
Gerd Möllmann <gerd.moellmann <at> gmail.com> writes:

> I'm afraid that's too late.  The stack frames of the error have already
> been unwound when we are back in the condition-case.

Darn.  I thought I remembered there was a way to get at the backtrace
while in an error handler in a condition-case, but that I just couldn't
remember how.  :-/





Removed tag(s) moreinfo. Request was from Lars Ingebrigtsen <larsi <at> gnus.org> to control <at> debbugs.gnu.org. (Tue, 27 Sep 2022 12:50:02 GMT) Full text and rfc822 format available.

Forcibly Merged 50629 58941. Request was from Stefan Kangas <stefankangas <at> gmail.com> to control <at> debbugs.gnu.org. (Tue, 01 Nov 2022 10:00:03 GMT) Full text and rfc822 format available.

This bug report was last modified 2 years and 227 days ago.

Previous Next


GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.