GNU bug report logs - #66096
High CPU usage, basically runaway emacs with visit to bidi_cache_search on and off?

Previous Next

To reply to this bug, email your comments to 66096 AT debbugs.gnu.org.

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

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

From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
To: bug-gnu-emacs <at> gnu.org
Cc: "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
Subject: High CPU usage, basically runaway emacs with visit to
 bidi_cache_search on and off?
Date: Tue, 19 Sep 2023 13:12:33 +0900

High CPU usage, basically runaway emacs with visit to bidi_cache_search 
on and off?

Hi,

Environment:
OS GNU/Debian Linux  X86_64
Emacs version
GNU Emacs 29.1 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.38, 
cairo version 1.16.0) of 2023-08-01
I compiled emacs using gcc.

Has anyone seen emacs 29.1 spending CPU way too high, basically went
into an infinite loop of some sort, and could not be interrupted by
Control-G?  Basically it is in a runaway state.
I found that the stacktraces show that bidi_cache_search
and friends are visited now and then.  It is not the recursive blowup 
probably since the stack depth is quite limited during my observation.


I have experienced this issue this morning.  Observing the stack
backtrace by monitoring the runaway emacs using gdb, I was surprised
to see many appearances of bidi_cache_search that were observed from
time to time while I do control-C to stop emacs and monitor
stacktrace, and the continue for a few seconds, and interrupt it again
with control-C.  After letting emacs run in this manner for about 5
minutes, I had tp kill emacs.  I had to edit the file by a deadline and 
could not continue debugging. :-(

At the end is a single stacktrace with bidi_cache_search at the top.
I have seen this occurring multiple times. My hitting control-C to emacs 
to enter gdb interaction means that the chance of hitting a particular 
stacktrace pattern is small and seeing the same pattern multiple times 
means that that pattern happens quite often.

The file I was editing is a Japanese text file.  Sorry, it contains 
proprietary information and I can't share it immediately.  However, I
will be editing it again with emacs this afternoon and if the problem 
recurs, I will try to redact it as much as possible and see if the
runaway problem recurs then.

I have a dozen or so more different stacktraces during gdb monitoring.
If someone wants to see the log, I can post it.
What is the preferred URL where I can paste the whole gdb session?

TIA.

Regars,
Chiaki

One stacktrace with bidi_cache_searh at the top.
I notice that charpos 358 was near the end of the file (probably at the 
end?) when I had to kill the emacs..
Sorry I had to recover the edited file after killing emacs, and it may 
no longer contain the exact buffer data when the problem occurred.

thread 1 "emacs" received signal SIGINT, Interrupt.
0x0000556f1905af04 in bidi_cache_search (charpos=charpos <at> entry=358,
    dir=dir <at> entry=1, level=-1) at bidi.c:660
660          if (charpos < bidi_cache[bidi_cache_last_idx].charpos)
(gdb) where
#0  0x0000556f1905af04 in bidi_cache_search
    (charpos=charpos <at> entry=358, dir=dir <at> entry=1, level=-1) at bidi.c:660
#1  0x0000556f1905b8a9 in bidi_cache_find
    (charpos=358, resolved_only=resolved_only <at> entry=false, 
bidi_it=bidi_it <at> entry=0x7ffeb7caae48) at bidi.c:877
#2  0x0000556f1905db97 in bidi_resolve_brackets
    (bidi_it=bidi_it <at> entry=0x7ffeb7caae48) at bidi.c:2883
#3  0x0000556f1905df79 in bidi_resolve_neutral
    (bidi_it=bidi_it <at> entry=0x7ffeb7caae48) at bidi.c:3010
#4  0x0000556f1905e4a1 in bidi_type_of_next_char (bidi_it=0x7ffeb7caae48)
    at bidi.c:3215
#5  bidi_level_of_next_char (bidi_it=bidi_it <at> entry=0x7ffeb7caae48)
    at bidi.c:3282
#6  0x0000556f1905f60e in bidi_move_to_visually_next
    (bidi_it=bidi_it <at> entry=0x7ffeb7caae48) at bidi.c:3485
#7  0x0000556f18fe0d7a in set_iterator_to_next
    (it=0x7ffeb7caa410, reseat_p=<optimized out>) at xdisp.c:8588
#8  0x0000556f18fdcb8d in move_it_in_display_line_to
    (it=it <at> entry=0x7ffeb7caa410, to_charpos=to_charpos <at> entry=2078, 
to_x=to_x <at> entry=-1, op=op <at> entry=MOVE_TO_POS) at xdisp.c:10268
#9  0x0000556f18fe1b88 in move_it_to
    (it=it <at> entry=0x7ffeb7caa410, to_charpos=2078, to_x=to_x <at> entry=-1, 
to_y=to_y <at> entry=-1, to_vpos=to_vpos <at> entry=-1, op=op <at> entry=8) at 
xdisp.c:10623
#10 0x0000556f18fe358c in resize_mini_window (w=0x556f1a3b4240, 
exact_p=true)
    at xdisp.c:12778
#11 0x0000556f18fc973a in with_echo_area_buffer
    (w=0x556f1a3b4240, which=which <at> entry=0, fn=fn <at> entry=0x556f18fe4250 
<resize_mini_window_1>, a1=0x556f1a3b4240, a2=0x30) at xdisp.c:12422
#12 0x0000556f18ff5269 in resize_echo_area_exactly () at xdisp.c:12678
#13 0x0000556f190de46d in command_loop_1 () at keyboard.c:1528
#14 0x0000556f19156377 in internal_condition_case
    (bfun=bfun <at> entry=0x556f190ddcb0 <command_loop_1>, 
handlers=handlers <at> entry=0x90, hfun=hfun <at> entry=0x556f190d0f40 
<cmd_error>) at eval.c:1474
#15 0x0000556f190c9bf6 in command_loop_2 (handlers=handlers <at> entry=0x90)
    at keyboard.c:1133
#16 0x0000556f191562d1 in internal_catch
    (tag=tag <at> entry=0x10080, func=func <at> entry=0x556f190c9bd0 
<command_loop_2>, arg=arg <at> entry=0x90) at eval.c:1197
#17 0x0000556f190c9b91 in command_loop () at keyboard.c:1111
#18 0x0000556f190d0af1 in recursive_edit_1 () at keyboard.c:720
#19 0x0000556f190d0e70 in Frecursive_edit () at keyboard.c:803
#20 0x0000556f18fa3cf2 in main (argc=7, argv=0x7ffeb7cabd08) at emacs.c:2529
(gdb) c

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

From: Eli Zaretskii <eliz <at> gnu.org>
To: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
Cc: 66096 <at> debbugs.gnu.org, ishikawa <at> yk.rim.or.jp
Subject: Re: bug#66096: High CPU usage,
 basically runaway emacs with visit to bidi_cache_search on and off?
Date: Tue, 19 Sep 2023 14:04:08 +0300

> Cc: "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
> Date: Tue, 19 Sep 2023 13:12:33 +0900
> From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
> 
> High CPU usage, basically runaway emacs with visit to bidi_cache_search 
> on and off?
> 
> Hi,
> 
> Environment:
> OS GNU/Debian Linux  X86_64
> Emacs version
> GNU Emacs 29.1 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.38, 
> cairo version 1.16.0) of 2023-08-01
> I compiled emacs using gcc.
> 
> Has anyone seen emacs 29.1 spending CPU way too high, basically went
> into an infinite loop of some sort, and could not be interrupted by
> Control-G?  Basically it is in a runaway state.
> I found that the stacktraces show that bidi_cache_search
> and friends are visited now and then.  It is not the recursive blowup 
> probably since the stack depth is quite limited during my observation.
> 
> 
> I have experienced this issue this morning.  Observing the stack
> backtrace by monitoring the runaway emacs using gdb, I was surprised
> to see many appearances of bidi_cache_search that were observed from
> time to time while I do control-C to stop emacs and monitor
> stacktrace, and the continue for a few seconds, and interrupt it again
> with control-C.  After letting emacs run in this manner for about 5
> minutes, I had tp kill emacs.  I had to edit the file by a deadline and 
> could not continue debugging. :-(
> 
> At the end is a single stacktrace with bidi_cache_search at the top.
> I have seen this occurring multiple times. My hitting control-C to emacs 
> to enter gdb interaction means that the chance of hitting a particular 
> stacktrace pattern is small and seeing the same pattern multiple times 
> means that that pattern happens quite often.

The backtrace shows we were resizing the mini-window, but it doesn't
tell where and why we were looping.

(The bidi_cache_search part is probably a red herring: that function
is indeed called very frequently when Emacs performs display and
layout calculations -- which is not surprising, since that's why the
bidi cache exists: to provide cache hits whenever possible.)

So it is important to have a file and the sequence of commands that
trigger this.  Please try to produce such a file and a recipe to
reproduce the problem.

Alternatively, you can use the technique described in etc/DEBUG for
finding where Emacs loops, see there under "If the symptom of the bug
is that Emacs fails to respond".  I think even if you do discover
where it loops, we'd need an example file to see why, though.

> I have a dozen or so more different stacktraces during gdb monitoring.
> If someone wants to see the log, I can post it.
> What is the preferred URL where I can paste the whole gdb session?

You can post them here, perhaps compressed.  However, if they are all
of the same kind, i.e. start with resize_echo_area_exactly, then I
don't think more backtraces alone will help.

Thanks.

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

From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 66096 <at> debbugs.gnu.org, "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
Subject: Re: bug#66096: High CPU usage, basically runaway emacs with visit to
 bidi_cache_search on and off?
Date: Wed, 20 Sep 2023 16:09:03 +0900

[Message part 1 (text/plain, inline)]

On 2023/09/19 20:04, Eli Zaretskii wrote:
>> Cc: "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
>> Date: Tue, 19 Sep 2023 13:12:33 +0900
>> From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
>>
>> High CPU usage, basically runaway emacs with visit to bidi_cache_search
>> on and off?
>>
>> Hi,
>>
>> Environment:
>> OS GNU/Debian Linux  X86_64
>> Emacs version
>> GNU Emacs 29.1 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.38,
>> cairo version 1.16.0) of 2023-08-01
>> I compiled emacs using gcc.
>>
>> Has anyone seen emacs 29.1 spending CPU way too high, basically went
>> into an infinite loop of some sort, and could not be interrupted by
>> Control-G?  Basically it is in a runaway state.
>> I found that the stacktraces show that bidi_cache_search
>> and friends are visited now and then.  It is not the recursive blowup
>> probably since the stack depth is quite limited during my observation.
>>
>>
>> I have experienced this issue this morning.  Observing the stack
>> backtrace by monitoring the runaway emacs using gdb, I was surprised
>> to see many appearances of bidi_cache_search that were observed from
>> time to time while I do control-C to stop emacs and monitor
>> stacktrace, and the continue for a few seconds, and interrupt it again
>> with control-C.  After letting emacs run in this manner for about 5
>> minutes, I had tp kill emacs.  I had to edit the file by a deadline and
>> could not continue debugging. :-(
>>
>> At the end is a single stacktrace with bidi_cache_search at the top.
>> I have seen this occurring multiple times. My hitting control-C to emacs
>> to enter gdb interaction means that the chance of hitting a particular
>> stacktrace pattern is small and seeing the same pattern multiple times
>> means that that pattern happens quite often.
> The backtrace shows we were resizing the mini-window, but it doesn't
> tell where and why we were looping.
>
> (The bidi_cache_search part is probably a red herring: that function
> is indeed called very frequently when Emacs performs display and
> layout calculations -- which is not surprising, since that's why the
> bidi cache exists: to provide cache hits whenever possible.)
>
> So it is important to have a file and the sequence of commands that
> trigger this.  Please try to produce such a file and a recipe to
> reproduce the problem.
>
> Alternatively, you can use the technique described in etc/DEBUG for
> finding where Emacs loops, see there under "If the symptom of the bug
> is that Emacs fails to respond".  I think even if you do discover
> where it loops, we'd need an example file to see why, though.
>
>> I have a dozen or so more different stacktraces during gdb monitoring.
>> If someone wants to see the log, I can post it.
>> What is the preferred URL where I can paste the whole gdb session?
> You can post them here, perhaps compressed.  However, if they are all
> of the same kind, i.e. start with resize_echo_area_exactly, then I
> don't think more backtraces alone will help.
>
> Thanks.
>
Thank you for your comment.

There seem to be enough variation of the stacktrace patterns.

I am attaching the gdb session file as zipped archive.
As you suggested, it seems Emacs is trying to resize echo area, and is 
looping somehow.
resize_echo_area_exactly () seems to be always there.
It could be that it was trying to dump the S-expression that encodes the 
latest GC information after each GC.

I have the following code snippet to monitor GC issues on my PC for 
quite sometime.
But I have not seen this particular problem before.
The long pause I have seen before was strictly in GC-related routines.

(setq my-gc-statistics (make-vector 30 nil))

;;; The element is
;;; (append (memory-use-counts) (list gc-elapsed gcs-done))
;;; Each time the following function is called, the
;;; elements in the array is shifted toward the end.
;;; Use (message "%S" my-gc-statistics) to force the
;;; recording of my-gc-statistics value in *Messages* buffer for later 
analysis.


(defun update-my-gc-statistics ()
  (let ((i 28))
    (progn
     ;;; very unlike Lisp
     (while (<= 0 i)
       (progn (aset my-gc-statistics (+ 1 i) (aref my-gc-statistics i))
             (setq i (- i 1) )))
     (aset my-gc-statistics 0
           (append (memory-use-counts) (list gc-elapsed gcs-done)))
     ;;; print the latest one last so that I can see the glimpse in the 
narrow
     ;;; output window.
     (message "%S\n%S" (current-time-string) (pp (reverse 
my-gc-statistics))))))

(setq post-gc-hook 'update-my-gc-statistics)

For example, in one place, I see
#0  0x0000556f1905be9e in string_char_and_length
    (length=<synthetic pointer>, p=0x556f20d8a3d8 " 70337 417360 
2.323839139 50)\n (99058573 3875 59193441 34949 11084445 70337 417401 
2.391973008 51)]\n\"") at 
/home/ishikawa/repos/emacs-29.1/src/character.h:375

And that string is probably   from (append (memory-use-counts) (list 
gc-elapsed gcs-done))

Also I see recursive_edit at the bottom of the stakctrace.
Not sure why. Maybe I was doing some error recovery of Japanese input?


In any case, Emacs should not enter a state that cannot be interrupted 
by CONTROL-G for a long time IMHO.
(Or was it that the processing of control-G somehow resulted in the 
effort to widen echo area and emacs failed?)

TIA


Chiaki

[emacs-cant-be-interrupted-with-control-g.zip (application/x-zip-compressed, attachment)]

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

From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 66096 <at> debbugs.gnu.org, "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
Subject: Re: bug#66096: High CPU usage, basically runaway emacs with visit to
 bidi_cache_search on and off?
Date: Wed, 20 Sep 2023 16:16:54 +0900

Oh, I now notice that you are saying if resize_echo_area_exactly is 
always there, the backtraces won't help much.
Tough.
I think the routines called by resize_echo_area_exactly do not change 
the environeent to satisfy what resize_echo_area_exactly wamts, but
I think that will need detailed debugging.

Unfortunately, the problem did not recur yesterday afternoon and I could 
edit the file after "recover-file".

I will try to create more meaningful debug information when something 
similar happens.
It was really the first time in a few years when emacs could not be 
interrupted by control-G.
So, I am not sure if I hit the right condition easily.

TIA

Chiaki

On 2023/09/20 16:09, ISHIKAWA,chiaki wrote:
> On 2023/09/19 20:04, Eli Zaretskii wrote:
>>> Cc: "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
>>> Date: Tue, 19 Sep 2023 13:12:33 +0900
>>> From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
>>>
>>> High CPU usage, basically runaway emacs with visit to bidi_cache_search
>>> on and off?
>>>
>>> Hi,
>>>
>>> Environment:
>>> OS GNU/Debian Linux  X86_64
>>> Emacs version
>>> GNU Emacs 29.1 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.38,
>>> cairo version 1.16.0) of 2023-08-01
>>> I compiled emacs using gcc.
>>>
>>> Has anyone seen emacs 29.1 spending CPU way too high, basically went
>>> into an infinite loop of some sort, and could not be interrupted by
>>> Control-G?  Basically it is in a runaway state.
>>> I found that the stacktraces show that bidi_cache_search
>>> and friends are visited now and then.  It is not the recursive blowup
>>> probably since the stack depth is quite limited during my observation.
>>>
>>>
>>> I have experienced this issue this morning.  Observing the stack
>>> backtrace by monitoring the runaway emacs using gdb, I was surprised
>>> to see many appearances of bidi_cache_search that were observed from
>>> time to time while I do control-C to stop emacs and monitor
>>> stacktrace, and the continue for a few seconds, and interrupt it again
>>> with control-C.  After letting emacs run in this manner for about 5
>>> minutes, I had tp kill emacs.  I had to edit the file by a deadline and
>>> could not continue debugging. :-(
>>>
>>> At the end is a single stacktrace with bidi_cache_search at the top.
>>> I have seen this occurring multiple times. My hitting control-C to 
>>> emacs
>>> to enter gdb interaction means that the chance of hitting a particular
>>> stacktrace pattern is small and seeing the same pattern multiple times
>>> means that that pattern happens quite often.
>> The backtrace shows we were resizing the mini-window, but it doesn't
>> tell where and why we were looping.
>>
>> (The bidi_cache_search part is probably a red herring: that function
>> is indeed called very frequently when Emacs performs display and
>> layout calculations -- which is not surprising, since that's why the
>> bidi cache exists: to provide cache hits whenever possible.)
>>
>> So it is important to have a file and the sequence of commands that
>> trigger this.  Please try to produce such a file and a recipe to
>> reproduce the problem.
>>
>> Alternatively, you can use the technique described in etc/DEBUG for
>> finding where Emacs loops, see there under "If the symptom of the bug
>> is that Emacs fails to respond".  I think even if you do discover
>> where it loops, we'd need an example file to see why, though.
>>
>>> I have a dozen or so more different stacktraces during gdb monitoring.
>>> If someone wants to see the log, I can post it.
>>> What is the preferred URL where I can paste the whole gdb session?
>> You can post them here, perhaps compressed.  However, if they are all
>> of the same kind, i.e. start with resize_echo_area_exactly, then I
>> don't think more backtraces alone will help.
>>
>> Thanks.
>>
> Thank you for your comment.
>
> There seem to be enough variation of the stacktrace patterns.
>
> I am attaching the gdb session file as zipped archive.
> As you suggested, it seems Emacs is trying to resize echo area, and is 
> looping somehow.
> resize_echo_area_exactly () seems to be always there.
> It could be that it was trying to dump the S-expression that encodes 
> the latest GC information after each GC.
>
> I have the following code snippet to monitor GC issues on my PC for 
> quite sometime.
> But I have not seen this particular problem before.
> The long pause I have seen before was strictly in GC-related routines.
>
> (setq my-gc-statistics (make-vector 30 nil))
>
> ;;; The element is
> ;;; (append (memory-use-counts) (list gc-elapsed gcs-done))
> ;;; Each time the following function is called, the
> ;;; elements in the array is shifted toward the end.
> ;;; Use (message "%S" my-gc-statistics) to force the
> ;;; recording of my-gc-statistics value in *Messages* buffer for later 
> analysis.
>
>
> (defun update-my-gc-statistics ()
>   (let ((i 28))
>     (progn
>      ;;; very unlike Lisp
>      (while (<= 0 i)
>        (progn (aset my-gc-statistics (+ 1 i) (aref my-gc-statistics i))
>              (setq i (- i 1) )))
>      (aset my-gc-statistics 0
>            (append (memory-use-counts) (list gc-elapsed gcs-done)))
>      ;;; print the latest one last so that I can see the glimpse in 
> the narrow
>      ;;; output window.
>      (message "%S\n%S" (current-time-string) (pp (reverse 
> my-gc-statistics))))))
>
> (setq post-gc-hook 'update-my-gc-statistics)
>
> For example, in one place, I see
> #0  0x0000556f1905be9e in string_char_and_length
>     (length=<synthetic pointer>, p=0x556f20d8a3d8 " 70337 417360 
> 2.323839139 50)\n (99058573 3875 59193441 34949 11084445 70337 417401 
> 2.391973008 51)]\n\"") at 
> /home/ishikawa/repos/emacs-29.1/src/character.h:375
>
> And that string is probably   from (append (memory-use-counts) (list 
> gc-elapsed gcs-done))
>
> Also I see recursive_edit at the bottom of the stakctrace.
> Not sure why. Maybe I was doing some error recovery of Japanese input?
>
>
> In any case, Emacs should not enter a state that cannot be interrupted 
> by CONTROL-G for a long time IMHO.
> (Or was it that the processing of control-G somehow resulted in the 
> effort to widen echo area and emacs failed?)
>
> TIA
>
>
> Chiaki

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

From: Eli Zaretskii <eliz <at> gnu.org>
To: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
Cc: 66096 <at> debbugs.gnu.org
Subject: Re: bug#66096: High CPU usage, basically runaway emacs with visit to
 bidi_cache_search on and off?
Date: Wed, 20 Sep 2023 16:24:35 +0300

> Date: Wed, 20 Sep 2023 16:09:03 +0900
> Cc: 66096 <at> debbugs.gnu.org, "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
> From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
> 
> I have the following code snippet to monitor GC issues on my PC for 
> quite sometime.
> But I have not seen this particular problem before.
> The long pause I have seen before was strictly in GC-related routines.
> 
> (setq my-gc-statistics (make-vector 30 nil))
> 
> ;;; The element is
> ;;; (append (memory-use-counts) (list gc-elapsed gcs-done))
> ;;; Each time the following function is called, the
> ;;; elements in the array is shifted toward the end.
> ;;; Use (message "%S" my-gc-statistics) to force the
> ;;; recording of my-gc-statistics value in *Messages* buffer for later 
> analysis.
> 
> 
> (defun update-my-gc-statistics ()
>    (let ((i 28))
>      (progn
>       ;;; very unlike Lisp
>       (while (<= 0 i)
>         (progn (aset my-gc-statistics (+ 1 i) (aref my-gc-statistics i))
>               (setq i (- i 1) )))
>       (aset my-gc-statistics 0
>             (append (memory-use-counts) (list gc-elapsed gcs-done)))
>       ;;; print the latest one last so that I can see the glimpse in the 
> narrow
>       ;;; output window.
>       (message "%S\n%S" (current-time-string) (pp (reverse 
> my-gc-statistics))))))
> 
> (setq post-gc-hook 'update-my-gc-statistics)
> 
> For example, in one place, I see
> #0  0x0000556f1905be9e in string_char_and_length
>      (length=<synthetic pointer>, p=0x556f20d8a3d8 " 70337 417360 
> 2.323839139 50)\n (99058573 3875 59193441 34949 11084445 70337 417401 
> 2.391973008 51)]\n\"") at 
> /home/ishikawa/repos/emacs-29.1/src/character.h:375
> 
> And that string is probably   from (append (memory-use-counts) (list 
> gc-elapsed gcs-done))

I tried to run with this, and I don't see any such infloop.  I see the
GC results displayed in the echo-area once in a while.

I guess some other customizations cause this, or maybe some special
circumstances with different fonts you use.  Customizations that
affect the echo-area display and resizing are of main interest.  If
you can try to reproduce this in "emacs -Q", with only the
post-gc-hook defined and as little of your other customizations as
possible, it could help.

> Also I see recursive_edit at the bottom of the stakctrace.
> Not sure why. Maybe I was doing some error recovery of Japanese input?

No, this is normal: Emacs enters one level of recursive-edit when it
starts.

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

From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 66096 <at> debbugs.gnu.org, "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
Subject: Re: bug#66096: High CPU usage, basically runaway emacs with visit to
 bidi_cache_search on and off?
Date: Thu, 21 Sep 2023 10:36:53 +0900

On 2023/09/20 22:24, Eli Zaretskii wrote:
>> Date: Wed, 20 Sep 2023 16:09:03 +0900
>> Cc: 66096 <at> debbugs.gnu.org, "ishikawa, chiaki" <ishikawa <at> yk.rim.or.jp>
>> From: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
>>
>> I have the following code snippet to monitor GC issues on my PC for
>> quite sometime.
>> But I have not seen this particular problem before.
>> The long pause I have seen before was strictly in GC-related routines.
>>
>> (setq my-gc-statistics (make-vector 30 nil))
>>
>> ;;; The element is
>> ;;; (append (memory-use-counts) (list gc-elapsed gcs-done))
>> ;;; Each time the following function is called, the
>> ;;; elements in the array is shifted toward the end.
>> ;;; Use (message "%S" my-gc-statistics) to force the
>> ;;; recording of my-gc-statistics value in *Messages* buffer for later
>> analysis.
>>
>>
>> (defun update-my-gc-statistics ()
>>     (let ((i 28))
>>       (progn
>>        ;;; very unlike Lisp
>>        (while (<= 0 i)
>>          (progn (aset my-gc-statistics (+ 1 i) (aref my-gc-statistics i))
>>                (setq i (- i 1) )))
>>        (aset my-gc-statistics 0
>>              (append (memory-use-counts) (list gc-elapsed gcs-done)))
>>        ;;; print the latest one last so that I can see the glimpse in the
>> narrow
>>        ;;; output window.
>>        (message "%S\n%S" (current-time-string) (pp (reverse
>> my-gc-statistics))))))
>>
>> (setq post-gc-hook 'update-my-gc-statistics)
>>
>> For example, in one place, I see
>> #0  0x0000556f1905be9e in string_char_and_length
>>       (length=<synthetic pointer>, p=0x556f20d8a3d8 " 70337 417360
>> 2.323839139 50)\n (99058573 3875 59193441 34949 11084445 70337 417401
>> 2.391973008 51)]\n\"") at
>> /home/ishikawa/repos/emacs-29.1/src/character.h:375
>>
>> And that string is probably   from (append (memory-use-counts) (list
>> gc-elapsed gcs-done))
> I tried to run with this, and I don't see any such infloop.  I see the
> GC results displayed in the echo-area once in a while.
>
> I guess some other customizations cause this, or maybe some special
> circumstances with different fonts you use.  Customizations that
> affect the echo-area display and resizing are of main interest.  If
> you can try to reproduce this in "emacs -Q", with only the
> post-gc-hook defined and as little of your other customizations as
> possible, it could help.
>
>> Also I see recursive_edit at the bottom of the stakctrace.
>> Not sure why. Maybe I was doing some error recovery of Japanese input?
> No, this is normal: Emacs enters one level of recursive-edit when it
> starts.

Thank you for the comment.

Yeah, I noticed strange font-related functions in a stacktrace.
In any case, if I see the issue with a file being edited,
I will report it.
I have re-compiled emacs with the flags suggested in etc/DEBUG for now.


Chiaki

Previous Next

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