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

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 52298 in the body.
You can then email your comments to 52298 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: bug-gnu-emacs <at> gnu.org
Cc: Alan Mackenzie <acm <at> muc.de>
Subject: 29.0.50;
 Frequent redisplay cycles induced by c-type-finder-timer-func timer
 in CC Mode
Date: Sun, 05 Dec 2021 09:46:29 +0200

It used to be the case that starting "emacs -Q" and disabling
blink-cursor-mode and global-eldoc-mode was enough to get me Emacs
that doesn't perform redisplay unless required.  To see this, do the
following with any Emacs up to and including Emacs 28:

  emacs -Q
  M-x blink-cursor-mode RET
  M-x global-eldoc-mode RET
  M-x trace-redisplay RET

(The last command is only available if you configured with
"--enable-checking=yes,glyphs".)  This would produce a few lines of
output on stderr, and then stop until you do something in Emacs, like
move the cursor with an arrow key.

This is no longer the case in Emacs 29.  There, if you visit a C file,
you will see a flurry of stderr messages about constant redisplay
cycles being forced.  It seems like the culprit is the function
'c-type-finder-timer-func', which is run from a timer at 10 Hz (!),
and which for some reason forces Emacs to perform a redisplay cycle
with that frequency.  The trace itself, viz.:

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

means that the processing induced by that timer function is far from
being trivial, which means something that this function does causes
Emacs to think some real change might have happened in the buffer.

Not even "emacs -Q -D" is enough to get rid of this
'c-type-finder-timer-func' timer in CC Mode buffers.

Is it possible to prevent this frequent timer from firing when no
changes have been done to the buffer?  And in any case, please try to
include some logic in that function to avoid whatever it does now to
force such frequent non-trivial redisplay cycles.  If nothing else,
laptop users will hate us if we release Emacs with this behavior.

In GNU Emacs 29.0.50 (build 297, i686-pc-mingw32)
 of 2021-12-04 built on HOME-C4E4A596F7
Repository revision: f247fa5d5ce7cb34f23c979c17b14c5713eb5490
Repository branch: master
Windowing system distributor 'Microsoft Corp.', version 5.1.2600
System Description: Microsoft Windows XP Service Pack 3 (v5.1.0.2600)

Configured using:
 'configure -C --prefix=/d/usr --with-wide-int
 --enable-checking=yes,glyphs 'CFLAGS=-O0 -gdwarf-4 -g3''

Configured features:
ACL GIF GMP GNUTLS HARFBUZZ JPEG JSON LCMS2 LIBXML2 MODULES NOTIFY
W32NOTIFY PDUMPER PNG RSVG SOUND THREADS TIFF TOOLKIT_SCROLL_BARS WEBP
XPM ZLIB

Important settings:
  value of $LANG: ENU
  locale-coding-system: cp1255

Major mode: Lisp Interaction

Minor modes in effect:
  tooltip-mode: t
  show-paren-mode: t
  electric-indent-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  line-number-mode: t
  indent-tabs-mode: t
  transient-mark-mode: t

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message mailcap yank-media rmc puny
dired dired-loaddefs rfc822 mml mml-sec epa derived epg rfc6068
epg-config gnus-util rmail rmail-loaddefs auth-source cl-seq eieio
eieio-core cl-macs eieio-loaddefs password-cache json map
text-property-search time-date seq gv subr-x byte-opt bytecomp
byte-compile cconv mm-decode mm-bodies mm-encode mail-parse rfc2231
mailabbrev gmm-utils mailheader cl-loaddefs cl-lib sendmail rfc2047
rfc2045 ietf-drums mm-util mail-prsvr mail-utils cus-start cus-load
iso-transl tooltip eldoc paren electric uniquify ediff-hook vc-hooks
lisp-float-type elisp-mode mwheel dos-w32 ls-lisp disp-table
term/w32-win w32-win w32-vars term/common-win tool-bar dnd fontset image
regexp-opt fringe tabulated-list replace newcomment text-mode lisp-mode
prog-mode register page tab-bar menu-bar rfn-eshadow isearch easymenu
timer select scroll-bar mouse jit-lock font-lock syntax font-core
term/tty-colors frame minibuffer cl-generic cham georgian utf-8-lang
misc-lang vietnamese tibetan thai tai-viet lao korean japanese eucjp-ms
cp51932 hebrew greek romanian slovak czech european ethiopic indian
cyrillic chinese composite emoji-zwj charscript charprop case-table
epa-hook jka-cmpr-hook help simple abbrev obarray cl-preloaded nadvice
button loaddefs faces cus-face macroexp files window text-properties
overlay sha1 md5 base64 format env code-pages mule custom widget keymap
hashtable-print-readable backquote threads w32notify w32 lcms2 multi-tty
make-network-process emacs)

Memory information:
((conses 16 65940 11920)
 (symbols 48 8784 1)
 (strings 16 23857 3044)
 (string-bytes 1 667119)
 (vectors 16 14295)
 (vector-slots 8 183967 12730)
 (floats 8 25 52)
 (intervals 40 273 68)
 (buffers 888 10))

Message #8 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: bug-gnu-emacs <at> gnu.org
Subject: Re: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Mon, 6 Dec 2021 20:53:15 +0000

Hello, Eli.

On Sun, Dec 05, 2021 at 09:46:29 +0200, Eli Zaretskii wrote:
> It used to be the case that starting "emacs -Q" and disabling
> blink-cursor-mode and global-eldoc-mode was enough to get me Emacs
> that doesn't perform redisplay unless required.  To see this, do the
> following with any Emacs up to and including Emacs 28:

>   emacs -Q
>   M-x blink-cursor-mode RET
>   M-x global-eldoc-mode RET
>   M-x trace-redisplay RET

> (The last command is only available if you configured with
> "--enable-checking=yes,glyphs".)  This would produce a few lines of
> output on stderr, and then stop until you do something in Emacs, like
> move the cursor with an arrow key.

> This is no longer the case in Emacs 29.  There, if you visit a C file,
> you will see a flurry of stderr messages about constant redisplay
> cycles being forced.  It seems like the culprit is the function
> 'c-type-finder-timer-func', which is run from a timer at 10 Hz (!),

That is customisable with c-type-finder-repeat-time.  The idea is to
have this as often as possible so that the backgroud scanning is
complete as soon as possible.  (See my next paragraph.)

> and which for some reason forces Emacs to perform a redisplay cycle
> with that frequency.  The trace itself, viz.:

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

> means that the processing induced by that timer function is far from
> being trivial, which means something that this function does causes
> Emacs to think some real change might have happened in the buffer.

The idea is that this processing only happens a short while after
loading a C file, the time being taken up by checking for the
fontification of "found types", that is identifiers identified as types
in the rest of the buffer somewhere.

> Not even "emacs -Q -D" is enough to get rid of this
> 'c-type-finder-timer-func' timer in CC Mode buffers.

If this processing continues beyond the time to scan all CC Mode
buffers, then there is a bug.  A megabyte long file (xdisp.c) scans in
aroung 18 seconds on my machine.

> Is it possible to prevent this frequent timer from firing when no
> changes have been done to the buffer?  And in any case, please try to
> include some logic in that function to avoid whatever it does now to
> force such frequent non-trivial redisplay cycles.  If nothing else,
> laptop users will hate us if we release Emacs with this behavior.

It can be disabled by setting (or customising) c-type-finder-time-slot
to nil.  As I say, the activity should cease after a few seconds, or a
few minutes with a well filled desktop.

There have been a couple of bugs in this area recently, one fixed
(stupidly) on the release branch (where there wasn't a problem).  The
other one was fixed in master.  By recently, I mean last Wednesday and
Saturday 2021-11-13.

But even given the above, I've a sneaking suspicion there's still a bug
here, which I'll have a look for (but not tonight).

> In GNU Emacs 29.0.50 (build 297, i686-pc-mingw32)
>  of 2021-12-04 built on HOME-C4E4A596F7
> Repository revision: f247fa5d5ce7cb34f23c979c17b14c5713eb5490
> Repository branch: master
> Windowing system distributor 'Microsoft Corp.', version 5.1.2600
> System Description: Microsoft Windows XP Service Pack 3 (v5.1.0.2600)

> Configured using:
>  'configure -C --prefix=/d/usr --with-wide-int
>  --enable-checking=yes,glyphs 'CFLAGS=-O0 -gdwarf-4 -g3''

[ .... ]

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #11 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50;
 Frequent redisplay cycles induced by c-type-finder-timer-func timer
 in CC Mode
Date: Tue, 07 Dec 2021 14:58:08 +0200

> Date: Mon, 6 Dec 2021 20:53:15 +0000
> Cc: bug-gnu-emacs <at> gnu.org
> From: Alan Mackenzie <acm <at> muc.de>
> 
> > This is no longer the case in Emacs 29.  There, if you visit a C file,
> > you will see a flurry of stderr messages about constant redisplay
> > cycles being forced.  It seems like the culprit is the function
> > 'c-type-finder-timer-func', which is run from a timer at 10 Hz (!),
> 
> That is customisable with c-type-finder-repeat-time.  The idea is to
> have this as often as possible so that the backgroud scanning is
> complete as soon as possible.  (See my next paragraph.)

Yes, but why would I need to do one more chore to get me a "silent"
redisplay?  And why does this timer cause such a serious work to the
display engine?

> If this processing continues beyond the time to scan all CC Mode
> buffers, then there is a bug.  A megabyte long file (xdisp.c) scans in
> aroung 18 seconds on my machine.

18 seconds is almost an eternity for my frequent use cases of firing
up Emacs to debug some display problem.  And it's much more than 18
sec here: I measured 4 minutes and 21 sec, with 1:54 CPU time.  My
build is unoptimized, but still, a factor of 13 wrt your timing is too
much to be explained by that alone.

> It can be disabled by setting (or customising) c-type-finder-time-slot
> to nil.  As I say, the activity should cease after a few seconds, or a
> few minutes with a well filled desktop.

Once again, it takes much more here.  And my main question was left
unanswered: what does this timer function do to cause such thorough
redisplay cycles, when I know that nothing was changed in the buffer?
can you please describe what this function does that could have such
an effect?

Message #14 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Tue, 7 Dec 2021 19:58:39 +0000

Hello, Eli.

On Tue, Dec 07, 2021 at 14:58:08 +0200, Eli Zaretskii wrote:
> > Date: Mon, 6 Dec 2021 20:53:15 +0000
> > Cc: bug-gnu-emacs <at> gnu.org
> > From: Alan Mackenzie <acm <at> muc.de>

> > > This is no longer the case in Emacs 29.  There, if you visit a C file,
> > > you will see a flurry of stderr messages about constant redisplay
> > > cycles being forced.  It seems like the culprit is the function
> > > 'c-type-finder-timer-func', which is run from a timer at 10 Hz (!),

> > That is customisable with c-type-finder-repeat-time.  The idea is to
> > have this as often as possible so that the backgroud scanning is
> > complete as soon as possible.  (See my next paragraph.)

> Yes, but why would I need to do one more chore to get me a "silent"
> redisplay?  And why does this timer cause such a serious work to the
> display engine?

I think there's still a bug in the mechanism.  This mechanism was the
outcome of a long thread in the list a few months ago, complaining about
the perceived randomness of CC Mode's font locking.  It scans all CC
Mode buffers at startup, and each buffer which gets visited, to detect
"found types".  For each occurrence anywhere in the buffer of a newly
"found type", the fontified text property gets set to nil.  Further, if
this occurrence is in a currently displayed window, a redisplay gets
triggered.

In a (hopefully fixed) bug, there occurred constant redisplay, because
the newly found types weren't getting properly added to
c-found-type-list.  The same thing might still be happening in a
different way.

> > If this processing continues beyond the time to scan all CC Mode
> > buffers, then there is a bug.  A megabyte long file (xdisp.c) scans in
> > aroung 18 seconds on my machine.

> 18 seconds is almost an eternity for my frequent use cases of firing
> up Emacs to debug some display problem.  And it's much more than 18
> sec here: I measured 4 minutes and 21 sec, with 1:54 CPU time.  My
> build is unoptimized, but still, a factor of 13 wrt your timing is too
> much to be explained by that alone.

Is that with xdisp.c the only CC Mode buffer?  When my desktop had
around 700 buffers, many of them CC Mode, the total background
processing was of the order of 10 minutes (optimised build).

That 4 minutes 21 seconds - does the thrashing of the redisplay stop
after this amount of uptime?

As a matter of interest, is Emacs responsive to key strokes when this is
happening?

> > It can be disabled by setting (or customising) c-type-finder-time-slot
> > to nil.  As I say, the activity should cease after a few seconds, or a
> > few minutes with a well filled desktop.

> Once again, it takes much more here.  And my main question was left
> unanswered: what does this timer function do to cause such thorough
> redisplay cycles, when I know that nothing was changed in the buffer?
> can you please describe what this function does that could have such
> an effect?

What changes in the buffer is the detection of "foo", "bar", ... as
found types.  These get marked throughout the buffer with the fontified
text property set to nil, and if an occurrence is in a displayed window,
that triggers an immediate redisplay to refontify that visible
occurrence of the found type.  I think this repeated redisplay is
happening too often.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #17 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Tue, 07 Dec 2021 22:16:28 +0200

> Date: Tue, 7 Dec 2021 19:58:39 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> muc.de>
> 
> > 18 seconds is almost an eternity for my frequent use cases of firing
> > up Emacs to debug some display problem.  And it's much more than 18
> > sec here: I measured 4 minutes and 21 sec, with 1:54 CPU time.  My
> > build is unoptimized, but still, a factor of 13 wrt your timing is too
> > much to be explained by that alone.
> 
> Is that with xdisp.c the only CC Mode buffer?

Yes.  Not only the only CC Mode buffer: the only Emacs buffer except
8scratch* and *Messages*.  It's "emacs -Q" that just visited xdisp.c.

> That 4 minutes 21 seconds - does the thrashing of the redisplay stop
> after this amount of uptime?

Yes.  After that, all I see is the timer running, which forces
frequent entries to redisplay (something to remember: frequent timers
cause frequent entries to redisplay), but it immediately exits without
doing anything.

> As a matter of interest, is Emacs responsive to key strokes when this is
> happening?

It's responsive, but it "stutters": if I lean on the right-arrow key,
it doesn't move with uniformly constant velocity, but instead
frequently stops for a split-second.

> What changes in the buffer is the detection of "foo", "bar", ... as
> found types.  These get marked throughout the buffer with the fontified
> text property set to nil, and if an occurrence is in a displayed window,
> that triggers an immediate redisplay to refontify that visible
> occurrence of the found type.  I think this repeated redisplay is
> happening too often.

And I think it happens not only for the fontified property set on the
visible portion of the buffer, but also on the portions that are
outside of the window.  In fact, the output of trace-redisplay clearly
tells me that redisplay was called when all the changes were after the
window's end.  Which is expected, given that the window shows the
first portion of the file.

Is your code using with-silent-modifications, or some other mechanism
that should prevent Emacs from thinking that the buffer has changed?
If not, why not?

Message #20 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: bug-gnu-emacs <at> gnu.org
Subject: Re: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Wed, 8 Dec 2021 20:15:46 +0000

Hello, Eli.

Yes, I've received your more recent posts in this thread.

On Sun, Dec 05, 2021 at 09:46:29 +0200, Eli Zaretskii wrote:
> It used to be the case that starting "emacs -Q" and disabling
> blink-cursor-mode and global-eldoc-mode was enough to get me Emacs
> that doesn't perform redisplay unless required.  To see this, do the
> following with any Emacs up to and including Emacs 28:

>   emacs -Q
>   M-x blink-cursor-mode RET
>   M-x global-eldoc-mode RET
>   M-x trace-redisplay RET

> (The last command is only available if you configured with
> "--enable-checking=yes,glyphs".)  This would produce a few lines of
> output on stderr, and then stop until you do something in Emacs, like
> move the cursor with an arrow key.

I've just tried building with that ./configure option, and trying out
M-x trace-redisplay with emacs -Q on a very recent master version.

The command is not very useful on a Linux console.  It outputs messages
on the same display thing that Emacs itself is using, and outputs them
as if they were a Unix text file being naively displayed in Windows:
i.e. like this:

aaaa
    aaaaaaaaaaaaa
                 aaaaaaaaaaaaa
		              aaaaaaaaaaaaaaa
			                     aaaaaaaaaaaaaaaaaa



> This is no longer the case in Emacs 29.  There, if you visit a C file,
> you will see a flurry of stderr messages about constant redisplay
> cycles being forced.  It seems like the culprit is the function
> 'c-type-finder-timer-func', which is run from a timer at 10 Hz (!),
> and which for some reason forces Emacs to perform a redisplay cycle
> with that frequency. ....

I see the flurry of messages.  But with trace-redisplay disabled, I see
no evidence of excessive redisplay (see below).  Could it be that there
is some interaction between trace-redisplay and CC Mode which is causing
all these redisplayings?

> .... The trace itself, viz.:

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

> means that the processing induced by that timer function is far from
> being trivial, which means something that this function does causes
> Emacs to think some real change might have happened in the buffer.

I'm not familiar with such traces, and trace-redisplay is not documented
in its doc string.  Could you please explain briefly  what the "071a03c8
(xdisp.c):" means, and what says that the processing is non-trivial.
Thanks!

> Not even "emacs -Q -D" is enough to get rid of this
> 'c-type-finder-timer-func' timer in CC Mode buffers.

> Is it possible to prevent this frequent timer from firing when no
> changes have been done to the buffer?  And in any case, please try to
> include some logic in that function to avoid whatever it does now to
> force such frequent non-trivial redisplay cycles.  If nothing else,
> laptop users will hate us if we release Emacs with this behavior.

When I apply the following patch to cc-fonts.el:

diff --git a/lisp/progmodes/cc-fonts.el b/lisp/progmodes/cc-fonts.el
index 967464ac14..2ae92f99bf 100644
--- a/lisp/progmodes/cc-fonts.el
+++ b/lisp/progmodes/cc-fonts.el
@@ -2429,6 +2429,11 @@ c-re-redisplay-timer
 (defun c-force-redisplay (start end)
   ;; Force redisplay immediately.  This assumes `font-lock-support-mode' is
   ;; 'jit-lock-mode.  Set the variable `c-re-redisplay-timer' to nil.
+;;;; TEMPORARY STOUGH, 2021-12-08
+  (message "c-force-redisplay - Buffer: %s - %s:%s - \"%s\""
+          (buffer-name (current-buffer)) start end
+          (buffer-substring-no-properties start end))
+;;;; END OF TEMPORARY STOUGH.
   (save-excursion (c-font-lock-fontify-region start end))
   (jit-lock-force-redisplay (copy-marker start) (copy-marker end))
   (setq c-re-redisplay-timer nil))

, and load xdisp.c freshly, I see only three lines of output in
*Messages*:

c-force-redisplay - Buffer: xdisp.c - 223:225 - "it"
c-force-redisplay - Buffer: xdisp.c - 49:55 - "buffer"
c-force-redisplay - Buffer: xdisp.c - 28:34 - "window"

That applies after waiting over a minute.  After this time, the `top'
utility shows Emacs consuming around 1% of a CPU core's time.

All this suggests that in normal use, CC Mode isn't triggering excessive
redisplay operations.

What am I not seeing?

> In GNU Emacs 29.0.50 (build 297, i686-pc-mingw32)
>  of 2021-12-04 built on HOME-C4E4A596F7

I've checked the git log, and there haven't been any changes to CC Mode
since this version.

> Repository revision: f247fa5d5ce7cb34f23c979c17b14c5713eb5490
> Repository branch: master
> Windowing system distributor 'Microsoft Corp.', version 5.1.2600
> System Description: Microsoft Windows XP Service Pack 3 (v5.1.0.2600)

> Configured using:
>  'configure -C --prefix=/d/usr --with-wide-int
>  --enable-checking=yes,glyphs 'CFLAGS=-O0 -gdwarf-4 -g3''

[ .... ]

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #23 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: bug#52298: 29.0.50;
 Frequent redisplay cycles induced by c-type-finder-timer-func timer
 in CC Mode
Date: Thu, 09 Dec 2021 09:08:16 +0200

> Date: Wed, 8 Dec 2021 20:15:46 +0000
> Cc: bug-gnu-emacs <at> gnu.org
> From: Alan Mackenzie <acm <at> muc.de>
> 
> I've just tried building with that ./configure option, and trying out
> M-x trace-redisplay with emacs -Q on a very recent master version.
> 
> The command is not very useful on a Linux console.

I didn't suggest that you invoke that command, it is not part of this
issue.  It is just a tool I used to see what's going on, and I do know
how to interpret its output.

And yes, if your main development environment is based on the Linux
console, then many tools will be unavailable to you, but that's a
tangent.

> It outputs messages
> on the same display thing that Emacs itself is using, and outputs them
> as if they were a Unix text file being naively displayed in Windows:
> i.e. like this:
> 
> aaaa
>     aaaaaaaaaaaaa
>                  aaaaaaaaaaaaa
> 		              aaaaaaaaaaaaaaa
> 			                     aaaaaaaaaaaaaaaaaa

That's not related to Windows, that's because Emacs switches the
terminal to a mode where newline doesn't cause the cursor to move to
the beginning of the next line.  IOW, this is because you are running
Emacs on the Linux console and the traces go to the same console,
which is not configured to receive simple printf's.

> >   redisplay_internal 0
> >   071a03c8 (xdisp.c): try_window_id 2
> >   redisplay_preserve_echo_area (8)
> 
> > means that the processing induced by that timer function is far from
> > being trivial, which means something that this function does causes
> > Emacs to think some real change might have happened in the buffer.
> 
> I'm not familiar with such traces, and trace-redisplay is not documented
> in its doc string.  Could you please explain briefly  what the "071a03c8
> (xdisp.c):" means, and what says that the processing is non-trivial.

The address and the file name are for when you run under GDB.  The
important part of that message is "try_window_id 2".  If you look in
xdisp.c for the trace that emits it, viz.:

      debug_method_add (w, "try_window_id %d", tem);

you will realize that redisplay called try_window_id, which means it
was working too hard: since nothing has changed in the buffer, and
even point didn't move, it should have succeeded in the call to
try_cursor_movement, which is before it.  So something prevented
try_cursor_movement from succeeding in this case, and kept preventing
that for full 4 minutes after the file was visited.  The question is:
what is that something that causes try_cursor_movement to fail?

> > Is it possible to prevent this frequent timer from firing when no
> > changes have been done to the buffer?  And in any case, please try to
> > include some logic in that function to avoid whatever it does now to
> > force such frequent non-trivial redisplay cycles.  If nothing else,
> > laptop users will hate us if we release Emacs with this behavior.
> 
> When I apply the following patch to cc-fonts.el:
> 
> diff --git a/lisp/progmodes/cc-fonts.el b/lisp/progmodes/cc-fonts.el
> index 967464ac14..2ae92f99bf 100644
> --- a/lisp/progmodes/cc-fonts.el
> +++ b/lisp/progmodes/cc-fonts.el
> @@ -2429,6 +2429,11 @@ c-re-redisplay-timer
>  (defun c-force-redisplay (start end)
>    ;; Force redisplay immediately.  This assumes `font-lock-support-mode' is
>    ;; 'jit-lock-mode.  Set the variable `c-re-redisplay-timer' to nil.
> +;;;; TEMPORARY STOUGH, 2021-12-08
> +  (message "c-force-redisplay - Buffer: %s - %s:%s - \"%s\""
> +          (buffer-name (current-buffer)) start end
> +          (buffer-substring-no-properties start end))
> +;;;; END OF TEMPORARY STOUGH.
>    (save-excursion (c-font-lock-fontify-region start end))
>    (jit-lock-force-redisplay (copy-marker start) (copy-marker end))
>    (setq c-re-redisplay-timer nil))
> 
> , and load xdisp.c freshly, I see only three lines of output in
> *Messages*:
> 
> c-force-redisplay - Buffer: xdisp.c - 223:225 - "it"
> c-force-redisplay - Buffer: xdisp.c - 49:55 - "buffer"
> c-force-redisplay - Buffer: xdisp.c - 28:34 - "window"
> 
> That applies after waiting over a minute.  After this time, the `top'
> utility shows Emacs consuming around 1% of a CPU core's time.
> 
> All this suggests that in normal use, CC Mode isn't triggering excessive
> redisplay operations.

No, it means that your hypothesis regarding what causes the phenomenon
was incorrect.  Something else prevents try_cursor_movement from
successfully deciding that the window doesn't need any redisplay.
That something is in the timer function the CC Mode runs.  If you can
find what that factor is and remove it, it will solve the issue.

In a followup message I wrote:

> Is your code using with-silent-modifications, or some other mechanism
> that should prevent Emacs from thinking that the buffer has changed?
> If not, why not?

Can you please answer that?  It might be the key to unlock this issue,
since you said that timer function puts text properties on buffer
text.

Thanks.

Message #26 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Thu, 9 Dec 2021 20:11:32 +0000

Hello, Eli.

On Thu, Dec 09, 2021 at 09:08:16 +0200, Eli Zaretskii wrote:
> > Date: Wed, 8 Dec 2021 20:15:46 +0000
> > Cc: bug-gnu-emacs <at> gnu.org
> > From: Alan Mackenzie <acm <at> muc.de>

> > I've just tried building with that ./configure option, and trying out
> > M-x trace-redisplay with emacs -Q on a very recent master version.

> > The command is not very useful on a Linux console.

> I didn't suggest that you invoke that command, it is not part of this
> issue.  It is just a tool I used to see what's going on, and I do know
> how to interpret its output.

Of course.  Still, when trace-redisplay is running on my system, the
amount of CPU usage is still around 1% of a core for this Emacs.

[ .... ]

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

> > > means that the processing induced by that timer function is far from
> > > being trivial, which means something that this function does causes
> > > Emacs to think some real change might have happened in the buffer.

> > I'm not familiar with such traces, and trace-redisplay is not documented
> > in its doc string.  Could you please explain briefly  what the "071a03c8
> > (xdisp.c):" means, and what says that the processing is non-trivial.

> The address and the file name are for when you run under GDB.  The
> important part of that message is "try_window_id 2".  If you look in
> xdisp.c for the trace that emits it, viz.:

>       debug_method_add (w, "try_window_id %d", tem);

> you will realize that redisplay called try_window_id, which means it
> was working too hard: since nothing has changed in the buffer, and
> even point didn't move, it should have succeeded in the call to
> try_cursor_movement, which is before it.  So something prevented
> try_cursor_movement from succeeding in this case, and kept preventing
> that for full 4 minutes after the file was visited.  The question is:
> what is that something that causes try_cursor_movement to fail?

The timer function is setting `fontified' text properties to nil.  It is
doing this inside a with-silent-modifications.  (Sorry I didn't answer
this question yesterday evening; I should have done.)

Have I misunderstood this action?  I thought that merely setting the
`fontified' text property to nil on a part of the buffer doesn't
instantaneously trigger redisplay (except by the calling of
after-change-functions, which is here inactive due to
`with-silent-modifications'), even if that part of the buffer is
currently displayed in a window.

If I _have_ misunderstood this, it is very likely the reason for the
flurry of redisplayings.  I think I need to read bits of xdisp.c rather
carefully.

[ .... ]

> > When I apply the following patch to cc-fonts.el:

[ .... ]

> > , and load xdisp.c freshly, I see only three lines of output in
> > *Messages*:

> > c-force-redisplay - Buffer: xdisp.c - 223:225 - "it"
> > c-force-redisplay - Buffer: xdisp.c - 49:55 - "buffer"
> > c-force-redisplay - Buffer: xdisp.c - 28:34 - "window"

> > That applies after waiting over a minute.  After this time, the `top'
> > utility shows Emacs consuming around 1% of a CPU core's time.

> > All this suggests that in normal use, CC Mode isn't triggering excessive
> > redisplay operations.

> No, it means that your hypothesis regarding what causes the phenomenon
> was incorrect.  Something else prevents try_cursor_movement from
> successfully deciding that the window doesn't need any redisplay.
> That something is in the timer function the CC Mode runs.  If you can
> find what that factor is and remove it, it will solve the issue.

OK.  I need to understand xdisp.c a little better.

> In a followup message I wrote:

> > Is your code using with-silent-modifications, or some other mechanism
> > that should prevent Emacs from thinking that the buffer has changed?
> > If not, why not?

> Can you please answer that?  It might be the key to unlock this issue,
> since you said that timer function puts text properties on buffer
> text.

Again, the code is indeed using with-silent-modifications, and again,
sorry for not saying so yesterday evening.

> Thanks.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #29 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Thu, 09 Dec 2021 22:38:32 +0200

> Date: Thu, 9 Dec 2021 20:11:32 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> muc.de>
> 
> >       debug_method_add (w, "try_window_id %d", tem);
> 
> > you will realize that redisplay called try_window_id, which means it
> > was working too hard: since nothing has changed in the buffer, and
> > even point didn't move, it should have succeeded in the call to
> > try_cursor_movement, which is before it.  So something prevented
> > try_cursor_movement from succeeding in this case, and kept preventing
> > that for full 4 minutes after the file was visited.  The question is:
> > what is that something that causes try_cursor_movement to fail?
> 
> The timer function is setting `fontified' text properties to nil.  It is
> doing this inside a with-silent-modifications.  (Sorry I didn't answer
> this question yesterday evening; I should have done.)
> 
> Have I misunderstood this action?  I thought that merely setting the
> `fontified' text property to nil on a part of the buffer doesn't
> instantaneously trigger redisplay (except by the calling of
> after-change-functions, which is here inactive due to
> `with-silent-modifications'), even if that part of the buffer is
> currently displayed in a window.

It seems the reason is not the 'fontified' property, it's the
'c-is-sws' property that c-forward-sws puts on the buffer text.  I
show the backtrace below.  There's also the 'c-type' property that
c-get-fontification-context puts; see the second backtrace below.

Both of these are called from the timer function.  Are they using
with-silent-modifications?

The result of this is that the buffer's modification tick is increased
all the time, and redisplay_window then decides that the current glyph
matrix is not up-to-date, which means it must work harder to decide
how to redisplay this window.

Here are the two backtraces I promised:

#0  0x013118d6 in modiff_incr (a=0x6ee5310) at lisp.h:3552
#1  0x0131203e in modify_text_properties (buffer=XIL(0xa000000006ee50a0),
    start=make_fixnum(39237), end=make_fixnum(39238)) at textprop.c:91
#2  0x01316a2b in add_text_properties_1 (start=make_fixnum(39237),
    end=make_fixnum(39238), properties=XIL(0xc00000000082b538),
    object=XIL(0xa000000006ee50a0), set_type=TEXT_PROPERTY_REPLACE,
    destructive=true) at textprop.c:1224
#3  0x01316ef0 in Fadd_text_properties (start=make_fixnum(39237),
    end=make_fixnum(39238), properties=XIL(0xc00000000082b538), object=XIL(0))
    at textprop.c:1296
#4  0x01316fcf in Fput_text_property (start=make_fixnum(39237),
    end=make_fixnum(39238), property=XIL(0x56056f0), value=XIL(0x30),
    object=XIL(0)) at textprop.c:1314
#5  0x012670c5 in funcall_subr (subr=0x17216a0 <Sput_text_property>,
    numargs=4, args=0x82b790) at eval.c:3152
#6  0x012669b1 in Ffuncall (nargs=5, args=0x82b788) at eval.c:3065
#7  0x012d3314 in exec_byte_code (bytestr=XIL(0x8000000006e55e40),
    vector=XIL(0xa000000006e55068), maxdepth=make_fixnum(19),
    args_template=make_fixnum(0), nargs=0, args=0x82c0a8) at bytecode.c:632
#8  0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006e551e8),
    syms_left=make_fixnum(0), nargs=0, args=0x82c0a8) at eval.c:3189
#9  0x01267a73 in funcall_lambda (fun=XIL(0xa000000006e551e8), nargs=0,
    arg_vector=0x82c0a8) at eval.c:3270
#10 0x01266a21 in Ffuncall (nargs=1, args=0x82c0a0) at eval.c:3069
#11 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074e9df8),
    vector=XIL(0xa0000000074e1888), maxdepth=make_fixnum(14),
    args_template=make_fixnum(257), nargs=1, args=0x82c7e0) at bytecode.c:632
#12 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa0000000074e1990),
    syms_left=make_fixnum(257), nargs=1, args=0x82c7d8) at eval.c:3189
#13 0x01267a73 in funcall_lambda (fun=XIL(0xa0000000074e1990), nargs=1,
    arg_vector=0x82c7d8) at eval.c:3270
#14 0x01266a21 in Ffuncall (nargs=2, args=0x82c7d0) at eval.c:3069
#15 0x012d3314 in exec_byte_code (bytestr=XIL(0x8000000006eedf18),
    vector=XIL(0xa0000000074e1b58), maxdepth=make_fixnum(7),
    args_template=make_fixnum(514), nargs=2, args=0x82cde0) at bytecode.c:632
#16 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa0000000074e1bc8),
    syms_left=make_fixnum(514), nargs=2, args=0x82cdd0) at eval.c:3189
#17 0x01267a73 in funcall_lambda (fun=XIL(0xa0000000074e1bc8), nargs=2,
    arg_vector=0x82cdd0) at eval.c:3270
#18 0x01266a21 in Ffuncall (nargs=3, args=0x82cdc8) at eval.c:3069
#19 0x012d3314 in exec_byte_code (bytestr=XIL(0x8000000006eedf48),
    vector=XIL(0xa00000000753e690), maxdepth=make_fixnum(5),
    args_template=make_fixnum(257), nargs=1, args=0x82d390) at bytecode.c:632
#20 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa00000000753e6b0),
    syms_left=make_fixnum(257), nargs=1, args=0x82d388) at eval.c:3189
#21 0x01267a73 in funcall_lambda (fun=XIL(0xa00000000753e6b0), nargs=1,
    arg_vector=0x82d388) at eval.c:3270
#22 0x01266a21 in Ffuncall (nargs=2, args=0x82d380) at eval.c:3069
#23 0x01265cc4 in call1 (fn=XIL(0xa00000000753e6b0), arg1=XIL(0x5c690a0))
    at eval.c:2925
#24 0x0127bd8f in mapcar1 (leni=1, vals=0x0, fn=XIL(0xa00000000753e6b0),
    seq=XIL(0xc000000006f4fe30)) at fns.c:2848
#25 0x0127c4eb in Fmapc (function=XIL(0xa00000000753e6b0),
    sequence=XIL(0xc000000006f4fe30)) at fns.c:2925
#26 0x01266f6c in funcall_subr (subr=0x171fa20 <Smapc>, numargs=2,
    args=0x82d688) at eval.c:3142
#27 0x012669b1 in Ffuncall (nargs=3, args=0x82d680) at eval.c:3065
#28 0x012d3314 in exec_byte_code (bytestr=XIL(0x8000000006eedf38),
    vector=XIL(0xa0000000074e1c48), maxdepth=make_fixnum(11),
    args_template=make_fixnum(514), nargs=2, args=0x82dca0) at bytecode.c:632
#29 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa0000000074e1c70),
    syms_left=make_fixnum(514), nargs=2, args=0x82dc90) at eval.c:3189
#30 0x01267a73 in funcall_lambda (fun=XIL(0xa0000000074e1c70), nargs=2,
    arg_vector=0x82dc90) at eval.c:3270
#31 0x01266a21 in Ffuncall (nargs=3, args=0x82dc88) at eval.c:3069
#32 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074a3398),
    vector=XIL(0xa000000006f6c918), maxdepth=make_fixnum(11),
    args_template=make_fixnum(0), nargs=0, args=0x82e530) at bytecode.c:632
#33 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006f37d58),
    syms_left=make_fixnum(0), nargs=0, args=0x82e530) at eval.c:3189
#34 0x01267a73 in funcall_lambda (fun=XIL(0xa000000006f37d58), nargs=0,
    arg_vector=0x82e530) at eval.c:3270
#35 0x01266a21 in Ffuncall (nargs=1, args=0x82e528) at eval.c:3069
#36 0x01264f28 in Fapply (nargs=2, args=0x82e528) at eval.c:2648
#37 0x01266e59 in funcall_subr (subr=0x171eda0 <Sapply>, numargs=2,
    args=0x82e528) at eval.c:3120
#38 0x012669b1 in Ffuncall (nargs=3, args=0x82e520) at eval.c:3065
#39 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000061333c4),
    vector=XIL(0xa000000006133294), maxdepth=make_fixnum(10),
    args_template=make_fixnum(257), nargs=1, args=0x82ebb0) at bytecode.c:632
#40 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006133264),
    syms_left=make_fixnum(257), nargs=1, args=0x82eba8) at eval.c:3189
#41 0x01267a73 in funcall_lambda (fun=XIL(0xa000000006133264), nargs=1,
    arg_vector=0x82eba8) at eval.c:3270
#42 0x01266a21 in Ffuncall (nargs=2, args=0x82eba0) at eval.c:3069
#43 0x01265cc4 in call1 (fn=XIL(0xf120), arg1=XIL(0xa00000000753e580))
    at eval.c:2925
#44 0x0117447a in timer_check_2 (timers=XIL(0), idle_timers=XIL(0))
    at keyboard.c:4374
#45 0x01174675 in timer_check () at keyboard.c:4436
#46 0x01171ed6 in readable_events (flags=1) at keyboard.c:3448
#47 0x0117c519 in get_input_pending (flags=1) at keyboard.c:6924
#48 0x0118878d in detect_input_pending_run_timers (do_display=false)
    at keyboard.c:10454
#49 0x0116e798 in read_char (commandflag=1, map=XIL(0xc000000007629a30),
    prev_event=XIL(0), used_mouse_menu=0x82f45f, end_time=0x0)
    at keyboard.c:2813
#50 0x01185e58 in read_key_sequence (keybuf=0x82f760, prompt=XIL(0),
    dont_downcase_last=false, can_return_switch_frame=true,
    fix_current_buffer=true, prevent_redisplay=false) at keyboard.c:9631
#51 0x0116924a in command_loop_1 () at keyboard.c:1393
#52 0x0126082e in internal_condition_case (bfun=0x1168b27 <command_loop_1>,
    handlers=XIL(0x90), hfun=0x1167b25 <cmd_error>) at eval.c:1492
#53 0x01168594 in command_loop_2 (handlers=XIL(0x90)) at keyboard.c:1134
#54 0x0125f6bf in internal_catch (tag=XIL(0xf3f0),
    func=0x116855d <command_loop_2>, arg=XIL(0x90)) at eval.c:1223
#55 0x01168517 in command_loop () at keyboard.c:1112
#56 0x0116758d in recursive_edit_1 () at keyboard.c:721
#57 0x01167823 in Frecursive_edit () at keyboard.c:804
#58 0x01162e9f in main (argc=2, argv=0xa42a10) at emacs.c:2409

Lisp Backtrace:
"put-text-property" (0x82b790)
"c-forward-sws" (0x82c0a8)
"c-fl-decl-start" (0x82c7d8)
"c-context-expand-fl-region" (0x82cdd0)
0x753e6b0 PVEC_COMPILED
"mapc" (0x82d688)
"c-before-context-fl-expand-region" (0x82dc90)
"c-type-finder-timer-func" (0x82e530)
"apply" (0x82e528)
"timer-event-handler" (0x82eba8)
(gdb) fr 4
#4  0x01316fcf in Fput_text_property (start=make_fixnum(39237),
    end=make_fixnum(39238), property=XIL(0x56056f0), value=XIL(0x30),
    object=XIL(0)) at textprop.c:1314
1314      Fadd_text_properties (start, end, properties, object);
(gdb) pp property
c-is-sws

----------------------------------------------------------------------

#0  0x013118d6 in modiff_incr (a=0x6ee5310) at lisp.h:3552
#1  0x0131203e in modify_text_properties (buffer=XIL(0xa000000006ee50a0),
    start=make_fixnum(39339), end=make_fixnum(39340)) at textprop.c:91
#2  0x01316a2b in add_text_properties_1 (start=make_fixnum(39339),
    end=make_fixnum(39340), properties=XIL(0xc00000000082b258),
    object=XIL(0xa000000006ee50a0), set_type=TEXT_PROPERTY_REPLACE,
    destructive=true) at textprop.c:1224
#3  0x01316ef0 in Fadd_text_properties (start=make_fixnum(39339),
    end=make_fixnum(39340), properties=XIL(0xc00000000082b258), object=XIL(0))
    at textprop.c:1296
#4  0x01316fcf in Fput_text_property (start=make_fixnum(39339),
    end=make_fixnum(39340), property=XIL(0x57a2ff8), value=XIL(0x566adc8),
    object=XIL(0)) at textprop.c:1314
#5  0x012670c5 in funcall_subr (subr=0x17216a0 <Sput_text_property>,
    numargs=4, args=0x82b478) at eval.c:3152
#6  0x012669b1 in Ffuncall (nargs=5, args=0x82b470) at eval.c:3065
#7  0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074a3208),
    vector=XIL(0xa000000006f37550), maxdepth=make_fixnum(10),
    args_template=make_fixnum(770), nargs=3, args=0x82bca0) at bytecode.c:632
#8  0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006f376e8),
    syms_left=make_fixnum(770), nargs=3, args=0x82bc88) at eval.c:3189
#9  0x01267a73 in funcall_lambda (fun=XIL(0xa000000006f376e8), nargs=3,
    arg_vector=0x82bc88) at eval.c:3270
#10 0x01266a21 in Ffuncall (nargs=4, args=0x82bc80) at eval.c:3069
#11 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074a3348),
    vector=XIL(0xa000000007581b18), maxdepth=make_fixnum(8),
    args_template=make_fixnum(770), nargs=3, args=0x82c348) at bytecode.c:632
#12 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000007581bc8),
    syms_left=make_fixnum(770), nargs=3, args=0x82c330) at eval.c:3189
#13 0x01267a73 in funcall_lambda (fun=XIL(0xa000000007581bc8), nargs=3,
    arg_vector=0x82c330) at eval.c:3270
#14 0x01266a21 in Ffuncall (nargs=4, args=0x82c328) at eval.c:3069
#15 0x012d3314 in exec_byte_code (bytestr=XIL(0x8000000006f7a9f0),
    vector=XIL(0xa0000000065a7a50), maxdepth=make_fixnum(23),
    args_template=make_fixnum(1028), nargs=4, args=0x82d658) at bytecode.c:632
#16 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa0000000065a7c68),
    syms_left=make_fixnum(1028), nargs=4, args=0x82d638) at eval.c:3189
#17 0x01267a73 in funcall_lambda (fun=XIL(0xa0000000065a7c68), nargs=4,
    arg_vector=0x82d638) at eval.c:3270
#18 0x01266a21 in Ffuncall (nargs=5, args=0x82d630) at eval.c:3069
#19 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074a3338),
    vector=XIL(0xa000000006f37c50), maxdepth=make_fixnum(18),
    args_template=make_fixnum(514), nargs=2, args=0x82dca8) at bytecode.c:632
#20 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006f37c98),
    syms_left=make_fixnum(514), nargs=2, args=0x82dc98) at eval.c:3189
#21 0x01267a73 in funcall_lambda (fun=XIL(0xa000000006f37c98), nargs=2,
    arg_vector=0x82dc98) at eval.c:3270
#22 0x01266a21 in Ffuncall (nargs=3, args=0x82dc90) at eval.c:3069
#23 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000074a3398),
    vector=XIL(0xa000000006f6c918), maxdepth=make_fixnum(11),
    args_template=make_fixnum(0), nargs=0, args=0x82e530) at bytecode.c:632
#24 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006f37d58),
    syms_left=make_fixnum(0), nargs=0, args=0x82e530) at eval.c:3189
#25 0x01267a73 in funcall_lambda (fun=XIL(0xa000000006f37d58), nargs=0,
    arg_vector=0x82e530) at eval.c:3270
#26 0x01266a21 in Ffuncall (nargs=1, args=0x82e528) at eval.c:3069
#27 0x01264f28 in Fapply (nargs=2, args=0x82e528) at eval.c:2648
#28 0x01266e59 in funcall_subr (subr=0x171eda0 <Sapply>, numargs=2,
    args=0x82e528) at eval.c:3120
#29 0x012669b1 in Ffuncall (nargs=3, args=0x82e520) at eval.c:3065
#30 0x012d3314 in exec_byte_code (bytestr=XIL(0x80000000061333c4),
    vector=XIL(0xa000000006133294), maxdepth=make_fixnum(10),
    args_template=make_fixnum(257), nargs=1, args=0x82ebb0) at bytecode.c:632
#31 0x012674f6 in fetch_and_exec_byte_code (fun=XIL(0xa000000006133264),
    syms_left=make_fixnum(257), nargs=1, args=0x82eba8) at eval.c:3189
#32 0x01267a73 in funcall_lambda (fun=XIL(0xa000000006133264), nargs=1,
    arg_vector=0x82eba8) at eval.c:3270
#33 0x01266a21 in Ffuncall (nargs=2, args=0x82eba0) at eval.c:3069
#34 0x01265cc4 in call1 (fn=XIL(0xf120), arg1=XIL(0xa00000000753e580))
    at eval.c:2925
#35 0x0117447a in timer_check_2 (timers=XIL(0), idle_timers=XIL(0))
    at keyboard.c:4374
#36 0x01174675 in timer_check () at keyboard.c:4436
#37 0x01171ed6 in readable_events (flags=1) at keyboard.c:3448
#38 0x0117c519 in get_input_pending (flags=1) at keyboard.c:6924
#39 0x0118878d in detect_input_pending_run_timers (do_display=false)
    at keyboard.c:10454
#40 0x0116e798 in read_char (commandflag=1, map=XIL(0xc000000007629a30),
    prev_event=XIL(0), used_mouse_menu=0x82f45f, end_time=0x0)
    at keyboard.c:2813
#41 0x01185e58 in read_key_sequence (keybuf=0x82f760, prompt=XIL(0),
    dont_downcase_last=false, can_return_switch_frame=true,
    fix_current_buffer=true, prevent_redisplay=false) at keyboard.c:9631
#42 0x0116924a in command_loop_1 () at keyboard.c:1393
#43 0x0126082e in internal_condition_case (bfun=0x1168b27 <command_loop_1>,
    handlers=XIL(0x90), hfun=0x1167b25 <cmd_error>) at eval.c:1492
#44 0x01168594 in command_loop_2 (handlers=XIL(0x90)) at keyboard.c:1134
#45 0x0125f6bf in internal_catch (tag=XIL(0xf3f0),
    func=0x116855d <command_loop_2>, arg=XIL(0x90)) at eval.c:1223
#46 0x01168517 in command_loop () at keyboard.c:1112
#47 0x0116758d in recursive_edit_1 () at keyboard.c:721
#48 0x01167823 in Frecursive_edit () at keyboard.c:804
#49 0x01162e9f in main (argc=2, argv=0xa42a10) at emacs.c:2409

Lisp Backtrace:
"put-text-property" (0x82b478)
"c-get-fontification-context" (0x82bc88)
0x7581bc8 PVEC_COMPILED
"c-find-decl-spots" (0x82d638)
"c-find-types-background" (0x82dc98)
"c-type-finder-timer-func" (0x82e530)
"apply" (0x82e528)
"timer-event-handler" (0x82eba8)
(gdb) fr 4
#4  0x01316fcf in Fput_text_property (start=make_fixnum(39339),
    end=make_fixnum(39340), property=XIL(0x57a2ff8), value=XIL(0x566adc8),
    object=XIL(0)) at textprop.c:1314
1314      Fadd_text_properties (start, end, properties, object);
(gdb) pp property
c-type

Message #32 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Fri, 10 Dec 2021 18:16:21 +0000

Hello, Eli.

On Thu, Dec 09, 2021 at 22:38:32 +0200, Eli Zaretskii wrote:
> > Date: Thu, 9 Dec 2021 20:11:32 +0000
> > Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> > From: Alan Mackenzie <acm <at> muc.de>

[ .... ]

> It seems the reason is not the 'fontified' property, it's the
> 'c-is-sws' property that c-forward-sws puts on the buffer text.  I
> show the backtrace below.  There's also the 'c-type' property that
> c-get-fontification-context puts; see the second backtrace below.

Thanks for the debugging!

> Both of these are called from the timer function.  Are they using
> with-silent-modifications?

I'm pretty sure they are.

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.

The main reason for all the redisplaying (which I got from
trace-redisplay displaying "redisplay_preserve_echo_area (8)") is the
call from detect_input_pending_run_timers in keyboard.c.  It is calling
redisplay_preserve_echo_area each time the timer triggers.

The call to detect_input_pending_run_timers (true) (that argument being
`do_display') seems to be in dispnew.c, assuming it's not in process.c.
I'll need to look further into this.

> The result of this is that the buffer's modification tick is increased
> all the time, and redisplay_window then decides that the current glyph
> matrix is not up-to-date, which means it must work harder to decide
> how to redisplay this window.

> Here are the two backtraces I promised:

> #0  0x013118d6 in modiff_incr (a=0x6ee5310) at lisp.h:3552
> #1  0x0131203e in modify_text_properties (buffer=XIL(0xa000000006ee50a0),
>     start=make_fixnum(39237), end=make_fixnum(39238)) at textprop.c:91
> #2  0x01316a2b in add_text_properties_1 (start=make_fixnum(39237),
>     end=make_fixnum(39238), properties=XIL(0xc00000000082b538),
>     object=XIL(0xa000000006ee50a0), set_type=TEXT_PROPERTY_REPLACE,
>     destructive=true) at textprop.c:1224
> #3  0x01316ef0 in Fadd_text_properties (start=make_fixnum(39237),
>     end=make_fixnum(39238), properties=XIL(0xc00000000082b538), object=XIL(0))
>     at textprop.c:1296
> #4  0x01316fcf in Fput_text_property (start=make_fixnum(39237),
>     end=make_fixnum(39238), property=XIL(0x56056f0), value=XIL(0x30),
>     object=XIL(0)) at textprop.c:1314
> #5  0x012670c5 in funcall_subr (subr=0x17216a0 <Sput_text_property>,
>     numargs=4, args=0x82b790) at eval.c:3152

[ .... ]

> Lisp Backtrace:
> "put-text-property" (0x82b790)
> "c-forward-sws" (0x82c0a8)
> "c-fl-decl-start" (0x82c7d8)
> "c-context-expand-fl-region" (0x82cdd0)
> 0x753e6b0 PVEC_COMPILED
> "mapc" (0x82d688)
> "c-before-context-fl-expand-region" (0x82dc90)
> "c-type-finder-timer-func" (0x82e530)
> "apply" (0x82e528)
> "timer-event-handler" (0x82eba8)

> ----------------------------------------------------------------------

> #0  0x013118d6 in modiff_incr (a=0x6ee5310) at lisp.h:3552
> #1  0x0131203e in modify_text_properties (buffer=XIL(0xa000000006ee50a0),
>     start=make_fixnum(39339), end=make_fixnum(39340)) at textprop.c:91
> #2  0x01316a2b in add_text_properties_1 (start=make_fixnum(39339),
>     end=make_fixnum(39340), properties=XIL(0xc00000000082b258),
>     object=XIL(0xa000000006ee50a0), set_type=TEXT_PROPERTY_REPLACE,
>     destructive=true) at textprop.c:1224
> #3  0x01316ef0 in Fadd_text_properties (start=make_fixnum(39339),
>     end=make_fixnum(39340), properties=XIL(0xc00000000082b258), object=XIL(0))
>     at textprop.c:1296
> #4  0x01316fcf in Fput_text_property (start=make_fixnum(39339),
>     end=make_fixnum(39340), property=XIL(0x57a2ff8), value=XIL(0x566adc8),
>     object=XIL(0)) at textprop.c:1314
> #5  0x012670c5 in funcall_subr (subr=0x17216a0 <Sput_text_property>,
>     numargs=4, args=0x82b478) at eval.c:3152

[ .... ]

> Lisp Backtrace:
> "put-text-property" (0x82b478)
> "c-get-fontification-context" (0x82bc88)
> 0x7581bc8 PVEC_COMPILED
> "c-find-decl-spots" (0x82d638)
> "c-find-types-background" (0x82dc98)
> "c-type-finder-timer-func" (0x82e530)
> "apply" (0x82e528)
> "timer-event-handler" (0x82eba8)
> (gdb) fr 4
> #4  0x01316fcf in Fput_text_property (start=make_fixnum(39339),
>     end=make_fixnum(39340), property=XIL(0x57a2ff8), value=XIL(0x566adc8),
>     object=XIL(0)) at textprop.c:1314
> 1314      Fadd_text_properties (start, end, properties, object);
> (gdb) pp property
> c-type

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #35 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Fri, 10 Dec 2021 20:51:32 +0200

> Date: Fri, 10 Dec 2021 18:16:21 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> muc.de>
> 
> > Both of these are called from the timer function.  Are they using
> > with-silent-modifications?
> 
> I'm pretty sure they are.
> 
> 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.  Are you sure you see that?  And what kind of 'if'
did you try to put and where?

> The main reason for all the redisplaying (which I got from
> trace-redisplay displaying "redisplay_preserve_echo_area (8)") is the
> call from detect_input_pending_run_timers in keyboard.c.  It is calling
> redisplay_preserve_echo_area each time the timer triggers.

This is normal, not something you need to investigate: every time a
timer function fires, we make one more iteration through the Emacs
idle loop, and that includes a call to redisplay_preserve_echo_area.

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.

Message #38 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Fri, 10 Dec 2021 22:52:40 +0000

Hello, Eli.

On Fri, Dec 10, 2021 at 20:51:32 +0200, Eli Zaretskii wrote:
> > Date: Fri, 10 Dec 2021 18:16:21 +0000
> > Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> > From: Alan Mackenzie <acm <at> muc.de>

> > > Both of these are called from the timer function.  Are they using
> > > with-silent-modifications?

> > I'm pretty sure they are.

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

> 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);
+    }

   bset_point_before_scroll (current_buffer, Qnil);


> > The main reason for all the redisplaying (which I got from
> > trace-redisplay displaying "redisplay_preserve_echo_area (8)") is the
> > call from detect_input_pending_run_timers in keyboard.c.  It is calling
> > redisplay_preserve_echo_area each time the timer triggers.

> This is normal, not something you need to investigate: every time a
> timer function fires, we make one more iteration through the Emacs
> idle loop, and that includes a call to redisplay_preserve_echo_area.

Ah, OK.

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

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.

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.  The
--enable-cheking=yes,glyphs will have slowed the machine down somewhat.
One refinement would be to turn off the timer when All the CC Mode
buffers have been scanned, only reenabling it when a new CC Mode buffer
gets loaded.  That might save that 0.3% core time at the end of the
found-type scan.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #41 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sat, 11 Dec 2021 09:59:38 +0200

> Date: Fri, 10 Dec 2021 22:52:40 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> 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?  Could we perhaps refrain from putting
them on buffer text when those functions are called from the timer?

And why does that timer have to tick so frequently?

> > 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?

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

Message #44 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sat, 11 Dec 2021 14:52:22 +0000

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 <at> debbugs.gnu.org, acm <at> muc.de
> > From: Alan Mackenzie <acm <at> 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).

Message #47 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sat, 11 Dec 2021 17:38:34 +0200

> Date: Sat, 11 Dec 2021 14:52:22 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> muc.de>
> 
> 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.

But we are talking about the timer whose job is to find type
declarations.  Does that job require these properties?

> 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?

I already established that, it's the fact that the buffer's modified
tick is increasing.  This then causes this test:

  current_matrix_up_to_date_p
    = (w->window_end_valid
       && !current_buffer->clip_changed
       && !current_buffer->prevent_redisplay_optimizations_p
       && !window_outdated (w)
       && !hscrolling_current_line_p (w));

to fail because window_outdated returns non-zero.  That's how I knew
that the buffer's modified tick is the culprit.

> 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:
> [...]
> 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.

So why is the timer function keep running for so long, and why does it
put those two other properties on the rest of the buffer?  It sounds
to me like you could stop the timer once the visible portion of the
buffer has been reached, because no type after that can affect
fontification.  You could then restart the timer when the buffer is
modified, or if the window is scrolled to reveal a portion of the
buffer below the current end-of-window.

Message #50 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sat, 11 Dec 2021 17:04:28 +0000

Hello, Eli.

On Sat, Dec 11, 2021 at 17:38:34 +0200, Eli Zaretskii wrote:
> > Date: Sat, 11 Dec 2021 14:52:22 +0000
> > Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> > From: Alan Mackenzie <acm <at> muc.de>

> > 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?

> I already established that, it's the fact that the buffer's modified
> tick is increasing.  This then causes this test:

>   current_matrix_up_to_date_p
>     = (w->window_end_valid
>        && !current_buffer->clip_changed
>        && !current_buffer->prevent_redisplay_optimizations_p
>        && !window_outdated (w)
>        && !hscrolling_current_line_p (w));

> to fail because window_outdated returns non-zero.  That's how I knew
> that the buffer's modified tick is the culprit.

Ah, OK.  Then this bit seems clear.  With that patch of mine in
textprop.c, which tests inhibit_modification_hooks before modifying the
tick, I don't see the "try_window_id 2" lines in the trace-redisplay
output.

So, I suggest I write a commit message and commit that patch.

;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;

Unfortunately, it makes little difference to the CPU usage of CC Mode in
the few minutes after visiting xdisp.c.

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

> But we are talking about the timer whose job is to find type
> declarations.  Does that job require these properties?

I can't say for definite, off hand, but almost certainly yes.  After the
first answer of this post, does it still matter?

> > 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:
> > [...]
> > 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.

> So why is the timer function keep running for so long, and why does it
> put those two other properties on the rest of the buffer?  It sounds
> to me like you could stop the timer once the visible portion of the
> buffer has been reached, because no type after that can affect
> fontification.

That's sadly not true.  The source code which determines an identifier is
a "found type" is frequently distant from the place where the identifier
needs to be fontified as a type.  For, example, near the beginning of a C
buffer we might have:

    foo (bar, baz);

and somewhere else we have code defining `bar' and `baz' as types, so
that the code line is in fact defining a forward declaration of an int
function, and isn't a function call with two arguments.

Other more usual things (which I can't think of at the moment) caused the
randomness in the fontification which gave rise to that long thread
earlier on in the year.

> You could then restart the timer when the buffer is modified, or if the
> window is scrolled to reveal a portion of the buffer below the current
> end-of-window.

Unfortunately not.  To fontify the current window contents reliably
involves having scanned the entire buffer.

It may well be that this refinement is too expensive in processing power
to be worthwhile.

I am puzzled as to why the mechanism is only taking around 20% - 25% of a
CPU core's time.  It is customised to take (a little more than) 0.05s of
every 0.1s.  Yet it is only taking a third to a half of that amount, even
less when one takes garbage collection into account.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #53 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sat, 11 Dec 2021 20:21:51 +0200

> Date: Sat, 11 Dec 2021 17:04:28 +0000
> Cc: 52298 <at> debbugs.gnu.org
> From: Alan Mackenzie <acm <at> muc.de>
> 
> So, I suggest I write a commit message and commit that patch.

Which patch?  I'm afraid I'm missing something here.

Message #56 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: acm <at> muc.de, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sun, 12 Dec 2021 08:58:08 +0000

Hello, Eli.

On Sat, Dec 11, 2021 at 20:21:51 +0200, Eli Zaretskii wrote:
> > Date: Sat, 11 Dec 2021 17:04:28 +0000
> > Cc: 52298 <at> debbugs.gnu.org
> > From: Alan Mackenzie <acm <at> muc.de>

> > So, I suggest I write a commit message and commit that patch.

> Which patch?  I'm afraid I'm missing something here.

This one, the one that should prevent excessive incursions into the
redisplay engine when a text property gets set whilst
inhibit-modification-hooks is set:

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);
+    }
 
   bset_point_before_scroll (current_buffer, Qnil);
 
-- 
Alan Mackenzie (Nuremberg, Germany).

Message #59 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sun, 12 Dec 2021 11:15:34 +0200

> Date: Sun, 12 Dec 2021 08:58:08 +0000
> Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> From: Alan Mackenzie <acm <at> muc.de>
> 
> > > So, I suggest I write a commit message and commit that patch.
> 
> > Which patch?  I'm afraid I'm missing something here.
> 
> This one, the one that should prevent excessive incursions into the
> redisplay engine when a text property gets set whilst
> inhibit-modification-hooks is set:

No, this cannot be used as-is, because when face properties change, we
do want redisplay to take notice, of course.  I guess that's why
inhibit-modification-hooks doesn't prevent incrementing the
modification tick when text properties are changed in the first place:
it's not feasible to know which text properties affect the display and
which don't.  No one expected text properties irrelevant to display to
be put on buffer text with such high frequency.

If you don't have any other ideas, I guess we will have to live with
this.  Too bad.

(Sorry, but I like CC Mode less and less with every Emacs release, due
to changes like this one.)

Message #62 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sun, 12 Dec 2021 19:05:45 +0000

Hello, Eli.

On Sun, Dec 12, 2021 at 11:15:34 +0200, Eli Zaretskii wrote:
> > Date: Sun, 12 Dec 2021 08:58:08 +0000
> > Cc: 52298 <at> debbugs.gnu.org, acm <at> muc.de
> > From: Alan Mackenzie <acm <at> muc.de>

> > > > So, I suggest I write a commit message and commit that patch.

> > > Which patch?  I'm afraid I'm missing something here.

> > This one, the one that should prevent excessive incursions into the
> > redisplay engine when a text property gets set whilst
> > inhibit-modification-hooks is set:

> No, this cannot be used as-is, because when face properties change, we
> do want redisplay to take notice, of course.  I guess that's why
> inhibit-modification-hooks doesn't prevent incrementing the
> modification tick when text properties are changed in the first place:
> it's not feasible to know which text properties affect the display and
> which don't.  No one expected text properties irrelevant to display to
> be put on buffer text with such high frequency.

Yes, that makes sense, thanks.  Maybe I'll put a comment in there saying
that.

> If you don't have any other ideas, I guess we will have to live with
> this.  Too bad.

> (Sorry, but I like CC Mode less and less with every Emacs release, due
> to changes like this one.)

This particular feature simply hasn't worked out well.  If the
background scanning were to complete in a few seconds, it wouldn't be
too bad.  But nearly two minutes on a modern (well, 4½ yo) machine for
just one buffer, with the annoyance of the "stuttering", is not worth
the gain.

What we have is effectively the entire buffer getting half-fontified in
the background.  That's not what JIT fontification is supposed to be
about.

So, in the next few days sometime, I will revert most of this change.  A
useful and harmless piece of it (fontifying a newly found type
throughout the buffer when it is encountered in "normal" jit
fontification), I plan to leave in.  That will get rid of that timer and
all the background scanning it triggered.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #65 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Alan Mackenzie <acm <at> muc.de>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sun, 12 Dec 2021 21:21:40 +0200

> Date: Sun, 12 Dec 2021 19:05:45 +0000
> Cc: 52298 <at> debbugs.gnu.org
> From: Alan Mackenzie <acm <at> muc.de>
> 
> This particular feature simply hasn't worked out well.  If the
> background scanning were to complete in a few seconds, it wouldn't be
> too bad.  But nearly two minutes on a modern (well, 4½ yo) machine for
> just one buffer, with the annoyance of the "stuttering", is not worth
> the gain.
> 
> What we have is effectively the entire buffer getting half-fontified in
> the background.  That's not what JIT fontification is supposed to be
> about.

Maybe just lowering the frequency of the time would be enough.  Or
running it off an idle timer.  E.g., I'm a happy user if jit-stealth,
and it never causes me any annoying side effects.  So maybe this
feature could run similarly?

Thanks.

Message #68 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Daniel Martín <mardani29 <at> yahoo.es>
To: Alan Mackenzie <acm <at> muc.de>
Cc: Eli Zaretskii <eliz <at> gnu.org>, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Mon, 13 Dec 2021 00:31:38 +0100

Alan Mackenzie <acm <at> muc.de> writes:

>
> This particular feature simply hasn't worked out well.  If the
> background scanning were to complete in a few seconds, it wouldn't be
> too bad.  But nearly two minutes on a modern (well, 4½ yo) machine for
> just one buffer, with the annoyance of the "stuttering", is not worth
> the gain.

If you want another data point, on my 2017 MacBook Pro visiting xdisp.c
took 1:30 min of background work (using 25% of the CPU).

Is it possible to make the feature optional, even for the default
font-lock decoration level in CC mode?  So only the people that want
more accurate highlighting of types pay the cost of this background
work.

Message #71 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Mon, 13 Dec 2021 14:19:40 +0000

Hello, Eli.

On Sun, Dec 12, 2021 at 21:21:40 +0200, Eli Zaretskii wrote:
> > Date: Sun, 12 Dec 2021 19:05:45 +0000
> > Cc: 52298 <at> debbugs.gnu.org
> > From: Alan Mackenzie <acm <at> muc.de>

> > This particular feature simply hasn't worked out well.  If the
> > background scanning were to complete in a few seconds, it wouldn't be
> > too bad.  But nearly two minutes on a modern (well, 4½ yo) machine for
> > just one buffer, with the annoyance of the "stuttering", is not worth
> > the gain.

> > What we have is effectively the entire buffer getting half-fontified in
> > the background.  That's not what JIT fontification is supposed to be
> > about.

> Maybe just lowering the frequency of the time would be enough.

Then instead of the scanning taking 2 minutes, it would take 10 or 20.
And that's just for one buffer, albeit a large one.

I would then, possibly, get complaints about CC Mode having to "warm up"
for half an hour before it was ready for use.  (Only half-serious.)

> Or running it off an idle timer.  E.g., I'm a happy user of
> jit-stealth, and it never causes me any annoying side effects.  So
> maybe this feature could run similarly?

I think it would be better just to use jit-stealth fontification, and
not have a special stealth-like feature for CC Mode.  With part of the
feature left in the code (the bit that causes the buffer's entire
fontification to be updated when a new found type is found), the current
stealth will eventually correct any wrongly fontified found types.

Sadly, there seem to be limits on how far correctness can go.  Maybe
when our PC cores are 10 times as powerful (if that ever happens), this
feature could return.  I suspect CC Mode may have been superseded by
then.

> Thanks.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #74 received at 52298 <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Daniel Martín <mardani29 <at> yahoo.es>
Cc: acm <at> muc.de, Eli Zaretskii <eliz <at> gnu.org>, 52298 <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Mon, 13 Dec 2021 14:25:20 +0000

Hello, Daniel.

On Mon, Dec 13, 2021 at 00:31:38 +0100, Daniel Martín wrote:
> Alan Mackenzie <acm <at> muc.de> writes:

> > This particular feature simply hasn't worked out well.  If the
> > background scanning were to complete in a few seconds, it wouldn't
> > be too bad.  But nearly two minutes on a modern (well, 4½ yo)
> > machine for just one buffer, with the annoyance of the "stuttering",
> > is not worth the gain.

> If you want another data point, on my 2017 MacBook Pro visiting xdisp.c
> took 1:30 min of background work (using 25% of the CPU).

Thanks, that's helpful.  It confirms that the slow background
fontification check is real, not just an artifact of my current set up.

> Is it possible to make the feature optional, even for the default
> font-lock decoration level in CC mode?  So only the people that want
> more accurate highlighting of types pay the cost of this background
> work.

It would be possible, but I don't think it would be a good idea.  People
generally tend to stay unaware of this sort of option (how many people
know about stealth fontification, for example?), and the cost of
maintaining it is fairly high.

I still think the best thing to do is to rip it out.  It was a
worthwhile experiment, but one which didn't deliver the desired result.

-- 
Alan Mackenzie (Nuremberg, Germany).

Message #79 received at 52298-done <at> debbugs.gnu.org (full text, mbox):

From: Alan Mackenzie <acm <at> muc.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 52298-done <at> debbugs.gnu.org
Subject: Re: bug#52298: 29.0.50; Frequent redisplay cycles induced by
 c-type-finder-timer-func timer in CC Mode
Date: Sun, 19 Dec 2021 14:38:14 +0000

Hello, Eli.

On Sun, Dec 12, 2021 at 19:05:45 +0000, Alan Mackenzie wrote:

> On Sun, Dec 12, 2021 at 11:15:34 +0200, Eli Zaretskii wrote:

[ .... ]

> > (Sorry, but I like CC Mode less and less with every Emacs release, due
> > to changes like this one.)

> This particular feature simply hasn't worked out well.  If the
> background scanning were to complete in a few seconds, it wouldn't be
> too bad.  But nearly two minutes on a modern (well, 4½ yo) machine for
> just one buffer, with the annoyance of the "stuttering", is not worth
> the gain.

> What we have is effectively the entire buffer getting half-fontified in
> the background.  That's not what JIT fontification is supposed to be
> about.

> So, in the next few days sometime, I will revert most of this change.  A
> useful and harmless piece of it (fontifying a newly found type
> throughout the buffer when it is encountered in "normal" jit
> fontification), I plan to leave in.  That will get rid of that timer and
> all the background scanning it triggered.

I've removed this feature as promised last Sunday, and I'm sure the
problem with the "stuttering" is now gone.  So I'm closing the bug with
this post.

-- 
Alan Mackenzie (Nuremberg, Germany).

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.