UI Unresponsive Again on macOS

UI Unresponsive Again on macOS

[Bob Halley]

I build from the master branch about once a week.  I had no problem with last week's build made early in the morning California time on Sunday the 6th, but the build I just made this morning becomes completely unresponsive after a short time.  I don't have an exact recipe to reproduce -- I was just typing, and then stopped for a bit, and then it became completely unresponsive.  This happens every time I try to use it.

I suspect one or both of these changes:

a65236214d9202fb69a6ba5169d4ac1a4bcb0b0d
3bd2e9e975ed29daaf03ca7559e4664aade0674f

as they are new since my last working build and seem to be relevant.

I obtained backtraces of all the threads.  I did two snapshots of thread 1 as it seemed to be spinning a bit.

(lldb) thread list
Process 85104 stopped
* thread #1: tid = 0x408ea9, 0x00007fff8d86790a libsystem_platform.dylib`_platform_memcmp + 298, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  thread #2: tid = 0x408ec9, 0x00007fff8d789f4a libsystem_kernel.dylib`__select + 10
  thread #3: tid = 0x408ed6, 0x00007fff8d78238a libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.NSEventThread'
  thread #4: tid = 0x409120, 0x00007fff8d78a4e2 libsystem_kernel.dylib`__workq_kernreturn + 10

(lldb) bt
* thread #1: tid = 0x408ea9, 0x00007fff8d86790a libsystem_platform.dylib`_platform_memcmp + 298, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007fff8d86790a libsystem_platform.dylib`_platform_memcmp + 298
    frame #1: 0x00007fff780a6b0b CoreFoundation`__CFStringEqual + 235
    frame #2: 0x00007fff78098f70 CoreFoundation`CFEqual + 432
    frame #3: 0x00007fff7810382a CoreFoundation`CFRunLoopRunSpecific + 90
    frame #4: 0x00007fff7768fa5c HIToolbox`RunCurrentEventLoopInMode + 240
    frame #5: 0x00007fff7768f799 HIToolbox`ReceiveNextEventCommon + 184
    frame #6: 0x00007fff7768f6c6 HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 71
    frame #7: 0x00007fff75c355b4 AppKit`_DPSNextEvent + 1120
    frame #8: 0x00007fff763afd6b AppKit`-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 2789
    frame #9: 0x00000001001b3fcb Emacs`ns_select(nfds=6, readfds=<unavailable>, writefds=<unavailable>, exceptfds=0x0000000000000000, timeout=0x00007fff92e0be40, sigmask=0x0000000000000000) + 811 at nsterm.m:4186 [opt]
    frame #10: 0x00000001001a0b88 Emacs`really_call_select(arg=0x00007fff5fbfebb0) + 88 at thread.c:566 [opt]
    frame #11: 0x000000010011e64b Emacs`flush_stack_call_func(func=<unavailable>, arg=<unavailable>) + 43 at alloc.c:5111 [opt]
    frame #12: 0x00000001001a0b27 Emacs`thread_select(func=<unavailable>, max_fds=<unavailable>, rfds=<unavailable>, wfds=<unavailable>, efds=<unavailable>, timeout=<unavailable>, sigmask=0x0000000000000000) + 55 at thread.c:589 [opt]
    frame #13: 0x0000000100184620 Emacs`wait_reading_process_output(time_limit=<unavailable>, nsecs=<unavailable>, read_kbd=<unavailable>, do_display=<unavailable>, wait_for_cell=0, wait_proc=<unavailable>, just_wait_proc=<unavailable>) + 4096 at process.c:5342 [opt]
    frame #14: 0x0000000100008185 Emacs`sit_for(timeout=<unavailable>, reading=<unavailable>, display_option=1) + 261 at dispnew.c:5763 [opt]
    frame #15: 0x00000001000c4237 Emacs`read_char(commandflag=1, map=4363902419, prev_event=0, used_mouse_menu=0x00007fff5fbff7ef, end_time=0x0000000000000000) + 5511 at keyboard.c:2722 [opt]
    frame #16: 0x00000001000c0d8e Emacs`read_key_sequence(keybuf=<unavailable>, bufsize=30, prompt=<unavailable>, dont_downcase_last=<unavailable>, can_return_switch_frame=<unavailable>, fix_current_buffer=<unavailable>, prevent_redisplay=<unavailable>) + 1854 at keyboard.c:9109 [opt]
    frame #17: 0x00000001000bf4ed Emacs`command_loop_1 + 1229 at keyboard.c:1370 [opt]
    frame #18: 0x000000010013cc07 Emacs`internal_condition_case(bfun=(Emacs`command_loop_1 at keyboard.c:1261), handlers=<unavailable>, hfun=(Emacs`cmd_error at keyboard.c:940)) + 87 at eval.c:1324 [opt]
    frame #19: 0x00000001000ce5e0 Emacs`command_loop_2(ignore=<unavailable>) + 48 at keyboard.c:1112 [opt]
    frame #20: 0x000000010013c4ce Emacs`internal_catch(tag=<unavailable>, func=(Emacs`command_loop_2 at keyboard.c:1108), arg=0) + 78 at eval.c:1091 [opt]
    frame #21: 0x00000001000be71e Emacs`command_loop + 158 at keyboard.c:1091 [opt]
    frame #22: 0x00000001000be62f Emacs`recursive_edit_1 + 111 at keyboard.c:697 [opt]
    frame #23: 0x00000001000be863 Emacs`Frecursive_edit + 227 at keyboard.c:768 [opt]
    frame #24: 0x00000001000bd43d Emacs`main(argc=0, argv=<unavailable>) + 6077 at emacs.c:1683 [opt]
    frame #25: 0x00007fff8d65b255 libdyld.dylib`start + 1
(lldb) c
Process 85104 resuming
Process 85104 stopped
(lldb) bt
* thread #1: tid = 0x408ea9, 0x00007fff780d14a2 CoreFoundation`__CFRunLoopFindMode + 82, stop reason = signal SIGSTOP
  * frame #0: 0x00007fff780d14a2 CoreFoundation`__CFRunLoopFindMode + 82
    frame #1: 0x00007fff781038aa CoreFoundation`CFRunLoopRunSpecific + 218
    frame #2: 0x00007fff7768fa5c HIToolbox`RunCurrentEventLoopInMode + 240
    frame #3: 0x00007fff7768f799 HIToolbox`ReceiveNextEventCommon + 184
    frame #4: 0x00007fff7768f6c6 HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 71
    frame #5: 0x00007fff75c355b4 AppKit`_DPSNextEvent + 1120
    frame #6: 0x00007fff763afd6b AppKit`-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 2789
    frame #7: 0x00000001001b3fcb Emacs`ns_select(nfds=6, readfds=<unavailable>, writefds=<unavailable>, exceptfds=0x0000000000000000, timeout=0x00007fff92e0be40, sigmask=0x0000000000000000) + 811 at nsterm.m:4186 [opt]
    frame #8: 0x00000001001a0b88 Emacs`really_call_select(arg=0x00007fff5fbfebb0) + 88 at thread.c:566 [opt]
    frame #9: 0x000000010011e64b Emacs`flush_stack_call_func(func=<unavailable>, arg=<unavailable>) + 43 at alloc.c:5111 [opt]
    frame #10: 0x00000001001a0b27 Emacs`thread_select(func=<unavailable>, max_fds=<unavailable>, rfds=<unavailable>, wfds=<unavailable>, efds=<unavailable>, timeout=<unavailable>, sigmask=0x0000000000000000) + 55 at thread.c:589 [opt]
    frame #11: 0x0000000100184620 Emacs`wait_reading_process_output(time_limit=<unavailable>, nsecs=<unavailable>, read_kbd=<unavailable>, do_display=<unavailable>, wait_for_cell=0, wait_proc=<unavailable>, just_wait_proc=<unavailable>) + 4096 at process.c:5342 [opt]
    frame #12: 0x0000000100008185 Emacs`sit_for(timeout=<unavailable>, reading=<unavailable>, display_option=1) + 261 at dispnew.c:5763 [opt]
    frame #13: 0x00000001000c4237 Emacs`read_char(commandflag=1, map=4363902419, prev_event=0, used_mouse_menu=0x00007fff5fbff7ef, end_time=0x0000000000000000) + 5511 at keyboard.c:2722 [opt]
    frame #14: 0x00000001000c0d8e Emacs`read_key_sequence(keybuf=<unavailable>, bufsize=30, prompt=<unavailable>, dont_downcase_last=<unavailable>, can_return_switch_frame=<unavailable>, fix_current_buffer=<unavailable>, prevent_redisplay=<unavailable>) + 1854 at keyboard.c:9109 [opt]
    frame #15: 0x00000001000bf4ed Emacs`command_loop_1 + 1229 at keyboard.c:1370 [opt]
    frame #16: 0x000000010013cc07 Emacs`internal_condition_case(bfun=(Emacs`command_loop_1 at keyboard.c:1261), handlers=<unavailable>, hfun=(Emacs`cmd_error at keyboard.c:940)) + 87 at eval.c:1324 [opt]
    frame #17: 0x00000001000ce5e0 Emacs`command_loop_2(ignore=<unavailable>) + 48 at keyboard.c:1112 [opt]
    frame #18: 0x000000010013c4ce Emacs`internal_catch(tag=<unavailable>, func=(Emacs`command_loop_2 at keyboard.c:1108), arg=0) + 78 at eval.c:1091 [opt]
    frame #19: 0x00000001000be71e Emacs`command_loop + 158 at keyboard.c:1091 [opt]
    frame #20: 0x00000001000be62f Emacs`recursive_edit_1 + 111 at keyboard.c:697 [opt]
    frame #21: 0x00000001000be863 Emacs`Frecursive_edit + 227 at keyboard.c:768 [opt]
    frame #22: 0x00000001000bd43d Emacs`main(argc=0, argv=<unavailable>) + 6077 at emacs.c:1683 [opt]
    frame #23: 0x00007fff8d65b255 libdyld.dylib`start + 1

(lldb) thread select 2
(lldb) bt
* thread #2: tid = 0x408ec9, 0x00007fff8d789f4a libsystem_kernel.dylib`__select + 10
  * frame #0: 0x00007fff8d789f4a libsystem_kernel.dylib`__select + 10
    frame #1: 0x00000001001b68b7 Emacs`-[EmacsApp fd_handler:](self=<unavailable>, _cmd=<unavailable>, unused=<unavailable>) + 295 at nsterm.m:5493 [opt]
    frame #2: 0x00007fff79b28c6d Foundation`__NSThread__start__ + 1243
    frame #3: 0x00007fff8d872aab libsystem_pthread.dylib`_pthread_body + 180
    frame #4: 0x00007fff8d8729f7 libsystem_pthread.dylib`_pthread_start + 286
    frame #5: 0x00007fff8d8721fd libsystem_pthread.dylib`thread_start + 13

(lldb) thread select 3
(lldb) bt
* thread #3: tid = 0x408ed6, 0x00007fff8d78238a libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.NSEventThread'
  * frame #0: 0x00007fff8d78238a libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x00007fff8d7817d7 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x00007fff78104c94 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x00007fff78104121 CoreFoundation`__CFRunLoopRun + 1361
    frame #4: 0x00007fff78103974 CoreFoundation`CFRunLoopRunSpecific + 420
    frame #5: 0x00007fff75d82a62 AppKit`_NSEventThread + 205
    frame #6: 0x00007fff8d872aab libsystem_pthread.dylib`_pthread_body + 180
    frame #7: 0x00007fff8d8729f7 libsystem_pthread.dylib`_pthread_start + 286
    frame #8: 0x00007fff8d8721fd libsystem_pthread.dylib`thread_start + 13

(lldb) thread select 4
(lldb) bt
* thread #4: tid = 0x409120, 0x00007fff8d78a4e2 libsystem_kernel.dylib`__workq_kernreturn + 10
  * frame #0: 0x00007fff8d78a4e2 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x00007fff8d872791 libsystem_pthread.dylib`_pthread_wqthread + 1426
    frame #2: 0x00007fff8d8721ed libsystem_pthread.dylib`start_wqthread + 13

Re: UI Unresponsive Again on macOS

[Alan Third]

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

On Fri, Mar 10, 2017 at 06:40:00AM -0800, Bob Halley wrote:
> I build from the master branch about once a week. I had no problem
> with last week's build made early in the morning California time on
> Sunday the 6th, but the build I just made this morning becomes
> completely unresponsive after a short time. I don't have an exact
> recipe to reproduce -- I was just typing, and then stopped for a
> bit, and then it became completely unresponsive. This happens every
> time I try to use it.
> 
> I suspect one or both of these changes:
> 
> a65236214d9202fb69a6ba5169d4ac1a4bcb0b0d
> 3bd2e9e975ed29daaf03ca7559e4664aade0674f
> 
> as they are new since my last working build and seem to be relevant.
> 
> I obtained backtraces of all the threads. I did two snapshots of
> thread 1 as it seemed to be spinning a bit.

Thanks for that, Bob. I noticed these hangs too, but I haven’t
actually managed to catch one in the debugger yet.

Can you please try the attached patch? I’m not at all sure it’ll fix
it, but it’ll be good to rule it out.
-- 
Alan Third

[-- Attachment #2: Disable SIGIO --]
[-- Type: text/plain, Size: 1375 bytes --]

From 6b4787023b247b68ae0598d03dce50a6fce44ab1 Mon Sep 17 00:00:00 2001
From: Alan Third <alan@idiocy.org>
Date: Fri, 10 Mar 2017 14:21:14 +0000
Subject: [PATCH] Disable SIGIO processing on NS port

* src/conf_post.h: undef USABLE_SIGIO and INTERRUPT_INPUT.
* src/nsterm.m (hold_event, ns_select): Remove unneeded calls to raise
SIGIO.
---
 src/conf_post.h | 6 ++++++
 src/nsterm.m    | 3 ---
 2 files changed, 6 insertions(+), 3 deletions(-)

diff --git a/src/conf_post.h b/src/conf_post.h
index e146b9bbe8..3b6b9aff8d 100644
--- a/src/conf_post.h
+++ b/src/conf_post.h
@@ -355,3 +355,9 @@ extern int emacs_setenv_TZ (char const *);
 #else
 # define UNINIT /* empty */
 #endif
+
+/* The NS port doesn't use SIGIO for input. */
+#ifdef HAVE_NS
+# undef USABLE_SIGIO
+# undef INTERRUPT_INPUT
+#endif
diff --git a/src/nsterm.m b/src/nsterm.m
index f985786e19..d61d357811 100644
--- a/src/nsterm.m
+++ b/src/nsterm.m
@@ -454,8 +454,6 @@ - (NSColor *)colorUsingDefaultColorSpace
     }
 
   hold_event_q.q[hold_event_q.nr++] = *event;
-  /* Make sure ns_read_socket is called, i.e. we have input.  */
-  raise (SIGIO);
   send_appdefined = YES;
 }
 
@@ -4120,7 +4118,6 @@ in certain situations (rapid incoming events).
   if (hold_event_q.nr > 0)
     {
       /* We already have events pending. */
-      raise (SIGIO);
       errno = EINTR;
       return -1;
     }
-- 
2.12.0

Re: UI Unresponsive Again on macOS

[Bob Halley]

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


> On Mar 10, 2017, at 06:51, Alan Third <alan@idiocy.org> wrote:
> 
> Can you please try the attached patch? I’m not at all sure it’ll fix
> it, but it’ll be good to rule it out.

With the patch, I can no longer reproduce the problem doing the same things that triggered it before.

So, looks good!  I'll keep running with the patch.

/Bob


[-- Attachment #2: Type: text/html, Size: 1916 bytes --]

Re: UI Unresponsive Again on macOS

[Herbert J. Skuhra]

Alan Third skrev:
> 
> On Fri, Mar 10, 2017 at 06:40:00AM -0800, Bob Halley wrote:
>> I build from the master branch about once a week. I had no problem
>> with last week's build made early in the morning California time on
>> Sunday the 6th, but the build I just made this morning becomes
>> completely unresponsive after a short time. I don't have an exact
>> recipe to reproduce -- I was just typing, and then stopped for a
>> bit, and then it became completely unresponsive. This happens every
>> time I try to use it.
>> 
>> I suspect one or both of these changes:
>> 
>> a65236214d9202fb69a6ba5169d4ac1a4bcb0b0d
>> 3bd2e9e975ed29daaf03ca7559e4664aade0674f
>> 
>> as they are new since my last working build and seem to be relevant.
>> 
>> I obtained backtraces of all the threads. I did two snapshots of
>> thread 1 as it seemed to be spinning a bit.
> 
> Thanks for that, Bob. I noticed these hangs too, but I haven’t
> actually managed to catch one in the debugger yet.
> 
> Can you please try the attached patch? I’m not at all sure it’ll fix
> it, but it’ll be good to rule it out.

Unfortunately I cannot confirm that this patch fixes the issue on my
system. I still see high cpu usage and hangs when using Gnus (nntp) on
macOS 10.12.4 Beta 5. git bisect showed that
3bd2e9e975ed29daaf03ca7559e4664aade0674f is the culprit.

--
Herbert

Re: UI Unresponsive Again on macOS

[Alan Third]

On Mon, Mar 13, 2017 at 07:23:05AM +0100, Herbert J. Skuhra wrote:
> Alan Third skrev:
> > 
> > Can you please try the attached patch? I’m not at all sure it’ll fix
> > it, but it’ll be good to rule it out.
> 
> Unfortunately I cannot confirm that this patch fixes the issue on my
> system. I still see high cpu usage and hangs when using Gnus (nntp) on
> macOS 10.12.4 Beta 5. git bisect showed that
> 3bd2e9e975ed29daaf03ca7559e4664aade0674f is the culprit.

Is it just Gnus that you’re seeing hangs with?

The one hang I’ve had since I installed this patch was when sending an
email from message mode. I wonder if there’s some specific
incompatibility with Gnus that I could work around.

Thanks for the feedback.
-- 
Alan Third

Re: UI Unresponsive Again on macOS

[Bob Halley]

While the patch certainly changed the odds of the problem happening, my Emacs with the patch locked up this morning while doing normal work, so something is still bad.

/Bob

Re: UI Unresponsive Again on macOS

[Alan Third]

On Mon, Mar 13, 2017 at 07:23:05AM +0100, Herbert J. Skuhra wrote:
> Alan Third skrev:
> > 
> > Can you please try the attached patch? I’m not at all sure it’ll fix
> > it, but it’ll be good to rule it out.
> 
> Unfortunately I cannot confirm that this patch fixes the issue on my
> system. I still see high cpu usage and hangs when using Gnus (nntp) on
> macOS 10.12.4 Beta 5. git bisect showed that
> 3bd2e9e975ed29daaf03ca7559e4664aade0674f is the culprit.

I’ve reverted the changes. Thanks for reporting back about these
problems.
-- 
Alan Third