From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Maneesh Yadav Newsgroups: gmane.emacs.bugs Subject: bug#21965: 24.5; Emacs freezes when canceling at open file Date: Thu, 18 Feb 2016 13:46:13 -0800 Message-ID: References: <8337vz6ca5.fsf@gnu.org> <83io4sysrk.fsf@gnu.org> NNTP-Posting-Host: plane.gmane.org Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 X-Trace: ger.gmane.org 1455832044 22322 80.91.229.3 (18 Feb 2016 21:47:24 GMT) X-Complaints-To: usenet@ger.gmane.org NNTP-Posting-Date: Thu, 18 Feb 2016 21:47:24 +0000 (UTC) Cc: 21965@debbugs.gnu.org To: John Wiegley Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Thu Feb 18 22:47:14 2016 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane.org Original-Received: from lists.gnu.org ([208.118.235.17]) by plane.gmane.org with esmtp (Exim 4.69) (envelope-from ) id 1aWWPp-000324-Gd for geb-bug-gnu-emacs@m.gmane.org; Thu, 18 Feb 2016 22:47:13 +0100 Original-Received: from localhost ([::1]:45942 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aWWPo-00023H-To for geb-bug-gnu-emacs@m.gmane.org; Thu, 18 Feb 2016 16:47:12 -0500 Original-Received: from eggs.gnu.org ([2001:4830:134:3::10]:46192) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aWWPj-00020J-IN for bug-gnu-emacs@gnu.org; Thu, 18 Feb 2016 16:47:09 -0500 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1aWWPe-0004Ru-H4 for bug-gnu-emacs@gnu.org; Thu, 18 Feb 2016 16:47:07 -0500 Original-Received: from debbugs.gnu.org ([208.118.235.43]:36148) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aWWPe-0004Rq-DK for bug-gnu-emacs@gnu.org; Thu, 18 Feb 2016 16:47:02 -0500 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84) (envelope-from ) id 1aWWPe-0006Lm-5z for bug-gnu-emacs@gnu.org; Thu, 18 Feb 2016 16:47:02 -0500 X-Loop: help-debbugs@gnu.org Resent-From: Maneesh Yadav Original-Sender: "Debbugs-submit" Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Thu, 18 Feb 2016 21:47:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 21965 X-GNU-PR-Package: emacs X-GNU-PR-Keywords: Original-Received: via spool by 21965-submit@debbugs.gnu.org id=B21965.145583198124349 (code B ref 21965); Thu, 18 Feb 2016 21:47:02 +0000 Original-Received: (at 21965) by debbugs.gnu.org; 18 Feb 2016 21:46:21 +0000 Original-Received: from localhost ([127.0.0.1]:33275 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84) (envelope-from ) id 1aWWOz-0006Kf-1T for submit@debbugs.gnu.org; Thu, 18 Feb 2016 16:46:21 -0500 Original-Received: from mail-pf0-f176.google.com ([209.85.192.176]:33937) by debbugs.gnu.org with esmtp (Exim 4.84) (envelope-from ) id 1aWWOx-0006KR-8p for 21965@debbugs.gnu.org; Thu, 18 Feb 2016 16:46:19 -0500 Original-Received: by mail-pf0-f176.google.com with SMTP id x65so38395887pfb.1 for <21965@debbugs.gnu.org>; Thu, 18 Feb 2016 13:46:19 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=FW3IhjnABZuUFGptPFbnmTQIcz/VmE9rf5q9swfRT/g=; b=N//1LSyk01yLtZ7MfGGoQQ9N0ANXQFIvi75ICdZOsQgJLV23TdVcjLE3zZsiNqa9sj iZHfwSRQu6UHPf4bcARpzTmDiCPcLLwgrgw9/8D4ZZYQFqHr7i5W2JWnqyo7SJdN0gSN ku9/UcNVB2BSptCglTxG81NZCDgATmxkwfthy2GLDJ/eaj7/DXAFeIEFrkN2l3N+W03Y 7nnYjAvJAtza5jBDpCRqiHNf+jvcwBzObd7Xcf6Hg9tIQ5T7MqK1Fmb6kxVBtaGwj+LZ e+phHKByCjeu5G5I1HADpcXXiOWnCy1YWz82UwOlpNPrISdjtZDfSxDJ9G90h75stMJf cNWw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:date :message-id:subject:from:to:cc:content-type; bh=FW3IhjnABZuUFGptPFbnmTQIcz/VmE9rf5q9swfRT/g=; b=Y7sY/WPxSj/odimTnFdIGQRwQRsD9T6UMGOny/AgQfBeJgLwx4Fb8EhWd/+mCSIOY0 I4wumj/Oxju2+8OaoLkzeGpWoONYltWW0Bgtb7/6JhdiTcz9ho2Wdrz4YeB7R63MyhWu FyQ6HwVDV/gE2Z+qIQzVnjeMD3XjYcaC+d0EFa7xpAbmLklvDUZCuFbjeV04H5EUSqG6 uGwBaT3qxlvNpmnTNgDm/3BvjMfM5dLBuKDIFgphvTZwA4H/lwgQlJJQNpQ2zGutcOx7 bmtfB92VsRLapb1puo3p3HQgEdkjVrkLBM1Gb6Yp10wH/3aQMI84UyQjFflFk70Ksw0N nseQ== X-Gm-Message-State: AG10YORqL4iNVjcDSHYLZ9UnLG0xTpZA/DU5JyMPyDS7HEi8vRCOEo6opGex49RspYL/lEqcJpHaZK9yp/GKKA== X-Received: by 10.98.9.27 with SMTP id e27mr13490754pfd.59.1455831973210; Thu, 18 Feb 2016 13:46:13 -0800 (PST) Original-Received: by 10.66.236.71 with HTTP; Thu, 18 Feb 2016 13:46:13 -0800 (PST) In-Reply-To: X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 208.118.235.43 X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Original-Sender: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.bugs:113258 Archived-At: Apologies to all I haven't ben able to follow up on this more thoroughly, part of the problem was trying to get the crash to replicate. I could do it in a few minutes while I was originally posting, then as I was getting all the right debug statements in it got harder and harder. I decided to just revert to normal use and wait for it to happen. Just happened again and I've put all the debugging info I can here and will try to trace through glib and figure out what is going on, just putting everything here for reference. overrided the following macros in gmain.c (and had to add some curly braces): #define LOCK_CONTEXT(context) g_mutex_lock (&context->mutex) #define LOCK_CONTEXT(context) {fprintf(stderr, "MANEESH GLIB DEBUG: About to LOCK: %p, %s, %d, %s, %p\n", context, __FILE__, __LINE__, __FUNCTION__,g_thread_self()); g_mutex_lock (&context->mutex);} #define UNLOCK_CONTEXT(context) g_mutex_unlock (&context->mutex) #define UNLOCK_CONTEXT(context) {fprintf(stderr, "MANEESH GLIB DEBUG: About to UNLOCK: %p, %s, %d, %s, %p\n", context, __FILE__, __LINE__, __FUNCTION__, g_thread_self()); g_mutex_unlock (&context->mutex);} At the time of crash, an abbreviated summary of stderr: ... MANEESH GLIB DEBUG: About to UNLOCK: 0x100f00e20, gmain.c, 4128, g_main_context_poll, 0x102001c00 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3222, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3538, g_main_context_query, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3583, g_main_context_query, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3859, g_main_context_pending, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3782, g_main_context_iterate, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3222, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3801, g_main_context_iterate, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3812, g_main_context_iterate, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3376, g_main_context_prepare, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3501, g_main_context_prepare, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3538, g_main_context_query, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3583, g_main_context_query, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 4124, g_main_context_poll, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 4128, g_main_context_poll, 0x100da5800 ... MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3242, g_main_context_release, 0x100da5800 MANEESH GLIB DEBUG: About to UNLOCK: 0x100d8a3a0, gmain.c, 3265, g_main_context_release, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 MANEESH GLIB DEBUG: About to LOCK: 0x100d8a3a0, gmain.c, 3208, g_main_context_acquire, 0x100da5800 lldb traces: (lldb) attach emacs Process 79773 stopped * thread #1: tid = 0x6c3b4f, 0x00007fff8deb9166 libsystem_kernel.dylib`__psynch_mutexwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP frame #0: 0x00007fff8deb9166 libsystem_kernel.dylib`__psynch_mutexwait + 10 libsystem_kernel.dylib`__psynch_mutexwait: -> 0x7fff8deb9166 <+10>: jae 0x7fff8deb9170 ; <+20> 0x7fff8deb9168 <+12>: movq %rax, %rdi 0x7fff8deb916b <+15>: jmp 0x7fff8deb4c53 ; cerror_nocancel 0x7fff8deb9170 <+20>: retq Executable module set to "/opt/local/bin/emacs". Architecture set to: x86_64h-apple-macosx. (lldb) thread backtrace all * thread #1: tid = 0x6c3b4f, 0x00007fff8deb9166 libsystem_kernel.dylib`__psynch_mutexwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP * frame #0: 0x00007fff8deb9166 libsystem_kernel.dylib`__psynch_mutexwait + 10 frame #1: 0x00007fff88a0d696 libsystem_pthread.dylib`_pthread_mutex_lock + 480 frame #2: 0x0000000100a17b48 libglib-2.0.0.dylib`g_mutex_lock + 26 frame #3: 0x00000001009d9b53 libglib-2.0.0.dylib`g_main_context_acquire + 109 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: 0x00007fff8a6d25c9 libdyld.dylib`start + 1 frame #18: 0x00007fff8a6d25c9 libdyld.dylib`start + 1 thread #2: tid = 0x6c3b6b, 0x00007fff8deb93fa libsystem_kernel.dylib`__select + 10, name = 'gmain' frame #0: 0x00007fff8deb93fa libsystem_kernel.dylib`__select + 10 frame #1: 0x00000001009e8bbd libglib-2.0.0.dylib`g_poll + 399 frame #2: 0x00000001009dd07c libglib-2.0.0.dylib`g_main_context_iterate + 845 frame #3: 0x00000001009dd1b1 libglib-2.0.0.dylib`g_main_context_iteration + 127 frame #4: 0x00000001009de796 libglib-2.0.0.dylib`glib_worker_main + 53 frame #5: 0x00000001009fddd9 libglib-2.0.0.dylib`g_thread_proxy + 90 frame #6: 0x00007fff88a1005a libsystem_pthread.dylib`_pthread_body + 131 frame #7: 0x00007fff88a0ffd7 libsystem_pthread.dylib`_pthread_start + 176 frame #8: 0x00007fff88a0d3ed libsystem_pthread.dylib`thread_start + 13 Inkscape is the only other binary linked to glib that is running, I think: Maneeshs-MacBook-Air:~ maneeshyadav$ ps PID TTY TIME CMD 49116 ttys000 0:00.14 -bash 79773 ttys000 2:16.74 emacs 49772 ttys001 0:01.80 -bash 63245 ttys002 0:00.56 -bash 65082 ttys002 0:00.01 /bin/bash /Applications/ChemAxon/MarvinBeans/bin/msketch 65087 ttys002 18:31.79 /Library/Java/JavaVirtualMachines/jdk1.8.0_60.jdk/Contents/Home/bin/java chemaxon.marvin.Sketch 81099 ttys002 1:06.60 inkscape On Wed, Nov 25, 2015 at 10:49 AM, Maneesh Yadav wrote: > 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 wrote: >>>>>>> Maneesh Yadav 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