bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode

[Alan Mackenzie <acm@muc.de>]

Hello, Eli.

On Sat, Dec 11, 2021 at 09:59:38 +0200, Eli Zaretskii wrote:
> > Date: Fri, 10 Dec 2021 22:52:40 +0000
> > Cc: 52298@debbugs.gnu.org, acm@muc.de
> > From: Alan Mackenzie <acm@muc.de>

> > > > I think that modify_text_properties is calling modiff_incr even when
> > > > inhibit_modification_hooks is non-nil.  I tried putting an `if' around
> > > > that bit of the code, without any great success.

> > > AFAIK, with-silent-modifications is supposed to prevent BUF_MODIFF
> > > from increasing.

> > I don't think it does in the modify_text_properties case.

> Maybe I'm misremembering.

> But let me ask you why those 2 text properties are involved in this
> case, and what do they signify?

c-is-sws (along with c-in-sws) marks syntactic whitespace in a buffer so
that especially for long comments, passing over that WS is rapid (after
the first pass has marked the properties).

c-type marks certain types of identifiers and positions related to a CC
Mode declaration, e.g. the start of a declarator, or the end of the
previous statement.

> Could we perhaps refrain from putting them on buffer text when those
> functions are called from the timer?

That would not be sensible.  Both of them are for optimisation, and
preventing them being used from the timer would involve an involved
(slow) mechanism.

In any case, with-silent-modifications is in force around "all" the code
called from c-type-finder-timer-func - there is a c-save-buffer-state
(which expands to with-silent-modifications) around all the critical
code.

> And why does that timer have to tick so frequently?

It doesn't have to.  It's just that the sooner the background scanning
gets finished, the better.

Though I'm beginning to have doubts about the entire mechanism, just as
you have.

> > > Are you sure you see that?  And what kind of 'if' did you try to put
> > > and where?

> > In modify_text_properties, around the modiff_incr bit:

> > diff --git a/src/textprop.c b/src/textprop.c
> > index d7d6a66923..d91b8624ef 100644
> > --- a/src/textprop.c
> > +++ b/src/textprop.c
> > @@ -85,10 +85,13 @@ modify_text_properties (Lisp_Object buffer,
> > Lisp_Object start, Lisp_Object end)

> >    prepare_to_modify_buffer_1 (b, e, NULL);

> > -  BUF_COMPUTE_UNCHANGED (buf, b - 1, e);
> > -  if (MODIFF <= SAVE_MODIFF)
> > -    record_first_change ();
> > -  modiff_incr (&MODIFF);
> > +  if (!inhibit_modification_hooks)
> > +    {
> > +      BUF_COMPUTE_UNCHANGED (buf, b - 1, e);
> > +      if (MODIFF <= SAVE_MODIFF)
> > +       record_first_change ();
> > +      modiff_incr (&MODIFF);
> > +    }

> And modiff_incr is still being called?  How's that possible, unless
> you don't use with-silent-modifications when you put those 2
> properties?  Or maybe modiff_incr is called from some other place as
> well?

I'm sure modiff_incr wasn't being called from that code with the `if'
surrounding it.  If might be being called from somewhere else.  I don't
think this manipulation of modiff_incr here is the source of the problem.

> > > Once again, the problem is not that redisplay is invoked, the problem
> > > is that it doesn't exit almost immediately, after detecting that
> > > nothing's changed.

OK, I think I see what the problem is, now.  It's the middle line in ....

  redisplay_internal 0
  071a03c8 (xdisp.c): try_window_id 2
  redisplay_preserve_echo_area (8)

..... , which indicates deep processing in redisplay.  (Yes, I know you've
been telling me this for a while...)  The question is why does the code
get that deep in rather than being aborted earlier?  The repeated calling
of the redisplay from keyboard.c is pretty harmless.

> > I'm again not entirely convinced we have a problem.  When trace-redisplay
> > is enabled on my machine, and xdisp.c visited, Emacs uses between 20% and
> > 25% of one CPU core for a little under 2 minutes (a 4½ year old Ryzen).
> > After this it is down to 0.3%.  All the time it is outputting
> > trace-redisplay messages, two I think for each timer iteration.

> Your Emacs is running TTY frames only.  On my system, during that
> stage, Emacs displaying on a GUI frame consumes 50% of 1 execution
> unit doing this stuff.  And 20% to 25% for 2 minutes is not
> negligible, either.  So yes, we do have a problem.  And we always will
> have a problem when redisplay goes that far in its processing when
> there's nothing to do, actually, and we invoke it so frequently.  So
> please, let's try to solve this, or at least understand what's going
> on well enough to make a decision.

> > I'm a bit surprised at the moment it's taking so long to do the initial
> > found-type scanning, but it's not all that bad.

> Well, that surprise of yours is another indication that we don't have
> a good understanding of what's going on here.  Can we please try to
> understand that fully?

Another thing.  After waiting the ~2 minutes for the background scanning
to complete, I had a look at which character positions had the
`fontified' text property, using a simple utility I wrote some years ago:

;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
(defvar regions nil)
(defun get-fontified ()
  "Display a list of regions which have the `fontified' property set.
If the region has the `defer' property, it is displayed as a list.
Otherwise
it is displayed as a cons.

Retain this list in variable `regions'."
  (interactive)
  (setq regions nil)
  (let* (end
         (beg (if (get-text-property (point-min) 'fontified)
                  (point-min)
                (next-single-property-change (point-min) 'fontified))))
    (while beg
      (setq end (or (next-single-property-change beg 'fontified)
                    (point-max)))
      (push (if (eq (get-text-property beg 'fontified) 'defer)
                (list beg end)
              (cons beg end))
            regions)
      (setq beg (if (get-text-property end 'fontified)
                    end
                  (next-single-property-change end 'fontified))))
    (setq regions (nreverse regions)))
  (message "Fontified regions: %s" regions))
(global-set-key [f10] 'get-fontified)
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;

Using the [f10] key (or just typing M-x get-fontified, if F10 is
otherwise occupied) the following positions ended up fontified in
X-Windows after that 2 minute pause:

    "Fontified regions: ((1 . 1740))"

,  That is, at the end, only the visible portion and a bit more were
fontified.  This suggests (though not conclusively) that no fontification
happened anywhere else in the buffer.

Yet another thing: I had a look at the commit where I introduced this
mechanism back in October, and it wasn't any faster then.  I think my
figure of 18s came from timing it in the foreground, disregarding the
influence of the timer mechanism.  I can't remember clearly any more.

-- 
Alan Mackenzie (Nuremberg, Germany).