Package: emacs;
Reported by: "ISHIKAWA,chiaki" <ishikawa <at> yk.rim.or.jp>
Date: Tue, 19 Sep 2023 04:13:01 UTC
Severity: normal
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
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.