emacs-buttercup
emacs-buttercup copied to clipboard
Trace formatting takes ages (with mutual refs?)
tl;dr backtrace formatting took around ~40 seconds for 10 failed tests and then didn't output any stack.
It's more or less instant and prints a useful stack with this:
(defun buttercup--format-stack-frame--print-limits (orig-fun &rest args)
"Limit `print-level' and `print-length' in ORIG-FUN, forward ARGS."
(let ((print-level eval-expression-print-level)
(print-length eval-expression-print-length))
(apply orig-fun args)))
(advice-add 'buttercup--format-stack-frame
:around #'buttercup--format-stack-frame--print-limits)
My best guess is that what happens is the following:
I have mutual references on the stack, something like:
(cl-defstruct a b)
(cl-defstruct b a)
(let ((a (make-a))
(b (make-b)))
(setf (a-b a) b)
(setf (b-a b) a)
(func-that-errors a))
Because print-level and print-length are nil by default (at least when running in makem), prin1-to-string goes into infinite recursion probably until max-specpdl-size is exhausted.
I've solved this problem for myself but I had to spend an hour or so debugging it. I recommend making a similar setting the default.
Have you tried setting print-circle to t as described by @alphapapa in https://github.com/jorgenschaefer/emacs-buttercup/issues/218#issuecomment-1151658577 ?
@snogge good idea, I forgot about print-circle, thank you.
It seems like it should be exactly what is needed in my case, however I've tried just now and for some reason it doesn't help as much as print-level and print-length as far as wall time performance goes. In fact is seems to add about 1s to the formatting time, not sure why.
It's very possible that print-level and print-length cuts of before print-circle` in this case.
Backtraces obviously need some work.
Yes, if the recursive structures are large enough, the level and length cutoffs could have a larger effect than print-circle.
It might be good for Buttercup to bind print-circle non-nil by default, anyway (around whatever code prints the backtraces).
In fact is seems to add about 1s to the formatting time, not sure why.
IIUC print-circle uses a hash table to track which items have been seen already, which can be some additional overhead, I guess (though whether that overhead is more than that of printing an item depends on the item, I suppose).