unofficial mirror of emacs-devel@gnu.org 
 help / color / mirror / code / Atom feed
* undo-auto--undoable-change infloop
@ 2022-07-26  3:54 Michael Heerdegen
  2022-07-26 12:04 ` Eli Zaretskii
  0 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-26  3:54 UTC (permalink / raw)
  To: Emacs Development

Hello,

does somebody have a guess what is happening here?  After automatically
replacing thousands of matches in a buffer with my el-search, I got a
sluggish Emacs afterwards, after a short pause.  Emacs consumed 100% of
one CPU.  It took me hours to find something, and it seems to be
unrelated to my own code: `undo-auto--undoable-change'.  It seems to
recurse very deep, or to be called extremely often.  I managed to
produce a backtrace, see below.  How is that recursion even possible -
what could be going on?

TIA,

Michael


The backtrace (the first cursor blink afterwards seems to initiate the
problematic behavior):

  (timer-activate [t 25311 13221 560142 nil undo-auto--boundary-timer nil nil 540000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13220 972130 nil undo-auto--boundary-timer nil nil 860000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13220 562017 nil undo-auto--boundary-timer nil nil 682000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13220 175101 nil undo-auto--boundary-timer nil nil 375000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13219 728313 nil undo-auto--boundary-timer nil nil 962000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13219 407621 nil undo-auto--boundary-timer nil nil 486000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13219 71400 nil undo-auto--boundary-timer nil nil 128000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13218 786464 nil undo-auto--boundary-timer nil nil 766000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13218 551162 nil undo-auto--boundary-timer nil nil 891000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13218 258788 nil undo-auto--boundary-timer nil nil 94000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13218 89932 nil undo-auto--boundary-timer nil nil 31000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13217 955384 nil undo-auto--boundary-timer nil nil 756000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13217 847383 nil undo-auto--boundary-timer nil nil 663000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13217 765424 nil undo-auto--boundary-timer nil nil 571000 nil])
  (run-at-time 10 nil undo-auto--boundary-timer)
  (undo-auto--boundary-ensure-timer)
  (undo-auto--undoable-change)
  (timer-activate [t 25311 13207 807483 0.15 blink-cursor-timer-function nil nil 407999 nil])
  (run-at-time 0.15 0.15 blink-cursor-timer-function)
  (run-with-timer 0.15 0.15 blink-cursor-timer-function)
  (blink-cursor--start-timer)
  (blink-cursor-start)

When I redefine `undo-auto--undoable-change' with an empty body, the
problem disappears.  I could not reproduce something similar with normal
query-replace.



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

* Re: undo-auto--undoable-change infloop
  2022-07-26  3:54 undo-auto--undoable-change infloop Michael Heerdegen
@ 2022-07-26 12:04 ` Eli Zaretskii
  2022-07-27  3:52   ` Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-26 12:04 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Date: Tue, 26 Jul 2022 05:54:42 +0200
> 
> does somebody have a guess what is happening here?  After automatically
> replacing thousands of matches in a buffer with my el-search, I got a
> sluggish Emacs afterwards, after a short pause.  Emacs consumed 100% of
> one CPU.  It took me hours to find something, and it seems to be
> unrelated to my own code: `undo-auto--undoable-change'.  It seems to
> recurse very deep, or to be called extremely often.  I managed to
> produce a backtrace, see below.  How is that recursion even possible -
> what could be going on?

I don't know what happened, but undo-auto--boundary-timer is invoked
10 sec after the timer is set.  Perhaps this kind of problem can
happen when there are many undoable changes, and processing them takes
more than 10 sec?



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

* Re: undo-auto--undoable-change infloop
  2022-07-26 12:04 ` Eli Zaretskii
@ 2022-07-27  3:52   ` Michael Heerdegen
  2022-07-27  4:56     ` Michael Heerdegen
                       ` (2 more replies)
  0 siblings, 3 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-27  3:52 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Eli Zaretskii <eliz@gnu.org> writes:

> I don't know what happened, but undo-auto--boundary-timer is invoked
> 10 sec after the timer is set.  Perhaps this kind of problem can
> happen when there are many undoable changes, and processing them takes
> more than 10 sec?

Maybe what I saw is only an artifact from debugging and tracing (which
also inserts into buffers...)

I'm totally unsure what is going on.  Is there anything I could try to
turn off?

A CPU profiler report looks like this, with stuff less than 3% removed:

       24220  41% - timer-event-handler
       21654  37%  - timer-activate
       19231  33%   - timer--activate
       17774  30%      timer--time-less-p
       19949  34% - ...
       19949  34%    Automatic GC
       14040  24% + command-execute  ;; actual command execution time
            [...] [...]

This is a very strange result, not saying anything to me.

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-27  3:52   ` Michael Heerdegen
@ 2022-07-27  4:56     ` Michael Heerdegen
  2022-07-27 11:20       ` Eli Zaretskii
  2022-07-27 11:20     ` undo-auto--undoable-change infloop Eli Zaretskii
  2022-07-29 14:49     ` Stefan Monnier
  2 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-27  4:56 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Michael Heerdegen <michael_heerdegen@web.de> writes:

>        24220  41% - timer-event-handler
>        21654  37%  - timer-activate
>        19231  33%   - timer--activate
>        17774  30%      timer--time-less-p
>        19949  34% - ...
>        19949  34%    Automatic GC
>        14040  24% + command-execute  ;; actual command execution time
>             [...] [...]

Though, since redefining `undo-auto--undoable-change' has the effect of
solving the issue, I guess it must be related to undo.

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-27  3:52   ` Michael Heerdegen
  2022-07-27  4:56     ` Michael Heerdegen
@ 2022-07-27 11:20     ` Eli Zaretskii
  2022-07-27 17:06       ` Michael Heerdegen
  2022-07-29 14:49     ` Stefan Monnier
  2 siblings, 1 reply; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-27 11:20 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Cc: emacs-devel@gnu.org
> Date: Wed, 27 Jul 2022 05:52:46 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > I don't know what happened, but undo-auto--boundary-timer is invoked
> > 10 sec after the timer is set.  Perhaps this kind of problem can
> > happen when there are many undoable changes, and processing them takes
> > more than 10 sec?
> 
> Maybe what I saw is only an artifact from debugging and tracing (which
> also inserts into buffers...)
> 
> I'm totally unsure what is going on.  Is there anything I could try to
> turn off?
> 
> A CPU profiler report looks like this, with stuff less than 3% removed:
> 
>        24220  41% - timer-event-handler
>        21654  37%  - timer-activate
>        19231  33%   - timer--activate
>        17774  30%      timer--time-less-p
>        19949  34% - ...
>        19949  34%    Automatic GC
>        14040  24% + command-execute  ;; actual command execution time
>             [...] [...]
> 
> This is a very strange result, not saying anything to me.

Why does it seem strange to you?



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

* Re: undo-auto--undoable-change infloop
  2022-07-27  4:56     ` Michael Heerdegen
@ 2022-07-27 11:20       ` Eli Zaretskii
  2022-07-28  2:51         ` Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-27 11:20 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Cc: emacs-devel@gnu.org
> Date: Wed, 27 Jul 2022 06:56:38 +0200
> 
> Michael Heerdegen <michael_heerdegen@web.de> writes:
> 
> >        24220  41% - timer-event-handler
> >        21654  37%  - timer-activate
> >        19231  33%   - timer--activate
> >        17774  30%      timer--time-less-p
> >        19949  34% - ...
> >        19949  34%    Automatic GC
> >        14040  24% + command-execute  ;; actual command execution time
> >             [...] [...]
> 
> Though, since redefining `undo-auto--undoable-change' has the effect of
> solving the issue, I guess it must be related to undo.

At the risk of saying the obvious: you do know that undo runs a timer
to amalgamate undoable changes?



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

* Re: undo-auto--undoable-change infloop
  2022-07-27 11:20     ` undo-auto--undoable-change infloop Eli Zaretskii
@ 2022-07-27 17:06       ` Michael Heerdegen
  2022-07-27 17:34         ` Eli Zaretskii
  0 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-27 17:06 UTC (permalink / raw)
  To: emacs-devel

Eli Zaretskii <eliz@gnu.org> writes:

> > A CPU profiler report looks like this, with stuff less than 3% removed:
> > 
> >        24220  41% - timer-event-handler
> >        21654  37%  - timer-activate
> >        19231  33%   - timer--activate
> >        17774  30%      timer--time-less-p
> >        19949  34% - ...
> >        19949  34%    Automatic GC
> >        14040  24% + command-execute  ;; actual command execution time
> >             [...] [...]
> > 
> > This is a very strange result, not saying anything to me.
>
> Why does it seem strange to you?

That there is no Lisp function there besides the timer stuff.  Undo
stuff like amalgamating is done in Lisp, so such function(s) should
appear there if they do work or initiate it.  And 30% time spent in
`timer--time-less-p' doesn't look sane.  Seems that function is called
extremely often.

Michael.




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

* Re: undo-auto--undoable-change infloop
  2022-07-27 17:06       ` Michael Heerdegen
@ 2022-07-27 17:34         ` Eli Zaretskii
  2022-07-28  2:45           ` Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-27 17:34 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Date: Wed, 27 Jul 2022 19:06:29 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > > A CPU profiler report looks like this, with stuff less than 3% removed:
> > > 
> > >        24220  41% - timer-event-handler
> > >        21654  37%  - timer-activate
> > >        19231  33%   - timer--activate
> > >        17774  30%      timer--time-less-p
> > >        19949  34% - ...
> > >        19949  34%    Automatic GC
> > >        14040  24% + command-execute  ;; actual command execution time
> > >             [...] [...]
> > > 
> > > This is a very strange result, not saying anything to me.
> >
> > Why does it seem strange to you?
> 
> That there is no Lisp function there besides the timer stuff.  Undo
> stuff like amalgamating is done in Lisp, so such function(s) should
> appear there if they do work or initiate it.  And 30% time spent in
> `timer--time-less-p' doesn't look sane.

It's 30% for timer--time-less-p _and_its_callees_, so you should look
deeper.

The 34% figure for GC also doesn't look good, btw.



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

* Re: undo-auto--undoable-change infloop
  2022-07-27 17:34         ` Eli Zaretskii
@ 2022-07-28  2:45           ` Michael Heerdegen
  0 siblings, 0 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-28  2:45 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Eli Zaretskii <eliz@gnu.org> writes:

> It's 30% for timer--time-less-p _and_its_callees_, so you should look
> deeper.

I don't know how.  The trace is fully expanded, there are no recorded
Lisp callees.

> The 34% figure for GC also doesn't look good, btw.

That, that doesn't look good overall...

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-27 11:20       ` Eli Zaretskii
@ 2022-07-28  2:51         ` Michael Heerdegen
  2022-07-28  3:10           ` Solved (was: undo-auto--undoable-change infloop) Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-28  2:51 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Eli Zaretskii <eliz@gnu.org> writes:

> [...] you do know that undo runs a timer to amalgamate undoable
> changes?

Yes, that was one of my theories.  But then setting
amalgamating-undo-limit to 1 should fix the problem, which isn't the
case.  And the amalgamating functions should also appear in the profiler
output, but there are none.

Michael.



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

* Solved (was: undo-auto--undoable-change infloop)
  2022-07-28  2:51         ` Michael Heerdegen
@ 2022-07-28  3:10           ` Michael Heerdegen
  2022-07-28  5:49             ` Eli Zaretskii
  0 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-28  3:10 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Michael Heerdegen <michael_heerdegen@web.de> writes:

> Eli Zaretskii <eliz@gnu.org> writes:
>
> > [...] you do know that undo runs a timer to amalgamate undoable
> > changes?

But that put me on the right path, thank you very much.

I was using worker buffers.  These were filled, modified and erased
thousands of times in my test scenario.  Doing (setq buffer-undo-list t)
in these buffer solved the problem.  Not sure what Emacs was actually
doing all the time, but the huge gc time probably was spent in
collecting the fallout from the huge undo records.

Thanks for mentioning also the obvious things,

Michael.



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

* Re: Solved (was: undo-auto--undoable-change infloop)
  2022-07-28  3:10           ` Solved (was: undo-auto--undoable-change infloop) Michael Heerdegen
@ 2022-07-28  5:49             ` Eli Zaretskii
  2022-07-29  0:40               ` No, not solved " Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-28  5:49 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Cc: emacs-devel@gnu.org
> Date: Thu, 28 Jul 2022 05:10:52 +0200
> 
> Michael Heerdegen <michael_heerdegen@web.de> writes:
> 
> I was using worker buffers.  These were filled, modified and erased
> thousands of times in my test scenario.  Doing (setq buffer-undo-list t)
> in these buffer solved the problem.

Any reason why you didn't use temporary buffers for that?  AFAIR, undo
is disabled there automatically.

> Not sure what Emacs was actually doing all the time, but the huge gc
> time probably was spent in collecting the fallout from the huge undo
> records.

Yes, makes sense.

> Thanks for mentioning also the obvious things,

Glad I could be of help.



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

* No, not solved (was: undo-auto--undoable-change infloop)
  2022-07-28  5:49             ` Eli Zaretskii
@ 2022-07-29  0:40               ` Michael Heerdegen
  2022-07-29  3:44                 ` No, not solved Michael Heerdegen
  2022-07-29  6:05                 ` No, not solved (was: undo-auto--undoable-change infloop) Eli Zaretskii
  0 siblings, 2 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-29  0:40 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Eli Zaretskii <eliz@gnu.org> writes:

> Any reason why you didn't use temporary buffers for that?  AFAIR, undo
> is disabled there automatically.

I actually do, I use buffers from evaluating

(list (generate-new-buffer " *El-Search Work Buffer A*" t)
      (generate-new-buffer " *El-Search Work Buffer B*" t))

But the problem is back.  After I had checked that `buffer-undo-list'
had been t all the time and my change could not have had an effect at
all, the problem instantly reappeared out of nothing.  I did not change
anything!  This is really mysterious and very frustrating.  I have
wasted hours now for this stuff and do not know a bit more than when it
started.

Michael.



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

* Re: No, not solved
  2022-07-29  0:40               ` No, not solved " Michael Heerdegen
@ 2022-07-29  3:44                 ` Michael Heerdegen
  2022-07-29  4:12                   ` Michael Heerdegen
  2022-07-29  6:05                 ` No, not solved (was: undo-auto--undoable-change infloop) Eli Zaretskii
  1 sibling, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-29  3:44 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Michael Heerdegen <michael_heerdegen@web.de> writes:

> I have wasted hours now for this stuff and do not know a bit more than
> when it started.

Could be it is related to an older package I wrote some years ago.  Will
report back.

Michael.



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

* Re: No, not solved
  2022-07-29  3:44                 ` No, not solved Michael Heerdegen
@ 2022-07-29  4:12                   ` Michael Heerdegen
  0 siblings, 0 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-29  4:12 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: emacs-devel

Michael Heerdegen <michael_heerdegen@web.de> writes:

> Could be it is related to an older package I wrote some years ago.  Will
> report back.

Yes, seems "interaction-log.el" was the culprit.  I'm still not sure
why.  It uses a timer that fires every .1 seconds, but that performs
only trivial tasks that take only much much less time.

In my scenario, for some reason Emacs begins to choke, sometimes.
Making the time span a bit larger (e.g. .5 seconds) seems to help.

Michael.



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

* Re: No, not solved (was: undo-auto--undoable-change infloop)
  2022-07-29  0:40               ` No, not solved " Michael Heerdegen
  2022-07-29  3:44                 ` No, not solved Michael Heerdegen
@ 2022-07-29  6:05                 ` Eli Zaretskii
  1 sibling, 0 replies; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-29  6:05 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Cc: emacs-devel@gnu.org
> Date: Fri, 29 Jul 2022 02:40:11 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > Any reason why you didn't use temporary buffers for that?  AFAIR, undo
> > is disabled there automatically.
> 
> I actually do, I use buffers from evaluating
> 
> (list (generate-new-buffer " *El-Search Work Buffer A*" t)
>       (generate-new-buffer " *El-Search Work Buffer B*" t))
> 
> But the problem is back.  After I had checked that `buffer-undo-list'
> had been t all the time and my change could not have had an effect at
> all, the problem instantly reappeared out of nothing.  I did not change
> anything!  This is really mysterious and very frustrating.  I have
> wasted hours now for this stuff and do not know a bit more than when it
> started.

So what is the problem, again?  Can you describe what your Lisp
program does, and what are the symptoms of the problem when it
happens?

If the problem is with timers, what does list-timers report when the
problem happens?

If you have a reproducible recipe, perhaps submit a bug report.



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

* Re: undo-auto--undoable-change infloop
  2022-07-27  3:52   ` Michael Heerdegen
  2022-07-27  4:56     ` Michael Heerdegen
  2022-07-27 11:20     ` undo-auto--undoable-change infloop Eli Zaretskii
@ 2022-07-29 14:49     ` Stefan Monnier
  2022-07-30  1:14       ` Michael Heerdegen
  2 siblings, 1 reply; 27+ messages in thread
From: Stefan Monnier @ 2022-07-29 14:49 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: Eli Zaretskii, emacs-devel

>        24220  41% - timer-event-handler
>        21654  37%  - timer-activate
>        19231  33%   - timer--activate
>        17774  30%      timer--time-less-p
>        19949  34% - ...
>        19949  34%    Automatic GC
>        14040  24% + command-execute  ;; actual command execution time
>             [...] [...]

Maybe this is a symptom of having way too many timers?


        Stefan




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

* Re: undo-auto--undoable-change infloop
  2022-07-29 14:49     ` Stefan Monnier
@ 2022-07-30  1:14       ` Michael Heerdegen
  2022-07-30  4:14         ` Michael Heerdegen
                           ` (2 more replies)
  0 siblings, 3 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-30  1:14 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

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

> Maybe this is a symptom of having way too many timers?

Maybe.

Could it be that when executing the timer function takes longer than the
0.1 seconds repeat delta, the timer fires again?  I had hoped that I
would handle that by checking the idle time - but when the function is
run, Emacs is still idle (running timers counts as idle AFAIR), although
it is actually quite busy.

I once used an variable watcher on timer-list and saw that it contained
hundreds or thousands of instances of my timer.  But these were not
different instances, I only ever create one timer when stating logging.
Ant the value list looked like (#1=[ilog-timer] #1# #1# ...very very
many #1#s and a few different timers).

Now I'm trying to protect the timer using a flag with the purpose to
prevent the timer function to do anything when the timer function is
currently called.

But does that even make sense, can that happen at all?  Or could it be
that the waiting instances are processed sequentially but take longer to
process than 0.1 seconds - longer than new instances are added?

But that all seems very strange.  Maybe just something is not in
order...?

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-30  1:14       ` Michael Heerdegen
@ 2022-07-30  4:14         ` Michael Heerdegen
  2022-07-30  5:54         ` Eli Zaretskii
  2022-07-30  7:23         ` Stefan Monnier
  2 siblings, 0 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-30  4:14 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

Michael Heerdegen <michael_heerdegen@web.de> writes:

> I once used an variable watcher on timer-list and saw that it contained
> hundreds or thousands of instances of my timer.  But these were not
> different instances, I only ever create one timer when stating logging.
> Ant the value list looked like (#1=[ilog-timer] #1# #1# ...very very
> many #1#s and a few different timers).

BTW, all these copies appear out of nothing: the variable watcher saw
very few timers, and then suddenly that many the next time the
WATCH-FUNCTION was called.  If they would have been added explicitly
from Lisp, I would see intermediate steps AFAIU.

I collected a backtrace from the moment of time when the variable
watcher fired (via WATCH-FUNCTION).  It was totally unrelated and I'm
quite sure that it isn't related.

> Now I'm trying to protect the timer using a flag with the purpose to
> prevent the timer function to do anything when the timer function is
> currently called.
>
> But does that even make sense

After thinking about it, I think it doesn't make sense, and it also
doesn't work.

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-30  1:14       ` Michael Heerdegen
  2022-07-30  4:14         ` Michael Heerdegen
@ 2022-07-30  5:54         ` Eli Zaretskii
  2022-07-30  7:23         ` Stefan Monnier
  2 siblings, 0 replies; 27+ messages in thread
From: Eli Zaretskii @ 2022-07-30  5:54 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: monnier, emacs-devel

> From: Michael Heerdegen <michael_heerdegen@web.de>
> Cc: Eli Zaretskii <eliz@gnu.org>,  emacs-devel@gnu.org
> Date: Sat, 30 Jul 2022 03:14:18 +0200
> 
> Stefan Monnier <monnier@iro.umontreal.ca> writes:
> 
> > Maybe this is a symptom of having way too many timers?
> 
> Maybe.
> 
> Could it be that when executing the timer function takes longer than the
> 0.1 seconds repeat delta, the timer fires again?

See timer-event-handler, which is the function invoked when a timer is
ripe, and handles both the invocation of the timer function and
rescheduling of the next timer invocation.  My reading of it is that
the above _could_ happen, but:

  . it can only happen if the timer function calls something that
    causes Emacs to wait for input, like sit-for, perhaps or
    accept-process-output, because otherwise Emacs will not check for
    ripe timers for as long as the timer function runs
  . the number of such "overlapping" invocations should not be more
    than 10, controlled by the value of timer-max-repeats



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

* Re: undo-auto--undoable-change infloop
  2022-07-30  1:14       ` Michael Heerdegen
  2022-07-30  4:14         ` Michael Heerdegen
  2022-07-30  5:54         ` Eli Zaretskii
@ 2022-07-30  7:23         ` Stefan Monnier
  2022-07-31  4:05           ` Michael Heerdegen
  2 siblings, 1 reply; 27+ messages in thread
From: Stefan Monnier @ 2022-07-30  7:23 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: Eli Zaretskii, emacs-devel

> different instances, I only ever create one timer when stating logging.
> Ant the value list looked like (#1=[ilog-timer] #1# #1# ...very very
> many #1#s and a few different timers).

This is very curious indeed!
AFAIK there should not be `eq` elements in that list.


        Stefan




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

* Re: undo-auto--undoable-change infloop
  2022-07-30  7:23         ` Stefan Monnier
@ 2022-07-31  4:05           ` Michael Heerdegen
  2022-08-05 14:42             ` Stefan Monnier
  0 siblings, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-07-31  4:05 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

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

> This is very curious indeed!
> AFAIK there should not be `eq` elements in that list.

I found something in a different place of my code.  That code uses
`timer-activate', but `timer-activate' doesn't check whether the timer
is already in the timer list, and that caused the duplicates I think.  I
didn't expect it to not check that.  Maybe that's the whole story
already.

Thanks for your help,

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-07-31  4:05           ` Michael Heerdegen
@ 2022-08-05 14:42             ` Stefan Monnier
  2022-08-06  0:26               ` Michael Heerdegen
  2022-08-09  4:02               ` Michael Heerdegen
  0 siblings, 2 replies; 27+ messages in thread
From: Stefan Monnier @ 2022-08-05 14:42 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: Eli Zaretskii, emacs-devel

> I found something in a different place of my code.  That code uses
> `timer-activate', but `timer-activate' doesn't check whether the timer
> is already in the timer list, and that caused the duplicates I think.  I
> didn't expect it to not check that.  Maybe that's the whole story
> already.

I suspect that `timer-activate` was not intended to be used by
end-users, but in any case I added a check that signals an error if you
try to re-add a timer.
[ It would have been better to report this as a bug, so we'd have
  a bug-number to refer to.  ]


        Stefan




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

* Re: undo-auto--undoable-change infloop
  2022-08-05 14:42             ` Stefan Monnier
@ 2022-08-06  0:26               ` Michael Heerdegen
  2022-08-09  4:02               ` Michael Heerdegen
  1 sibling, 0 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-08-06  0:26 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

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

> I suspect that `timer-activate` was not intended to be used by
> end-users, but in any case I added a check that signals an error if
> you try to re-add a timer.

Ok, thanks.  I intend to rewrite that stuff, I hope I end with some
cleaner implementation of the behavior I want.

> [ It would have been better to report this as a bug, so we'd have
>   a bug-number to refer to.  ]

Hmm, my questions often end like this, so I guess it's better to ask
them in the form of bug reports in the future ;-)

Thanks,

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-08-05 14:42             ` Stefan Monnier
  2022-08-06  0:26               ` Michael Heerdegen
@ 2022-08-09  4:02               ` Michael Heerdegen
  2022-08-09  8:00                 ` Stefan Monnier
  1 sibling, 1 reply; 27+ messages in thread
From: Michael Heerdegen @ 2022-08-09  4:02 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

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

> I suspect that `timer-activate` was not intended to be used by
> end-users, but in any case I added a check that signals an error if
> you try to re-add a timer.

I now remember why I am using this.  The scenario is always the same, I
need this in quite a bunch of packages:

I want something happening automatically after certain user interaction
(e.g. scrolling, editing the minibuffer etc), say, running a certain
function F after a delay of DELTA seconds.  When the user does something
before DELTA seconds have passed, the time should count from full DELTA
again - the timer should be postponed.  If it's later, the timer should
be started anew (unless the "scenario" had been left).

In the code, I can't be certain whether the timer had been triggered (at
least without consulting "internal" information).  In any case the timer
still exists as a timerp fulfilling object (it's the value of some
variable I use).  So I used `timer-set-time' to update the preferred run
time and called `timer-activate' to ensure it's in the list (to cover
the second case: timer had been run).  And, as we had found out, that is
wrong when the timer is actually still in the list.

Is there a way to achieve what I want without relying on "internal data"
(like looking in `timer-list')?

Michael.



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

* Re: undo-auto--undoable-change infloop
  2022-08-09  4:02               ` Michael Heerdegen
@ 2022-08-09  8:00                 ` Stefan Monnier
  2022-08-10  2:39                   ` Michael Heerdegen
  0 siblings, 1 reply; 27+ messages in thread
From: Stefan Monnier @ 2022-08-09  8:00 UTC (permalink / raw)
  To: Michael Heerdegen; +Cc: Eli Zaretskii, emacs-devel

> Is there a way to achieve what I want without relying on "internal data"
> (like looking in `timer-list')?

It's not 100% clear what is "internal" and what is not in `timer.el`, to
be honest, so I'm not completely sure what's the right answer.
But I think you can `cancel-timer` before `timer-activate`, which will
make sure it's not in the list any more.


        Stefan




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

* Re: undo-auto--undoable-change infloop
  2022-08-09  8:00                 ` Stefan Monnier
@ 2022-08-10  2:39                   ` Michael Heerdegen
  0 siblings, 0 replies; 27+ messages in thread
From: Michael Heerdegen @ 2022-08-10  2:39 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: Eli Zaretskii, emacs-devel

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

> But I think you can `cancel-timer` before `timer-activate`, which will
> make sure it's not in the list any more.

That solution also came to my mind.  Wastes a lot of time, though.  The
`timer-list' is traversed 3 times: First, to find the timer to delete
it, second to test if it's already present when trying to add it (your
change), third, to sort it in at the right position (though I don't
understand why that is necessary).  The list is probably never that
large so that it would matter much.

Anyway, thanks for answering and sorry for the noise,

Michael.



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

end of thread, other threads:[~2022-08-10  2:39 UTC | newest]

Thread overview: 27+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-07-26  3:54 undo-auto--undoable-change infloop Michael Heerdegen
2022-07-26 12:04 ` Eli Zaretskii
2022-07-27  3:52   ` Michael Heerdegen
2022-07-27  4:56     ` Michael Heerdegen
2022-07-27 11:20       ` Eli Zaretskii
2022-07-28  2:51         ` Michael Heerdegen
2022-07-28  3:10           ` Solved (was: undo-auto--undoable-change infloop) Michael Heerdegen
2022-07-28  5:49             ` Eli Zaretskii
2022-07-29  0:40               ` No, not solved " Michael Heerdegen
2022-07-29  3:44                 ` No, not solved Michael Heerdegen
2022-07-29  4:12                   ` Michael Heerdegen
2022-07-29  6:05                 ` No, not solved (was: undo-auto--undoable-change infloop) Eli Zaretskii
2022-07-27 11:20     ` undo-auto--undoable-change infloop Eli Zaretskii
2022-07-27 17:06       ` Michael Heerdegen
2022-07-27 17:34         ` Eli Zaretskii
2022-07-28  2:45           ` Michael Heerdegen
2022-07-29 14:49     ` Stefan Monnier
2022-07-30  1:14       ` Michael Heerdegen
2022-07-30  4:14         ` Michael Heerdegen
2022-07-30  5:54         ` Eli Zaretskii
2022-07-30  7:23         ` Stefan Monnier
2022-07-31  4:05           ` Michael Heerdegen
2022-08-05 14:42             ` Stefan Monnier
2022-08-06  0:26               ` Michael Heerdegen
2022-08-09  4:02               ` Michael Heerdegen
2022-08-09  8:00                 ` Stefan Monnier
2022-08-10  2:39                   ` Michael Heerdegen

Code repositories for project(s) associated with this 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).