debugging post command hook max-lisp-eval-depth

debugging post command hook max-lisp-eval-depth

[John Shahid]

Hi all,

every now and then my Emacs will get in a bad state because of some
infinite recursion in the post-command-hook. I am reaching out for ideas
on how to debug Emacs when it gets into this weird state. Keep in mind
that it is hard to do anything with Emacs at that point since any
command (switching buffer, starting debugger) will fail with the same
error `Lisp nesting exceeds...'.

I don't know when this started happening and can't easily debug/bisect
my configuration since this situation happens rarely and intermittently
(2 or 3 times last week).

What I currently have is the following post-command-hook in init.el (not
sure how useful it will be) to stop the infinite recursion:

    (defvar debug-post-command-hook-count nil)

    (defun debug-post-command-hook ()
      (let ((debug-post-command-hook-count (1+ (or debug-post-command-hook-count 0))))
        (if (> debug-post-command-hook-count 10)
            (debug)
          (print (format "post-command-hook %d %S"
                         debug-post-command-hook-count
                         (current-buffer))
                 #'external-debugging-output))))

    (add-hook 'post-command-hook #'debug-post-command-hook)

I also compiled emacs with no optimization and debug symbols (using info
in etc/DEBUG) and planning to use `xbacktrace' when I run into that
situation.

Do you have any other ideas to prepare me for when this happens again ?

p.s. my emacs version is "4a7e74fea687011ee81dcbb02294bccd99b3a05f". I
tried to use the latest commit but ran into weird issues during
redisplay (where Emacs would end up in die()) and autocompletion (where
the candidates left edge isn't lined up properly), but I decided to
ignore those issues for now and stick with the previous revision.

-js

Re: debugging post command hook max-lisp-eval-depth

[Stefan Monnier]

> every now and then my Emacs will get in a bad state because of some
> infinite recursion in the post-command-hook. I am reaching out for ideas
> on how to debug Emacs when it gets into this weird state. Keep in mind
> that it is hard to do anything with Emacs at that point since any
> command (switching buffer, starting debugger) will fail with the same
> error `Lisp nesting exceeds...'.

Hmm... post-command-hook is run via `safe_run_hooks` which is supposed
to try and catch errors such that when an error is caught the
corresponding function is removed from post-command-hook.

Of course, this is a just a mitigating factor, but it should prevent the
problem you describe, except in those cases where the offending function
is constantly re-added (e.g. by a pre-command-hook).

Another approach is something like:

    (advice-add 'debug :around
      (lambda (&rest args)
        (let ((post-command-hook nil))
          (apply args))))


-- Stefan

Re: debugging post command hook max-lisp-eval-depth

[John Shahid]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

> Hmm... post-command-hook is run via `safe_run_hooks` which is supposed
> to try and catch errors such that when an error is caught the
> corresponding function is removed from post-command-hook.

I don't think there is a specific hook that is recursing infinitely. The
two I noticed in the error message were both global minor modes
(magit-file-mode & display-line-numbers).

>
> Of course, this is a just a mitigating factor, but it should prevent the
> problem you describe, except in those cases where the offending function
> is constantly re-added (e.g. by a pre-command-hook).

I think that's the case, `define-globalized-minor-mode' will add the
post-command-hook in MODE-cmhh.

>
> Another approach is something like:
>
>     (advice-add 'debug :around
>       (lambda (&rest args)
>         (let ((post-command-hook nil))
>           (apply args))))

That's a great idea. Thanks!

Re: debugging post command hook max-lisp-eval-depth

[Stefan Monnier]

>> Hmm... post-command-hook is run via `safe_run_hooks` which is supposed
>> to try and catch errors such that when an error is caught the
>> corresponding function is removed from post-command-hook.
> I don't think there is a specific hook that is recursing infinitely. The
> two I noticed in the error message were both global minor modes
> (magit-file-mode & display-line-numbers).

Hmm... I don't understand what you mean: when you say "I don't think
there is a specific hook that is recursing infinitely" do you mean hook
as in "post-command-hook" or in "one of the functions placed on
post-command-hook"?

Then you say "the two ... were global minor modes", but I fail to see
how a "hook" can be a "minor mode".

>> Of course, this is a just a mitigating factor, but it should prevent the
>> problem you describe, except in those cases where the offending function
>> is constantly re-added (e.g. by a pre-command-hook).
> I think that's the case, `define-globalized-minor-mode' will add the
> post-command-hook in MODE-cmhh.

Now that I think about it, the message you get should say which hook
function had an error, since the message is emitted with:

  AUTO_STRING (format, "Error in %s (%S): %S");
  Lisp_Object hook = args[0];
  Lisp_Object fun = args[1];
  CALLN (Fmessage, format, hook, fun, error);

where `fun` is the function during which the error was signaled.

So if you only get "Lisp nesting exceeds...", check your *Messages* and
if even there you don't have the "Error in ... (...): ..." message, it
means that the error was most likely signaled elsewhere than in
post-command-hook.


        Stefan

Re: debugging post command hook max-lisp-eval-depth

[John Shahid]

On Mon, Jun 18, 2018, 10:03 AM Stefan Monnier <monnier@iro.umontreal.ca>
wrote:

> >> Hmm... post-command-hook is run via `safe_run_hooks` which is supposed
> >> to try and catch errors such that when an error is caught the
> >> corresponding function is removed from post-command-hook.
> > I don't think there is a specific hook that is recursing infinitely. The
> > two I noticed in the error message were both global minor modes
> > (magit-file-mode & display-line-numbers).
>
> Hmm... I don't understand what you mean: when you say "I don't think
> there is a specific hook that is recursing infinitely" do you mean hook
> as in "post-command-hook" or in "one of the functions placed on
> post-command-hook"?
>
> Then you say "the two ... were global minor modes", but I fail to see
> how a "hook" can be a "minor mode".
>

Sorry, I meant functions placed on the hook.


> >> Of course, this is a just a mitigating factor, but it should prevent the
> >> problem you describe, except in those cases where the offending function
> >> is constantly re-added (e.g. by a pre-command-hook).
> > I think that's the case, `define-globalized-minor-mode' will add the
> > post-command-hook in MODE-cmhh.
>
> Now that I think about it, the message you get should say which hook
> function had an error, since the message is emitted with:
>
>   AUTO_STRING (format, "Error in %s (%S): %S");
>   Lisp_Object hook = args[0];
>   Lisp_Object fun = args[1];
>   CALLN (Fmessage, format, hook, fun, error);
>
> where `fun` is the function during which the error was signaled.
>

That's what I was trying to explain above. The function name in the error
message isn't consistent.


> So if you only get "Lisp nesting exceeds...", check your *Messages* and
> if even there you don't have the "Error in ... (...): ..." message, it
> means that the error was most likely signaled elsewhere than in
> post-command-hook.
>
>
>         Stefan
>

Re: debugging post command hook max-lisp-eval-depth

[Stefan Monnier]

> That's what I was trying to explain above. The function name in the error
> message isn't consistent.

Sorry, but I don't know what you mean by "name is not consistent".


        Stefan

Re: debugging post command hook max-lisp-eval-depth

[John Shahid]

On Mon, Jun 18, 2018, 12:53 PM Stefan Monnier <monnier@iro.umontreal.ca>
wrote:

> > That's what I was trying to explain above. The function name in the error
> > message isn't consistent.
>
> Sorry, but I don't know what you mean by "name is not consistent".
>

I'm seeing different function names in the error message.


>
>         Stefan
>

Re: debugging post command hook max-lisp-eval-depth

[John Shahid]

I have been running the debug version of emacs for a few days now and I
cannot reproduce the problem. The hooks I saw in the error message
(`global-display-line-numbers-mode' & `global-magit-file-mode') don't
have any recursive calls. I don't understand how they recurse
indefinitely. Could this be caused by some stale .elc files ? It doesn't
look like `define-globalized-minor-mode' has changed recently, so I
don't understand how a stale .elc file would cause that.

p.s. I will give it another day then switch back to an optimized version
of Emacs.

John Shahid <jvshahid@gmail.com> writes:

> On Mon, Jun 18, 2018, 12:53 PM Stefan Monnier <monnier@iro.umontreal.ca>
> wrote:
>
>> > That's what I was trying to explain above. The function name in the error
>> > message isn't consistent.
>>
>> Sorry, but I don't know what you mean by "name is not consistent".
>>
>
> I'm seeing different function names in the error message.
>
>
>>
>>         Stefan
>>

Re: debugging post command hook max-lisp-eval-depth

[Stefan Monnier]

> (`global-display-line-numbers-mode' & `global-magit-file-mode') don't

Neither of those should normally ever appear on post-command-hook, AFAIK.

> have any recursive calls.

I'd look at some code shared by the two minor modes, tho maybe it
happened via an advice or a function place on both minor mode's hooks
(i.e. the minor modes aren't directly related, except as "vehicles").

> Could this be caused by some stale .elc files ?

Technically, yes.  But there are many other possibilities, just as (un)likely.


        Stefan

Re: debugging post command hook max-lisp-eval-depth

[Leo Liu]

On 2018-06-20 17:53 -0400, Stefan Monnier wrote:
>> have any recursive calls.
>
> I'd look at some code shared by the two minor modes, tho maybe it
> happened via an advice or a function place on both minor mode's hooks
> (i.e. the minor modes aren't directly related, except as "vehicles").

I wonder if this is a similar bug https://debbugs.gnu.org/31793. There
is a recipe to reliably render emacs unusable in the report.

Leo

Re: debugging post command hook max-lisp-eval-depth

[John Shahid]

Leo Liu <sdl.web@gmail.com> writes:

> On 2018-06-20 17:53 -0400, Stefan Monnier wrote:
>>> have any recursive calls.
>>
>> I'd look at some code shared by the two minor modes, tho maybe it
>> happened via an advice or a function place on both minor mode's hooks
>> (i.e. the minor modes aren't directly related, except as "vehicles").
>
> I wonder if this is a similar bug https://debbugs.gnu.org/31793. There
> is a recipe to reliably render emacs unusable in the report.

I submitted a patch for the bug you mentioned above. I'm not sure if I'm
running into the same problem as you are. Either way, I'll run with the
patch for a few days to see whether it fixes my issue.