GNU bug report logs - #44326
27.1.50; busy loop in lisp_free_align

Previous Next

To reply to this bug, email your comments to 44326 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: Aaron Jensen <aaronjensen <at> gmail.com>
To: bug-gnu-emacs <at> gnu.org
Subject: 27.1.50; busy loop in lisp_free_align
Date: Fri, 30 Oct 2020 06:18:13 -0500

This should probably be merged into a reopened #30322

I'm seeing a busy loop in lisp_free_align often on Emacs 27. It does
eventually recover, but it takes a minute or more.

* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
    frame #0: 0x000000010021c692
emacs`lisp_align_free(block=0x0000000291d2d400) at alloc.c:1245:7
   1242       struct ablock **tem = &free_ablock;
   1243       struct ablock *atop = &abase->blocks[aligned ?
ABLOCKS_SIZE : ABLOCKS_SIZE - 1];
   1244
-> 1245       while (*tem)
   1246         {
   1247           if (*tem >= (struct ablock *) abase && *tem < atop)
   1248             {

I'm running gcmh-mode, and the last time it hung it was a gcmh-mode
idle collection. Not sure if that makes any difference.

Aaron

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

From: Aaron Jensen <aaronjensen <at> gmail.com>
To: bug-gnu-emacs <at> gnu.org
Subject: Re: 27.1.50; busy loop in lisp_free_align
Date: Fri, 30 Oct 2020 09:33:52 -0500

Some more information that is hopefully helpful.

My Emacs memory usage is currently around 2.5GB.

Lisp Stack trace from busy loop:

(unsigned char *) $2 = 0x00000001003f48c6 “timer-event-handler”
(unsigned char *) $3 = 0x00000001003f074c “apply”
(unsigned char *) $4 = 0x00000001191ba690 “gcmh-idle-garbage-collect”
(unsigned char *) $5 = 0x00000001003ee2fe “garbage-collect”

GC Stats during busy loop. These don't seem to increase, it stays busy
in lisp_align_free, though with different blocks over time.

(lldb) p num_used
(object_ct) $8 = 2924
(lldb) p num_free
(object_ct) $9 = 13506

Here is a macOS sample from activity monitor:

Physical footprint:         2.5G
Physical footprint (peak):  3.2G
----

Call graph:
    2102 Thread_6786366   DispatchQueue_1: com.apple.main-thread  (serial)
    + 2102 start  (in libdyld.dylib) + 1  [0x7fff6a33dcc9]
    +   2102 main  (in emacs) + 6980  [0x100161764]  emacs.c:2066
    +     2102 Frecursive_edit  (in emacs) + 313  [0x100164299]  keyboard.c:786
    +       2102 recursive_edit_1  (in emacs) + 192  [0x100163f50]
keyboard.c:714
    +         2102 command_loop  (in emacs) + 202  [0x1001640ca]
keyboard.c:1070
    +           2102 internal_catch  (in emacs) + 74  [0x1002614ba]  eval.c:1117
    +             2102 command_loop_2  (in emacs) + 44  [0x10017ce8c]
keyboard.c:1091
    +               2102 internal_condition_case  (in emacs) + 127
[0x100261b4f]  eval.c:1356
    +                 2102 command_loop_1  (in emacs) + 1449
[0x100165139]  keyboard.c:1350
    +                   2102 read_key_sequence  (in emacs) + 1897
[0x100166719]  keyboard.c:9554
    +                     2102 read_char  (in emacs) + 5298
[0x10016b5e2]  keyboard.c:2738
    +                       2102 sit_for  (in emacs) + 750
[0x100008f8e]  dispnew.c:6056
    +                         2102 wait_reading_process_output  (in
emacs) + 5631  [0x1002edbaf]  process.c:5707
    +                           2102 detect_input_pending_run_timers
(in emacs) + 54  [0x10016d056]  keyboard.c:10368
    +                             2102 get_input_pending  (in emacs) +
64  [0x100170960]  keyboard.c:6807
    +                               2102 readable_events  (in emacs) +
31  [0x10016e44f]  keyboard.c:3397
    +                                 2102 timer_check  (in emacs) +
168  [0x100170aa8]  keyboard.c:4398
    +                                   2102 timer_check_2  (in emacs)
+ 1695  [0x1001711bf]  keyboard.c:4336
    +                                     2102 call1  (in emacs) + 63
[0x100268d2f]  eval.c:2655
    +                                       2102 Ffuncall  (in emacs)
+ 542  [0x10026824e]  eval.c:2797
    +                                         2102 funcall_lambda  (in
emacs) + 508  [0x10026985c]  eval.c:2990
    +                                           2102 exec_byte_code
(in emacs) + 8766  [0x1002d951e]  bytecode.c:633
    +                                             2102 Ffuncall  (in
emacs) + 468  [0x100268204]  eval.c:2795
    +                                               2102 funcall_subr
(in emacs) + 267  [0x10026930b]  eval.c:2848
    +                                                 2102 Fapply  (in
emacs) + 138  [0x1002649ca]  eval.c:2378
    +                                                   2102 Ffuncall
(in emacs) + 542  [0x10026824e]  eval.c:2797
    +                                                     2102
funcall_lambda  (in emacs) + 508  [0x10026985c]  eval.c:2990
    +                                                       2102
exec_byte_code  (in emacs) + 8766  [0x1002d951e]  bytecode.c:633
    +                                                         2102
Ffuncall  (in emacs) + 468  [0x100268204]  eval.c:2795
    +                                                           2102
funcall_subr  (in emacs) + 454  [0x1002693c6]  eval.c:2866
    +                                                             2102
Fgarbage_collect  (in emacs) + 60  [0x10021f7ec]  alloc.c:6056
    +
2102 garbage_collect  (in emacs) + 867  [0x10021e623]  alloc.c:5984
    +
2102 gc_sweep  (in emacs) + 14  [0x10021f58e]  alloc.c:7013
    +
 2090 sweep_conses  (in emacs) + 652  [0x10022424c]  alloc.c:6786
    +
 ! 2034 lisp_align_free  (in emacs) + 274,270,...
[0x10021c692,0x10021c68e,...]  alloc.c:1245
    +
 ! 32 lisp_align_free  (in emacs) + 300,280,...
[0x10021c6ac,0x10021c698,...]  alloc.c:1247
    +
 ! 9 lisp_align_free  (in emacs) + 376  [0x10021c6f8]  alloc.c:1260
    +
 ! : 7 free_small  (in libsystem_malloc.dylib) + 1464
[0x7fff6a4f7d9e]
    +
 ! : | 6 mvm_madvise_free  (in libsystem_malloc.dylib) + 87
[0x7fff6a4fe93e]
    +
 ! : | + 6 madvise  (in libsystem_kernel.dylib) + 10  [0x7fff6a48104a]
    +
 ! : | 1 mvm_madvise_free  (in libsystem_malloc.dylib) + 8
[0x7fff6a4fe8ef]
    +
 ! : 1 free  (in libsystem_malloc.dylib) + 107  [0x7fff6a4f4a1c]
    +
 ! : | 1 szone_size  (in libsystem_malloc.dylib) + 73
[0x7fff6a4f73a1]
    +
 ! : |   1 small_size  (in libsystem_malloc.dylib) + 144
[0x7fff6a4f7636]
    +
 ! : 1 free_small  (in libsystem_malloc.dylib) + 2090
[0x7fff6a4f8010]
    +
 ! :   1 small_free_scan_madvise_free  (in libsystem_malloc.dylib) +
451  [0x7fff6a501e54]
    +
 ! :     1 mvm_madvise_free  (in libsystem_malloc.dylib) + 87
[0x7fff6a4fe93e]
    +
 ! :       1 madvise  (in libsystem_kernel.dylib) + 10
[0x7fff6a48104a]
    +
 ! 7 lisp_align_free  (in emacs) + 348,352  [0x10021c6dc,0x10021c6e0]
alloc.c:1253
    +
 ! 5 lisp_align_free  (in emacs) + 86  [0x10021c5d6]  alloc.c:1228
    +
 ! : 5 mem_find  (in emacs) + 109  [0x10021ceed]  alloc.c:3960
    +
 ! 3 lisp_align_free  (in emacs) + 94  [0x10021c5de]  alloc.c:1228
    +
 !   3 mem_delete  (in emacs) + 399  [0x10022200f]  alloc.c:4220
    +
 !     2 xfree  (in emacs) + 64  [0x100210a70]  alloc.c:768
    +
 !     | 1 free_tiny  (in libsystem_malloc.dylib) + 459
[0x7fff6a4f8d8b]
    +
 !     | + 1 tiny_free_no_lock  (in libsystem_malloc.dylib) + 1111
[0x7fff6a4f92d6]
    +
 !     | +   1 tiny_free_list_add_ptr  (in libsystem_malloc.dylib) +
478  [0x7fff6a4f9ac8]
    +
 !     | 1 free_tiny  (in libsystem_malloc.dylib) + 479
[0x7fff6a4f8d9f]
    +
 !     1 xfree  (in emacs) + 37  [0x100210a55]  alloc.c:765
    +
 !       1 pdumper_object_p  (in emacs) + 59  [0x100210abb]
pdumper.h:148
    +
 3 sweep_conses  (in emacs) + 294,339,...
[0x1002240e6,0x100224113,...]  alloc.c:6761
    +
 2 sweep_conses  (in emacs) + 146  [0x100224052]  alloc.c:6739
    +
 2 sweep_conses  (in emacs) + 389  [0x100224145]  alloc.c:6764
    +
 2 sweep_conses  (in emacs) + 420  [0x100224164]  alloc.c:6766
    +
 ! 2 dead_object  (in emacs) + 18  [0x10021aa32]  lisp.h:1304
    +
 !   2 make_lisp_ptr  (in emacs) + 0,8  [0x100219e90,0x100219e98]
lisp.h:1284
    +
 1 sweep_conses  (in emacs) + 276  [0x1002240d4]  alloc.c:6759
    +
 1 sweep_conses  (in emacs) + 261  [0x1002240c5]  alloc.c:6760
    +
 1 sweep_conses  (in emacs) + 401  [0x100224151]  alloc.c:6765


Aaron

On Fri, Oct 30, 2020 at 6:18 AM Aaron Jensen <aaronjensen <at> gmail.com> wrote:
>
> This should probably be merged into a reopened #30322
>
> I'm seeing a busy loop in lisp_free_align often on Emacs 27. It does
> eventually recover, but it takes a minute or more.
>
> * thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
>     frame #0: 0x000000010021c692
> emacs`lisp_align_free(block=0x0000000291d2d400) at alloc.c:1245:7
>    1242       struct ablock **tem = &free_ablock;
>    1243       struct ablock *atop = &abase->blocks[aligned ?
> ABLOCKS_SIZE : ABLOCKS_SIZE - 1];
>    1244
> -> 1245       while (*tem)
>    1246         {
>    1247           if (*tem >= (struct ablock *) abase && *tem < atop)
>    1248             {
>
> I'm running gcmh-mode, and the last time it hung it was a gcmh-mode
> idle collection. Not sure if that makes any difference.
>
> Aaron

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

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Aaron Jensen <aaronjensen <at> gmail.com>
Cc: 44326 <at> debbugs.gnu.org
Subject: Re: bug#44326: 27.1.50; busy loop in lisp_free_align
Date: Wed, 27 Jan 2021 05:28:08 +0100

Aaron Jensen <aaronjensen <at> gmail.com> writes:

> Some more information that is hopefully helpful.
>
> My Emacs memory usage is currently around 2.5GB.
>
> Lisp Stack trace from busy loop:
>
> (unsigned char *) $2 = 0x00000001003f48c6 “timer-event-handler”
> (unsigned char *) $3 = 0x00000001003f074c “apply”
> (unsigned char *) $4 = 0x00000001191ba690 “gcmh-idle-garbage-collect”
> (unsigned char *) $5 = 0x00000001003ee2fe “garbage-collect”
>
> GC Stats during busy loop. These don't seem to increase, it stays busy
> in lisp_align_free, though with different blocks over time.

Is it always hanging in a `gcmh-idle-garbage-collect'?  Can you
reproduce this problem without using that package?

Also, could you include the output from `M-x report-emacs-bug',
especially the bit that describes your Emacs version and OS version?

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

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

From: Aaron Jensen <aaronjensen <at> gmail.com>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: 44326 <at> debbugs.gnu.org
Subject: Re: bug#44326: 27.1.50; busy loop in lisp_free_align
Date: Tue, 26 Jan 2021 22:35:54 -0600

On Tue, Jan 26, 2021 at 10:28 PM Lars Ingebrigtsen <larsi <at> gnus.org> wrote:
>
> Aaron Jensen <aaronjensen <at> gmail.com> writes:
>
> > Some more information that is hopefully helpful.
> >
> > My Emacs memory usage is currently around 2.5GB.
> >
> > Lisp Stack trace from busy loop:
> >
> > (unsigned char *) $2 = 0x00000001003f48c6 “timer-event-handler”
> > (unsigned char *) $3 = 0x00000001003f074c “apply”
> > (unsigned char *) $4 = 0x00000001191ba690 “gcmh-idle-garbage-collect”
> > (unsigned char *) $5 = 0x00000001003ee2fe “garbage-collect”
> >
> > GC Stats during busy loop. These don't seem to increase, it stays busy
> > in lisp_align_free, though with different blocks over time.
>
> Is it always hanging in a `gcmh-idle-garbage-collect'?

Yes, though since reducing my high cons threshold to 16mb, it hasn't reocurred.

> Can you
> reproduce this problem without using that package?

No, I don't believe so.
>
> Also, could you include the output from `M-x report-emacs-bug',
> especially the bit that describes your Emacs version and OS version?

Sure, though it's a different build by now and I'm using native-comp
now, but wasn't before.

In GNU Emacs 28.0.50 (build 1, x86_64-apple-darwin19.6.0, NS
appkit-1894.60 Version 10.15.7 (Build 19H114))
 of 2021-01-24 built on aaron-sub.local
Repository revision: 0ffb3dfaa483b0c5cf1f7f367efcb5e9c041ab53
Repository branch: feature/native-comp
Windowing system distributor 'Apple', version 10.3.1894
System Description:  Mac OS X 10.15.7

Configured using:
 'configure --disable-dependency-tracking --disable-silent-rules
 --enable-locallisppath=/usr/local/share/emacs/site-lisp
 --infodir=/usr/local/Cellar/emacs-plus <at> 28/28.0.50/share/info/emacs
 --prefix=/usr/local/Cellar/emacs-plus <at> 28/28.0.50 --with-xml2
 --with-gnutls --with-nativecomp --without-dbus --with-imagemagick
 --with-modules --with-rsvg --with-ns --disable-ns-self-contained
 'CFLAGS=-I/usr/local/opt/gcc/include -I/usr/local/opt/libgccjit/include
 -I/usr/local/opt/gmp/include -I/usr/local/opt/jpeg/include'
 'LDFLAGS=-L/usr/local/lib/gcc/10 -I/usr/local/opt/gcc/include
 -I/usr/local/opt/libgccjit/include -I/usr/local/opt/gmp/include
 -I/usr/local/opt/jpeg/include''

Configured features:
ACL GLIB GMP GNUTLS IMAGEMAGICK JPEG JSON LCMS2 LIBXML2 MODULES
NATIVE_COMP NOTIFY KQUEUE NS PDUMPER PNG RSVG THREADS TIFF
TOOLKIT_SCROLL_BARS ZLIB

Important settings:
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8-unix

Aaron

Previous Next

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