Subject: bug#21965: 24.5; Emacs freezes when canceling at open file

From: Maneesh Yadav <[email-masked]>
Date: Wed, 25 Nov 2015 10:49:29 -0800

Weird.

I patched glib2 this way (just overriding the macros (and removing
semicolons on macro invocations...seemed to be the best way to deal
with if statements that didn't wrap in curly braces...just realized my
strings don't reflect "UN"LOCK/LOCK....not a big deal since line
numbers are there...fixed for next time):

#define LOCK_CONTEXT(context) g_mutex_lock (&context->mutex)

#define LOCK_CONTEXT(context) {printf("MANEESH GLIB DEBUG: About to
LOCK: %s, %d, %s\n", __FILE__, __LINE__, __FUNCTION__); g_mutex_lock
(&context->mutex);}

#define UNLOCK_CONTEXT(context) g_mutex_unlock (&context->mutex)

#define UNLOCK_CONTEXT(context) {printf("MANEESH GLIB DEBUG: About to
LOCK: %s, %d, %s\n", __FILE__, __LINE__, __FUNCTION__); g_mutex_unlock
(&context->mutex);}

Grabbing the output (emacs -Q > test.out) shows the stall mid print:

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3208, g_main_context_acquire

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3222, g_main_context_acquire

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3801, g_main_context_iterate

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3812, g_main_context_iterate

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3376, g_main_context_prepare

MANEESH GLIB DEBUG: About to LOCK: gmain.c, 3501, g_main_context_prepare

MANEESH GLIB DEBUG

gmain.c 3501 region:

if (timeout)

    {

      *timeout = context->timeout;

      if (*timeout != 0)

        context->time_is_fresh = FALSE;

    }

  UNLOCK_CONTEXT (context)

  return n_poll;

Nothing terribly different from the lldb backtrace (for completeness):

(lldb) thread backtrace all

* thread #1: tid = 0x9bb3c, 0x00007fff8a861166
libsystem_kernel.dylib`__psynch_mutexwait + 10, queue =
'com.apple.main-thread', stop reason = signal SIGSTOP

  * frame #0: 0x00007fff8a861166 libsystem_kernel.dylib`__psynch_mutexwait + 10

    frame #1: 0x00007fff853b5696
libsystem_pthread.dylib`_pthread_mutex_lock + 480

    frame #2: 0x0000000100a17b78 libglib-2.0.0.dylib`g_mutex_lock + 26

    frame #3: 0x00000001009da551 libglib-2.0.0.dylib`g_main_context_acquire + 78

    frame #4: 0x000000010024fc47 emacs`xg_select + 231

    frame #5: 0x0000000100225c3d emacs`wait_reading_process_output + 3757

    frame #6: 0x0000000100008cb6 emacs`sit_for + 582

    frame #7: 0x0000000100108f00 emacs`read_char + 4496

    frame #8: 0x0000000100104edd emacs`read_key_sequence + 1757

    frame #9: 0x0000000100103cec emacs`command_loop_1 + 1212

    frame #10: 0x00000001001bf04e emacs`internal_condition_case + 382

    frame #11: 0x000000010011ce09 emacs`command_loop_2 + 41

    frame #12: 0x00000001001be696 emacs`internal_catch + 342

    frame #13: 0x0000000100102ddb emacs`command_loop + 187

    frame #14: 0x0000000100102c9f emacs`recursive_edit_1 + 127

    frame #15: 0x0000000100102f87 emacs`Frecursive_edit + 327

    frame #16: 0x0000000100100fd3 emacs`main + 4387

    frame #17: 0x00007fff8707a5c9 libdyld.dylib`start + 1

    frame #18: 0x00007fff8707a5c9 libdyld.dylib`start + 1

  thread #2: tid = 0x9bb48, 0x00007fff8a8613fa
libsystem_kernel.dylib`__select + 10, name = 'gmain'

    frame #0: 0x00007fff8a8613fa libsystem_kernel.dylib`__select + 10

    frame #1: 0x00000001009e8bed libglib-2.0.0.dylib`g_poll + 399

    frame #2: 0x00000001009dd303
libglib-2.0.0.dylib`g_main_context_iterate + 627

    frame #3: 0x00000001009dd40e
libglib-2.0.0.dylib`g_main_context_iteration + 104

    frame #4: 0x00000001009de7c6 libglib-2.0.0.dylib`glib_worker_main + 53

    frame #5: 0x00000001009fde09 libglib-2.0.0.dylib`g_thread_proxy + 90

    frame #6: 0x00007fff853b805a libsystem_pthread.dylib`_pthread_body + 131

    frame #7: 0x00007fff853b7fd7 libsystem_pthread.dylib`_pthread_start + 176

    frame #8: 0x00007fff853b53ed libsystem_pthread.dylib`thread_start + 13

Everything is terrible.

On Tue, Nov 24, 2015 at 5:50 PM, John Wiegley <[email-masked]> wrote:
>>>>>> Maneesh Yadav <[email-masked]> writes:
>
>>> To go deeper, we may need to build a separate copy of glib and start
>>> putting some print statements in to find out why there is lock contention.
>>> Would you be up for that? I'd like to know if this is happening in
>>> g_get_worker_context.
>
> I've read further, and since "static gsize initialised;" must initialize to
> zero, it's for me to see how this code could be wrong just from reading it.
>
> I'd like to find every line of code in glib that calls LOCK_CONTEXT or
> UNLOCK_CONTEXT, and print out:
>
>     Function, file, line, lock or unlock, pointer value of context
>
> That should help us narrow it down.
>
> John