unofficial mirror of bug-gnu-emacs@gnu.org 
 help / color / mirror / code / Atom feed
* bug#50629: 28.0.50; hard to debug an uncaught error with ert
@ 2021-09-16 23:28 Mike Kupfer
  2022-08-26 11:41 ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Mike Kupfer @ 2021-09-16 23:28 UTC (permalink / raw)
  To: 50629

(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))





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2021-09-16 23:28 bug#50629: 28.0.50; hard to debug an uncaught error with ert Mike Kupfer
@ 2022-08-26 11:41 ` Lars Ingebrigtsen
  2022-08-26 13:52   ` Gerd Möllmann
  0 siblings, 1 reply; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-26 11:41 UTC (permalink / raw)
  To: Mike Kupfer; +Cc: 50629

Mike Kupfer <mkupfer@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?





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-26 11:41 ` Lars Ingebrigtsen
@ 2022-08-26 13:52   ` Gerd Möllmann
  2022-08-27 13:20     ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-26 13:52 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: 50629, Mike Kupfer

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Mike Kupfer <mkupfer@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)





^ permalink raw reply related	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-26 13:52   ` Gerd Möllmann
@ 2022-08-27 13:20     ` Lars Ingebrigtsen
  2022-08-27 13:44       ` Gerd Möllmann
  0 siblings, 1 reply; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-27 13:20 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: 50629, Mike Kupfer

Gerd Möllmann <gerd.moellmann@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.






^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 13:20     ` Lars Ingebrigtsen
@ 2022-08-27 13:44       ` Gerd Möllmann
  2022-08-27 13:52         ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-27 13:44 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Mike Kupfer, 50629

Lars Ingebrigtsen <larsi@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?





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 13:44       ` Gerd Möllmann
@ 2022-08-27 13:52         ` Lars Ingebrigtsen
  2022-08-27 14:06           ` Gerd Möllmann
  0 siblings, 1 reply; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-27 13:52 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Mike Kupfer, 50629

Gerd Möllmann <gerd.moellmann@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.





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 13:52         ` Lars Ingebrigtsen
@ 2022-08-27 14:06           ` Gerd Möllmann
  2022-08-27 14:29             ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-27 14:06 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Mike Kupfer, 50629

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Gerd Möllmann <gerd.moellmann@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.






^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 14:06           ` Gerd Möllmann
@ 2022-08-27 14:29             ` Lars Ingebrigtsen
  2022-08-27 14:38               ` Mike Kupfer
  2022-08-27 15:13               ` Gerd Möllmann
  0 siblings, 2 replies; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-27 14:29 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Mike Kupfer, 50629

Gerd Möllmann <gerd.moellmann@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.





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 14:29             ` Lars Ingebrigtsen
@ 2022-08-27 14:38               ` Mike Kupfer
  2022-08-27 14:40                 ` Lars Ingebrigtsen
  2022-08-27 15:13               ` Gerd Möllmann
  1 sibling, 1 reply; 20+ messages in thread
From: Mike Kupfer @ 2022-08-27 14:38 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Gerd Möllmann, 50629

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





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 14:38               ` Mike Kupfer
@ 2022-08-27 14:40                 ` Lars Ingebrigtsen
  0 siblings, 0 replies; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-27 14:40 UTC (permalink / raw)
  To: Mike Kupfer; +Cc: Gerd Möllmann, 50629

Mike Kupfer <mkupfer@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.  😀





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 14:29             ` Lars Ingebrigtsen
  2022-08-27 14:38               ` Mike Kupfer
@ 2022-08-27 15:13               ` Gerd Möllmann
  2022-08-28  1:21                 ` Ihor Radchenko
  1 sibling, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-27 15:13 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Mike Kupfer, 50629

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.





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-27 15:13               ` Gerd Möllmann
@ 2022-08-28  1:21                 ` Ihor Radchenko
  2022-08-28  9:27                   ` Gerd Möllmann
  0 siblings, 1 reply; 20+ messages in thread
From: Ihor Radchenko @ 2022-08-28  1:21 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Lars Ingebrigtsen, 50629, Mike Kupfer

Gerd Möllmann <gerd.moellmann@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





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28  1:21                 ` Ihor Radchenko
@ 2022-08-28  9:27                   ` Gerd Möllmann
  2022-08-28 10:03                     ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-28  9:27 UTC (permalink / raw)
  To: Ihor Radchenko; +Cc: Lars Ingebrigtsen, Mike Kupfer, 50629

Ihor Radchenko <yantar92@gmail.com> writes:

> Gerd Möllmann <gerd.moellmann@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@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






^ permalink raw reply related	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28  9:27                   ` Gerd Möllmann
@ 2022-08-28 10:03                     ` Lars Ingebrigtsen
  2022-08-28 10:31                       ` Gerd Möllmann
  0 siblings, 1 reply; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-28 10:03 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Mike Kupfer, Ihor Radchenko, 50629

Gerd Möllmann <gerd.moellmann@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?






^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28 10:03                     ` Lars Ingebrigtsen
@ 2022-08-28 10:31                       ` Gerd Möllmann
  2022-08-28 10:43                         ` Gerd Möllmann
                                           ` (2 more replies)
  0 siblings, 3 replies; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-28 10:31 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Mike Kupfer, Ihor Radchenko, 50629

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Gerd Möllmann <gerd.moellmann@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.





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28 10:31                       ` Gerd Möllmann
@ 2022-08-28 10:43                         ` Gerd Möllmann
  2022-08-28 12:25                         ` Gerd Möllmann
  2022-08-29 14:46                         ` Lars Ingebrigtsen
  2 siblings, 0 replies; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-28 10:43 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: 50629, Ihor Radchenko, Mike Kupfer

Gerd Möllmann <gerd.moellmann@gmail.com> writes:

> Lars Ingebrigtsen <larsi@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





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28 10:31                       ` Gerd Möllmann
  2022-08-28 10:43                         ` Gerd Möllmann
@ 2022-08-28 12:25                         ` Gerd Möllmann
  2022-08-29 14:46                         ` Lars Ingebrigtsen
  2 siblings, 0 replies; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-28 12:25 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: 50629, Ihor Radchenko, Mike Kupfer

Gerd Möllmann <gerd.moellmann@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.)





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-28 10:31                       ` Gerd Möllmann
  2022-08-28 10:43                         ` Gerd Möllmann
  2022-08-28 12:25                         ` Gerd Möllmann
@ 2022-08-29 14:46                         ` Lars Ingebrigtsen
  2022-08-29 15:20                           ` Gerd Möllmann
  2 siblings, 1 reply; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-29 14:46 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Mike Kupfer, Ihor Radchenko, 50629

Gerd Möllmann <gerd.moellmann@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...





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-29 14:46                         ` Lars Ingebrigtsen
@ 2022-08-29 15:20                           ` Gerd Möllmann
  2022-08-29 15:28                             ` Lars Ingebrigtsen
  0 siblings, 1 reply; 20+ messages in thread
From: Gerd Möllmann @ 2022-08-29 15:20 UTC (permalink / raw)
  To: Lars Ingebrigtsen; +Cc: Mike Kupfer, Ihor Radchenko, 50629

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Gerd Möllmann <gerd.moellmann@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.





^ permalink raw reply	[flat|nested] 20+ messages in thread

* bug#50629: 28.0.50; hard to debug an uncaught error with ert
  2022-08-29 15:20                           ` Gerd Möllmann
@ 2022-08-29 15:28                             ` Lars Ingebrigtsen
  0 siblings, 0 replies; 20+ messages in thread
From: Lars Ingebrigtsen @ 2022-08-29 15:28 UTC (permalink / raw)
  To: Gerd Möllmann; +Cc: Mike Kupfer, Ihor Radchenko, 50629

Gerd Möllmann <gerd.moellmann@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.  :-/






^ permalink raw reply	[flat|nested] 20+ messages in thread

end of thread, other threads:[~2022-08-29 15:28 UTC | newest]

Thread overview: 20+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-09-16 23:28 bug#50629: 28.0.50; hard to debug an uncaught error with ert Mike Kupfer
2022-08-26 11:41 ` Lars Ingebrigtsen
2022-08-26 13:52   ` Gerd Möllmann
2022-08-27 13:20     ` Lars Ingebrigtsen
2022-08-27 13:44       ` Gerd Möllmann
2022-08-27 13:52         ` Lars Ingebrigtsen
2022-08-27 14:06           ` Gerd Möllmann
2022-08-27 14:29             ` Lars Ingebrigtsen
2022-08-27 14:38               ` Mike Kupfer
2022-08-27 14:40                 ` Lars Ingebrigtsen
2022-08-27 15:13               ` Gerd Möllmann
2022-08-28  1:21                 ` Ihor Radchenko
2022-08-28  9:27                   ` Gerd Möllmann
2022-08-28 10:03                     ` Lars Ingebrigtsen
2022-08-28 10:31                       ` Gerd Möllmann
2022-08-28 10:43                         ` Gerd Möllmann
2022-08-28 12:25                         ` Gerd Möllmann
2022-08-29 14:46                         ` Lars Ingebrigtsen
2022-08-29 15:20                           ` Gerd Möllmann
2022-08-29 15:28                             ` Lars Ingebrigtsen

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).