emacs-buttercup icon indicating copy to clipboard operation
emacs-buttercup copied to clipboard

Trace formatting takes ages (with mutual refs?)

Open jscheid opened this issue 3 years ago • 4 comments

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.

jscheid avatar Jun 26 '22 09:06 jscheid

Have you tried setting print-circle to t as described by @alphapapa in https://github.com/jorgenschaefer/emacs-buttercup/issues/218#issuecomment-1151658577 ?

snogge avatar Jun 27 '22 23:06 snogge

@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.

jscheid avatar Jun 28 '22 07:06 jscheid

It's very possible that print-level and print-length cuts of before print-circle` in this case. Backtraces obviously need some work.

snogge avatar Jun 29 '22 20:06 snogge

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

alphapapa avatar Jun 30 '22 09:06 alphapapa