29.0.50 master freeze on macOS

29.0.50 master freeze on macOS

[Alexander Adolf]

Hello,

I get a complete lockup of Emacs a couple of times a day on macOS. I
built Emacs from commit e4030f25f98d2ac9c638e573b0ab6e6b0a35f38b
yesterday, but the freeze started occurring a while back with one of the
28 versions. I don't recall exactly when.

When the freeze happens, Emacs is completely frozen, that is,
emacsclients are locked up too, and neither SIGUSR1 nor SIGUSR2 change
anything. The only way forward is killing the process, an restarting it.

I'm running the nextstep build (i.e. Emacs.app), and macOS generates a
crash report when a GUI app hangs. In that report, four threads are
shown:

- com.apple.main-thread: the trace doesn't reveal much as the call trace
  leads into the OS kernel, where symbol names are rare. It seems there
  is some sort of interrupt going on, followed by a memmove().

- gmain: the trace for this thread goes from a thread_start relatively
  straight to end in a select().

- an unnamed thread: the trace for this thread goes from a thread_start
  relatively straight to end in a pselect().

- com.apple.NSEventThread: the trace for this thread goes from a
  thread_start relatively straight into a CFRunLoopServiceMachPort(),
  and ends a ipc_mqueue_receive_continue().


Any hints how I could go about further narrowing in on the problem, i.e.
building with debug symbols, etc.?

Any hints appreciated.

  --alexander

Re: 29.0.50 master freeze on macOS

[Eli Zaretskii]

> From: Alexander Adolf <alexander.adolf@condition-alpha.com>
> Date: Thu, 14 Jul 2022 16:05:37 +0200
> 
> I get a complete lockup of Emacs a couple of times a day on macOS. I
> built Emacs from commit e4030f25f98d2ac9c638e573b0ab6e6b0a35f38b
> yesterday, but the freeze started occurring a while back with one of the
> 28 versions. I don't recall exactly when.
> 
> When the freeze happens, Emacs is completely frozen, that is,
> emacsclients are locked up too, and neither SIGUSR1 nor SIGUSR2 change
> anything. The only way forward is killing the process, an restarting it.

Did you try to attach a debugger?

Re: 29.0.50 master freeze on macOS

[Alexander Adolf]

Eli Zaretskii <eliz@gnu.org> writes:

> [...]
> Did you try to attach a debugger?

<face-palm/> Ah, stupid me! Will do next time and post findings here.

Re: 29.0.50 master freeze on macOS

[Alexander Adolf]

[-- Attachment #1: Type: text/plain, Size: 860 bytes --]

Alexander Adolf <alexander.adolf@condition-alpha.com> writes:

> Eli Zaretskii <eliz@gnu.org> writes:
>
>> [...]
>> Did you try to attach a debugger?
>
> <face-palm/> Ah, stupid me! Will do next time and post findings here.

It just happened again. This time I attached a debugger, and gave it a
couple of halt/continue cycles to see what's going on.

It turns out that thread #1 appears to get stuck in try_window(),
coincidentally (or maybe not) in exactly the loop updated by commit
ed4ba79ea8f2be2d01f6447910e2c8319908d0d6 earlier today by yourself. See
attached screenshot.

As you can see in the screenshot, some symbol information appears to be
available.

Do you want me to try to dig further into details, or should I pull &
rebuild to include your commit, and see it that fixes it?


Many thanks and looking forward to your thoughts,

  --alexander


[-- Attachment #2: Screenshot 2022-07-15 at 18.10.07.png --]
[-- Type: image/png, Size: 1433769 bytes --]

Re: 29.0.50 master freeze on macOS

[Eli Zaretskii]

> From: Alexander Adolf <alexander.adolf@condition-alpha.com>
> Cc: emacs-devel@gnu.org
> Date: Fri, 15 Jul 2022 18:31:43 +0200
> 
> It just happened again. This time I attached a debugger, and gave it a
> couple of halt/continue cycles to see what's going on.
> 
> It turns out that thread #1 appears to get stuck in try_window(),
> coincidentally (or maybe not) in exactly the loop updated by commit
> ed4ba79ea8f2be2d01f6447910e2c8319908d0d6 earlier today by yourself. See
> attached screenshot.

No, it's not the same scenario, because what happened to you was
unrelated to showing a tooltip.

> Do you want me to try to dig further into details, or should I pull &
> rebuild to include your commit, and see it that fixes it?

Please follow the instructions in etc/DEBUG under "If the symptom of
the bug is that Emacs fails to respond", to establish where Emacs
infloops.

Re: 29.0.50 master freeze on macOS

[Alexander Adolf]

Hello Eli,

Eli Zaretskii <eliz@gnu.org> writes:

> [...]
> Please follow the instructions in etc/DEBUG under "If the symptom of
> the bug is that Emacs fails to respond", to establish where Emacs
> infloops.

Some more findings based on that guidance (for which thanks, btw):

It loops in face_inherited_attr(). Here is the call stack:

#0	0x00000001018f32db in face_inherited_attr at /Users/alexanderadolf/Projects/emacs/master/src/xfaces.c:2335
#1	0x00000001018f2297 in merge_named_face at /Users/alexanderadolf/Projects/emacs/master/src/xfaces.c:2379
#2	0x00000001018ee57d in merge_face_ref at /Users/alexanderadolf/Projects/emacs/master/src/xfaces.c:2866
#3	0x00000001018f169a in face_at_buffer_position at /Users/alexanderadolf/Projects/emacs/master/src/xfaces.c:6644
#4	0x0000000101866526 in face_at_pos at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:4425
#5	0x000000010186c47a in extend_face_to_end_of_line at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:22840
#6	0x0000000101849164 in display_line at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:24780
#7	0x0000000101846fb9 in try_window at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:20203
#8	0x0000000101873ef7 in redisplay_window at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:19610
#9	0x00000001018708e6 in redisplay_window_0 at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:17188
#10	0x000000010199042b in internal_condition_case_1 at /Users/alexanderadolf/Projects/emacs/master/src/eval.c:1509
#11	0x000000010186ff75 in redisplay_windows at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:17158
#12	0x000000010186ffaa in redisplay_windows at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:17152
#13	0x00000001018407fc in redisplay_internal at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:16608
#14	0x0000000101846115 in redisplay at /Users/alexanderadolf/Projects/emacs/master/src/xdisp.c:15812
#15	0x00000001018fc0e5 in read_char at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:2587
#16	0x00000001018f945b in read_key_sequence at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:9984
#17	0x00000001018f74bc in command_loop_1 at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:1382
#18	0x00000001019903a7 in internal_condition_case at /Users/alexanderadolf/Projects/emacs/master/src/eval.c:1485
#19	0x00000001018f70ae in command_loop_2 at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:1132
#20	0x000000010198fc61 in internal_catch at /Users/alexanderadolf/Projects/emacs/master/src/eval.c:1208
#21	0x0000000101a83d78 in recursive_edit_1.cold.1 at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:1110
#22	0x00000001018f695d in command_loop [inlined] at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:1107
#23	0x00000001018f6958 in recursive_edit_1 at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:719
#24	0x00000001018f6ad3 in Frecursive_edit at /Users/alexanderadolf/Projects/emacs/master/src/keyboard.c:802
#25	0x00000001018f5a81 in main at /Users/alexanderadolf/Projects/emacs/master/src/emacs.c:2517
#26	0x00007fff20875f3d in start ()

In face_inherited_attr(), variable values were:

w	window *	NULL	
f	frame *	NULL	
attrs	Lisp_Object *	NULL	
attr_idx	lface_attribute_index	LFACE_EXTEND_INDEX
named_merge_points	named_merge_point *	0x7ffeee3e9018	0x00007ffeee3e9018
inherited_attrs	Lisp_Object [20]	
attr_val	Lisp_Object	0xf3f0	0x000000000000f3f0

Inside the while() loop, the if (CONSP (parent_face)) fails, and it
executes the else branch. From there, it calls 

get_lface_attributes (struct window *w,
                      struct frame *f, Lisp_Object face_name,
		      Lisp_Object attrs[LFACE_VECTOR_SIZE], bool signal_p,
		      struct named_merge_point *named_merge_points)

which executes the “default case, no remapping” path.

Interestingly, the window and frame pointers are NULL in the context of
face_inherited_attr() only. I.e. in both the function that calls it
(merge_named_face()), and in the function called by it
(get_lface_attributes()), the pointers have the same, non-NULL value.

Hope this helps? If you want me to look into more specific things next
time it happens, please don't hesitate to drop me a note.


Many thanks and looking forward to your thoughts,

  --alexander

Re: 29.0.50 master freeze on macOS

[Alexander Adolf]

Alexander Adolf <alexander.adolf@condition-alpha.com> writes:

> [...]
> Inside the while() loop, the if (CONSP (parent_face)) fails, and it
> executes the else branch. From there, it calls 
> [...]

One more thing: get_lface_attributes() always returns ok, i.e.
it never gets to the break instruction.

Re: 29.0.50 master freeze on macOS

[Eli Zaretskii]

> From: Alexander Adolf <alexander.adolf@condition-alpha.com>
> Cc: emacs-devel@gnu.org
> Date: Tue, 19 Jul 2022 17:27:14 +0200
> 
> It loops in face_inherited_attr(). Here is the call stack:
> [...]
> In face_inherited_attr(), variable values were:
> 
> w	window *	NULL	
> f	frame *	NULL	
> attrs	Lisp_Object *	NULL	
> attr_idx	lface_attribute_index	LFACE_EXTEND_INDEX
> named_merge_points	named_merge_point *	0x7ffeee3e9018	0x00007ffeee3e9018
> inherited_attrs	Lisp_Object [20]	
> attr_val	Lisp_Object	0xf3f0	0x000000000000f3f0
> 
> Inside the while() loop, the if (CONSP (parent_face)) fails, and it
> executes the else branch. From there, it calls 
> 
> get_lface_attributes (struct window *w,
>                       struct frame *f, Lisp_Object face_name,
> 		      Lisp_Object attrs[LFACE_VECTOR_SIZE], bool signal_p,
> 		      struct named_merge_point *named_merge_points)
> 
> which executes the “default case, no remapping” path.
> 
> Interestingly, the window and frame pointers are NULL in the context of
> face_inherited_attr() only. I.e. in both the function that calls it
> (merge_named_face()), and in the function called by it
> (get_lface_attributes()), the pointers have the same, non-NULL value.
> 
> Hope this helps? If you want me to look into more specific things next
> time it happens, please don't hesitate to drop me a note.

This helps, thanks.  But since the loop is in that place, it is very
important to see the definition of the face which causes this.

Specifically:

  . what is the value of face_name argument to merge_named_face that
    calls face_inherited_attr? it should be a symbol.
  . what are the attributes in the attrs[] argument to
    face_inherited_attr? this is a vector of Lisp objects, and the
    meaning of each component can be seen in the lface_attribute_index
    enumeration

Thanks.

Re: 29.0.50 master freeze on macOS

[Alexander Adolf]

Hello Eli,

Eli Zaretskii <eliz@gnu.org> writes:

>> [...]
> This helps, thanks.  But since the loop is in that place, it is very
> important to see the definition of the face which causes this.
>
> Specifically:
>
>   . what is the value of face_name argument to merge_named_face that
>     calls face_inherited_attr? it should be a symbol.
>   . what are the attributes in the attrs[] argument to
>     face_inherited_attr? this is a vector of Lisp objects, and the
>     meaning of each component can be seen in the lface_attribute_index
>     enumeration

Shortly after I received your message, I updated my (M)ELPA packages to
their latest versions, and was rewarded with a "symbol's function
definition is void" error for a function in compat. I decided to use
the big stick, and did a

(byte-recompile-directory package-user-dir nil 'force)

And guess what, no more freeze happening since. I'll continue keeping an
eye on it though.


Cheers,

  --alexander

Re: 29.0.50 master freeze on macOS

[Eli Zaretskii]

> From: Alexander Adolf <alexander.adolf@condition-alpha.com>
> Cc: emacs-devel@gnu.org
> Date: Mon, 25 Jul 2022 15:26:57 +0200
> 
> Shortly after I received your message, I updated my (M)ELPA packages to
> their latest versions, and was rewarded with a "symbol's function
> definition is void" error for a function in compat. I decided to use
> the big stick, and did a
> 
> (byte-recompile-directory package-user-dir nil 'force)
> 
> And guess what, no more freeze happening since. I'll continue keeping an
> eye on it though.

Thanks.