* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode @ 2021-12-05 7:46 Eli Zaretskii 2021-12-06 20:53 ` Alan Mackenzie 2021-12-08 20:15 ` Alan Mackenzie 0 siblings, 2 replies; 25+ messages in thread From: Eli Zaretskii @ 2021-12-05 7:46 UTC (permalink / raw) To: 52298; +Cc: Alan Mackenzie 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)) ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-05 7:46 bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode Eli Zaretskii @ 2021-12-06 20:53 ` Alan Mackenzie 2021-12-07 12:58 ` Eli Zaretskii 2021-12-08 20:15 ` Alan Mackenzie 1 sibling, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-06 20:53 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298 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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-06 20:53 ` Alan Mackenzie @ 2021-12-07 12:58 ` Eli Zaretskii 2021-12-07 19:58 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-07 12:58 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Mon, 6 Dec 2021 20:53:15 +0000 > Cc: bug-gnu-emacs@gnu.org > From: Alan Mackenzie <acm@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? ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-07 12:58 ` Eli Zaretskii @ 2021-12-07 19:58 ` Alan Mackenzie 2021-12-07 20:16 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-07 19:58 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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@gnu.org > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-07 19:58 ` Alan Mackenzie @ 2021-12-07 20:16 ` Eli Zaretskii 0 siblings, 0 replies; 25+ messages in thread From: Eli Zaretskii @ 2021-12-07 20:16 UTC (permalink / raw) To: Alan Mackenzie; +Cc: acm, 52298 > Date: Tue, 7 Dec 2021 19:58:39 +0000 > Cc: 52298@debbugs.gnu.org, acm@muc.de > From: Alan Mackenzie <acm@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? ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-05 7:46 bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode Eli Zaretskii 2021-12-06 20:53 ` Alan Mackenzie @ 2021-12-08 20:15 ` Alan Mackenzie 2021-12-09 7:08 ` Eli Zaretskii 1 sibling, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-08 20:15 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298 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). ^ permalink raw reply related [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-08 20:15 ` Alan Mackenzie @ 2021-12-09 7:08 ` Eli Zaretskii 2021-12-09 20:11 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-09 7:08 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Wed, 8 Dec 2021 20:15:46 +0000 > Cc: bug-gnu-emacs@gnu.org > From: Alan Mackenzie <acm@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. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-09 7:08 ` Eli Zaretskii @ 2021-12-09 20:11 ` Alan Mackenzie 2021-12-09 20:38 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-09 20:11 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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@gnu.org > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-09 20:11 ` Alan Mackenzie @ 2021-12-09 20:38 ` Eli Zaretskii 2021-12-10 18:16 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-09 20:38 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Thu, 9 Dec 2021 20:11:32 +0000 > Cc: 52298@debbugs.gnu.org, acm@muc.de > From: Alan Mackenzie <acm@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 ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-09 20:38 ` Eli Zaretskii @ 2021-12-10 18:16 ` Alan Mackenzie 2021-12-10 18:51 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-10 18:16 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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@debbugs.gnu.org, acm@muc.de > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-10 18:16 ` Alan Mackenzie @ 2021-12-10 18:51 ` Eli Zaretskii 2021-12-10 22:52 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-10 18:51 UTC (permalink / raw) To: Alan Mackenzie; +Cc: acm, 52298 > Date: Fri, 10 Dec 2021 18:16:21 +0000 > Cc: 52298@debbugs.gnu.org, acm@muc.de > From: Alan Mackenzie <acm@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. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-10 18:51 ` Eli Zaretskii @ 2021-12-10 22:52 ` Alan Mackenzie 2021-12-11 7:59 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-10 22:52 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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@debbugs.gnu.org, acm@muc.de > > From: Alan Mackenzie <acm@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). ^ permalink raw reply related [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-10 22:52 ` Alan Mackenzie @ 2021-12-11 7:59 ` Eli Zaretskii 2021-12-11 14:52 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-11 7:59 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > 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? 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? ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-11 7:59 ` Eli Zaretskii @ 2021-12-11 14:52 ` Alan Mackenzie 2021-12-11 15:38 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-11 14:52 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-11 14:52 ` Alan Mackenzie @ 2021-12-11 15:38 ` Eli Zaretskii 2021-12-11 17:04 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-11 15:38 UTC (permalink / raw) To: Alan Mackenzie; +Cc: acm, 52298 > Date: Sat, 11 Dec 2021 14:52:22 +0000 > Cc: 52298@debbugs.gnu.org, acm@muc.de > From: Alan Mackenzie <acm@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. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-11 15:38 ` Eli Zaretskii @ 2021-12-11 17:04 ` Alan Mackenzie 2021-12-11 18:21 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-11 17:04 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298 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@debbugs.gnu.org, acm@muc.de > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-11 17:04 ` Alan Mackenzie @ 2021-12-11 18:21 ` Eli Zaretskii 2021-12-12 8:58 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-11 18:21 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Sat, 11 Dec 2021 17:04:28 +0000 > Cc: 52298@debbugs.gnu.org > From: Alan Mackenzie <acm@muc.de> > > So, I suggest I write a commit message and commit that patch. Which patch? I'm afraid I'm missing something here. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-11 18:21 ` Eli Zaretskii @ 2021-12-12 8:58 ` Alan Mackenzie 2021-12-12 9:15 ` Eli Zaretskii 0 siblings, 1 reply; 25+ messages in thread From: Alan Mackenzie @ 2021-12-12 8:58 UTC (permalink / raw) To: Eli Zaretskii; +Cc: acm, 52298 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@debbugs.gnu.org > > From: Alan Mackenzie <acm@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). ^ permalink raw reply related [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 8:58 ` Alan Mackenzie @ 2021-12-12 9:15 ` Eli Zaretskii 2021-12-12 19:05 ` Alan Mackenzie 0 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-12 9:15 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Sun, 12 Dec 2021 08:58:08 +0000 > Cc: 52298@debbugs.gnu.org, acm@muc.de > From: Alan Mackenzie <acm@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.) ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 9:15 ` Eli Zaretskii @ 2021-12-12 19:05 ` Alan Mackenzie 2021-12-12 19:21 ` Eli Zaretskii ` (2 more replies) 0 siblings, 3 replies; 25+ messages in thread From: Alan Mackenzie @ 2021-12-12 19:05 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298 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@debbugs.gnu.org, acm@muc.de > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 19:05 ` Alan Mackenzie @ 2021-12-12 19:21 ` Eli Zaretskii 2021-12-13 14:19 ` Alan Mackenzie 2021-12-12 23:31 ` Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors 2021-12-19 14:38 ` Alan Mackenzie 2 siblings, 1 reply; 25+ messages in thread From: Eli Zaretskii @ 2021-12-12 19:21 UTC (permalink / raw) To: Alan Mackenzie; +Cc: 52298 > Date: Sun, 12 Dec 2021 19:05:45 +0000 > Cc: 52298@debbugs.gnu.org > From: Alan Mackenzie <acm@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. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 19:21 ` Eli Zaretskii @ 2021-12-13 14:19 ` Alan Mackenzie 0 siblings, 0 replies; 25+ messages in thread From: Alan Mackenzie @ 2021-12-13 14:19 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298 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@debbugs.gnu.org > > From: Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 19:05 ` Alan Mackenzie 2021-12-12 19:21 ` Eli Zaretskii @ 2021-12-12 23:31 ` Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors 2021-12-13 14:25 ` Alan Mackenzie 2021-12-19 14:38 ` Alan Mackenzie 2 siblings, 1 reply; 25+ messages in thread From: Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors @ 2021-12-12 23:31 UTC (permalink / raw) To: Alan Mackenzie; +Cc: Eli Zaretskii, 52298 Alan Mackenzie <acm@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. ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 23:31 ` Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors @ 2021-12-13 14:25 ` Alan Mackenzie 0 siblings, 0 replies; 25+ messages in thread From: Alan Mackenzie @ 2021-12-13 14:25 UTC (permalink / raw) To: Daniel Martín; +Cc: acm, 52298 Hello, Daniel. On Mon, Dec 13, 2021 at 00:31:38 +0100, Daniel Martín wrote: > Alan Mackenzie <acm@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). ^ permalink raw reply [flat|nested] 25+ messages in thread
* bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode 2021-12-12 19:05 ` Alan Mackenzie 2021-12-12 19:21 ` Eli Zaretskii 2021-12-12 23:31 ` Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors @ 2021-12-19 14:38 ` Alan Mackenzie 2 siblings, 0 replies; 25+ messages in thread From: Alan Mackenzie @ 2021-12-19 14:38 UTC (permalink / raw) To: Eli Zaretskii; +Cc: 52298-done 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). ^ permalink raw reply [flat|nested] 25+ messages in thread
end of thread, other threads:[~2021-12-19 14:38 UTC | newest] Thread overview: 25+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2021-12-05 7:46 bug#52298: 29.0.50; Frequent redisplay cycles induced by c-type-finder-timer-func timer in CC Mode Eli Zaretskii 2021-12-06 20:53 ` Alan Mackenzie 2021-12-07 12:58 ` Eli Zaretskii 2021-12-07 19:58 ` Alan Mackenzie 2021-12-07 20:16 ` Eli Zaretskii 2021-12-08 20:15 ` Alan Mackenzie 2021-12-09 7:08 ` Eli Zaretskii 2021-12-09 20:11 ` Alan Mackenzie 2021-12-09 20:38 ` Eli Zaretskii 2021-12-10 18:16 ` Alan Mackenzie 2021-12-10 18:51 ` Eli Zaretskii 2021-12-10 22:52 ` Alan Mackenzie 2021-12-11 7:59 ` Eli Zaretskii 2021-12-11 14:52 ` Alan Mackenzie 2021-12-11 15:38 ` Eli Zaretskii 2021-12-11 17:04 ` Alan Mackenzie 2021-12-11 18:21 ` Eli Zaretskii 2021-12-12 8:58 ` Alan Mackenzie 2021-12-12 9:15 ` Eli Zaretskii 2021-12-12 19:05 ` Alan Mackenzie 2021-12-12 19:21 ` Eli Zaretskii 2021-12-13 14:19 ` Alan Mackenzie 2021-12-12 23:31 ` Daniel Martín via Bug reports for GNU Emacs, the Swiss army knife of text editors 2021-12-13 14:25 ` Alan Mackenzie 2021-12-19 14:38 ` Alan Mackenzie
Code repositories for project(s) associated with this external index https://git.savannah.gnu.org/cgit/emacs.git https://git.savannah.gnu.org/cgit/emacs/org-mode.git This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.