Subject: Re: bug#50205: 27.2; crashes or hangs when opening a specific file using tramp

From: Eli Zaretskii <[email-masked]>
Date: Fri, 27 Aug 2021 09:04:26 +0300

[Please use Reply All when replying, to keep the bug address on the CC list.]

> From: Mani Kancherla <[email-masked]>
> Date: Thu, 26 Aug 2021 13:16:28 -0700
> 
> Thanks for looking into this. Here is a backtrace from when it crashed. This is with "GNU Emacs 27.2.50
> (build 3, x86_64-apple-darwin20.4.0, NS appkit-2022.44 Version 11.3.1 (Build 20E241)) of 2021-08-18". I just
> got the source and built locally.
> 
> Process 28232 stopped
> * thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
>     frame #0: 0x00007fff2038d58e libsystem_kernel.dylib`__abort_with_payload + 10
> libsystem_kernel.dylib`__abort_with_payload:
> ->  0x7fff2038d58e <+10>: jae    0x7fff2038d598            ; <+20>
>     0x7fff2038d590 <+12>: movq   %rax, %rdi
>     0x7fff2038d593 <+15>: jmp    0x7fff2036bb49            ; cerror_nocancel
>     0x7fff2038d598 <+20>: retq
> Target 0: (emacs) stopped.
> (lldb) bt
> * thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGABRT
>   * frame #0: 0x00007fff2038d58e libsystem_kernel.dylib`__abort_with_payload + 10
>     frame #1: 0x00007fff2038efdd libsystem_kernel.dylib`abort_with_payload_wrapper_internal + 80
>     frame #2: 0x00007fff2038ef8d libsystem_kernel.dylib`abort_with_reason + 19
>     frame #3: 0x00007fff2025e9e3 libobjc.A.dylib`_objc_fatalv(unsigned long long, unsigned long long, char
> const*, __va_list_tag*) + 114
>     frame #4: 0x00007fff2025e971 libobjc.A.dylib`_objc_fatal(char const*, ...) + 135
>     frame #5: 0x00007fff2025d6fe libobjc.A.dylib`void AutoreleasePoolPage::busted<void (*)(char const*, ...)>
> (void (*)(char const*, ...)) const + 120
>     frame #6: 0x00007fff2025f623 libobjc.A.dylib`AutoreleasePoolPage::busted_die() const + 9
>     frame #7: 0x00007fff20240db8 libobjc.A.dylib`objc_autoreleasePoolPop + 41
>     frame #8: 0x00007fff235348d3 AppKit`-[NSView
> _recursive:displayRectIgnoringOpacity:inContext:stopAtLayerBackedViews:] + 3258
>     frame #9: 0x00007fff22e03335 AppKit`-[NSView(NSLayerKitGlue)
> _drawViewBackingLayer:inContext:drawingHandler:] + 967
>     frame #10: 0x00007fff26c08de1 QuartzCore`CABackingStoreUpdate_ + 219
>     frame #11: 0x00007fff26c700f9 QuartzCore`invocation function for block in CA::Layer::display_() + 53
>     frame #12: 0x00007fff26c082f3 QuartzCore`-[CALayer _display] + 2247
>     frame #13: 0x00007fff22e02ea5 AppKit`-[_NSBackingLayer display] + 475
>     frame #14: 0x00007fff22d6e00f AppKit`-[_NSViewBackingLayer display] + 555
>     frame #15: 0x00007fff26c0725f QuartzCore`CA::Layer::display_if_needed(CA::Transaction*) + 863
>     frame #16: 0x00007fff26d5244a QuartzCore`CA::Context::commit_transaction(CA::Transaction*, double,
> double*) + 666
>     frame #17: 0x00007fff26be874f QuartzCore`CA::Transaction::commit() + 713
>     frame #18: 0x00007fff22e181dc AppKit`__62+[CATransaction(NSCATransaction)
> NS_setFlushesWithDisplayLink]_block_invoke + 285
>     frame #19: 0x00007fff2356c443 AppKit`___NSRunLoopObserverCreateWithHandler_block_invoke + 41
>     frame #20: 0x00007fff20498e41 CoreFoundation
> `__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__ + 23
>     frame #21: 0x00007fff20498cd5 CoreFoundation`__CFRunLoopDoObservers + 543
>     frame #22: 0x00007fff20498168 CoreFoundation`__CFRunLoopRun + 841
>     frame #23: 0x00007fff2049775c CoreFoundation`CFRunLoopRunSpecific + 563
>     frame #24: 0x00007fff286b9203 HIToolbox`RunCurrentEventLoopInMode + 292
>     frame #25: 0x00007fff286b8e36 HIToolbox`ReceiveNextEventCommon + 284
>     frame #26: 0x00007fff286b8d03 HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 70
>     frame #27: 0x00007fff22c93b32 AppKit`_DPSNextEvent + 864
>     frame #28: 0x00007fff22c92305 AppKit`-[NSApplication(NSEvent)
> _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1364
>     frame #29: 0x00000001001bd950 emacs`ns_send_appdefined(value=-1) at nsterm.m:4375:24 [opt]
>     frame #30: 0x00000001001bde9b emacs`ns_run_loop_break at nsterm.m:4760:5 [opt]
>     frame #31: 0x00000001001a9e6e emacs`sys_cond_broadcast(cond=<unavailable>) at systhread.c:183:3
> [opt]
>     frame #32: 0x00000001001a9c59 emacs`lisp_mutex_unlock(mutex=<unavailable>) at thread.c:230:3
> [opt]
>     frame #33: 0x00000001001a8af6 emacs`mutex_unlock_callback(arg=<unavailable>) at thread.c:339:7
> [opt]
>     frame #34: 0x0000000100120264 emacs`flush_stack_call_func(func=<unavailable>, arg=<unavailable>)
> at alloc.c:4951:3 [opt]
>     frame #35: 0x00000001001a8ac5 emacs`Fmutex_unlock(mutex=0x0000000101c46065) at thread.c:355:3
> [opt]
>     frame #36: 0x0000000100146bdb emacs`funcall_subr(subr=0x00000001002582f8, numargs=1,
> args=<unavailable>) at eval.c:2868:19 [opt]
>     frame #37: 0x000000010014625c emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:2795:11 [opt]
>     frame #38: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010680b034,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000002, nargs=0,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #39: 0x0000000100146df4 emacs`funcall_lambda(fun=0x0000000101c72fc5, nargs=0,
> arg_vector=0x00007ffeefbf8010) at eval.c:2990:11 [opt]
>     frame #40: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #41: 0x00000001001822aa emacs`bcall0(f=0x0000000101c72fc5) at bytecode.c:328:3 [opt]
>     frame #42: 0x0000000100147b0d emacs`do_one_unbind(this_binding=0x00007ffeefbf8068,
> unwinding=<unavailable>, bindflag=SET_INTERNAL_UNBIND) at eval.c:0 [opt]
>     frame #43: 0x000000010014283f emacs`unbind_to(count=<unavailable>, value=0x0000000000000000)
> at eval.c:3575:7 [opt]
>     frame #44: 0x000000010017ff2b emacs`exec_byte_code(bytestr=0x000000010680aff4,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000606, nargs=4,
> args=<unavailable>) at bytecode.c:653:4 [opt]
>     frame #45: 0x0000000100146df4 emacs`funcall_lambda(fun=0x0000000101baa0c5, nargs=4,
> arg_vector=0x00007ffeefbf8910) at eval.c:2990:11 [opt]
>     frame #46: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #47: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010214981c,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000c06, nargs=1,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #48: 0x0000000100146df4 emacs`funcall_lambda(fun=0x00000001021497d5, nargs=1,
> arg_vector=0x00007ffeefbf8ad0) at eval.c:2990:11 [opt]
>     frame #49: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #50: 0x000000010014683c emacs`call1(fn=<unavailable>, arg1=0x0000000100a955e4) at
> eval.c:2655:10 [opt]
>     frame #51: 0x000000010005a9ea emacs`decode_mode_spec(w=0x000000010303ea30, c=64,
> field_width=1, string=0x00007ffeefbf8b90) at xdisp.c:26602:10 [opt]
>     frame #52: 0x000000010003464a emacs`display_mode_element(it=0x00007ffeefbf8e28,
> depth=<unavailable>, field_width=<unavailable>, precision=<unavailable>, elt=<unavailable>,
> props=0x0000000000000000, risky=false) at xdisp.c:25520:14 [opt]
>     frame #53: 0x0000000100034113 emacs`display_mode_element(it=0x00007ffeefbf8e28,
> depth=<unavailable>, field_width=<unavailable>, precision=<unavailable>, elt=0x0000000102271a73,
> props=0x0000000000000000, risky=false) at xdisp.c:25721:13 [opt]
>     frame #54: 0x0000000100034113 emacs`display_mode_element(it=0x00007ffeefbf8e28,
> depth=<unavailable>, field_width=<unavailable>, precision=<unavailable>, elt=0x0000000102265d53,
> props=0x0000000000000000, risky=false) at xdisp.c:25721:13 [opt]
>     frame #55: 0x000000010001e1db emacs`display_mode_line(w=<unavailable>,
> face_id=MODE_LINE_FACE_ID, format=0x0000000102265d03) at xdisp.c:25211:3 [opt]
>     frame #56: 0x000000010004aaf0 emacs`display_mode_lines(w=0x000000010303ea30) at
> xdisp.c:25127:7 [opt]
>     frame #57: 0x0000000100051277 emacs`redisplay_window(window=0x000000010303ea35,
> just_this_one_p=false) at xdisp.c:18998:7 [opt]
>     frame #58: 0x000000010004fb76 emacs`redisplay_window_0(window=<unavailable>) at xdisp.c:16331:5
> [opt]
>     frame #59: 0x0000000100144d96 emacs`internal_condition_case_1(bfun=(emacs`redisplay_window_0
> at xdisp.c:16329), arg=0x000000010303ea35, handlers=<unavailable>, hfun=(emacs
> `redisplay_window_error at xdisp.c:16322)) at eval.c:1380:25 [opt]
>     frame #60: 0x000000010004ed54 emacs`redisplay_windows(window=0x000000010303ea35) at
> xdisp.c:16311:4 [opt]
>     frame #61: 0x000000010002b640 emacs`redisplay_internal at xdisp.c:15779:5 [opt]
>     frame #62: 0x000000010002d991 emacs`redisplay_preserve_echo_area(from_where=2) at
> xdisp.c:16128:7 [opt]
>     frame #63: 0x0000000100008d62 emacs`Fredisplay(force=<unavailable>) at dispnew.c:6093:3 [opt]
>     frame #64: 0x0000000100146bdb emacs`funcall_subr(subr=0x000000010024a558, numargs=0,
> args=<unavailable>) at eval.c:2868:19 [opt]
>     frame #65: 0x000000010014625c emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:2795:11 [opt]
>     frame #66: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x0000000102136ff4,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000c06, nargs=1,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #67: 0x0000000100146df4 emacs`funcall_lambda(fun=0x0000000102136d7d, nargs=1,
> arg_vector=0x00007ffeefbfe0c0) at eval.c:2990:11 [opt]
>     frame #68: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #69: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221cae4,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000802, nargs=0,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #70: 0x0000000100146df4 emacs`funcall_lambda(fun=0x00000001021e1f8d, nargs=0,
> arg_vector=0x00007ffeefbfe3d0) at eval.c:2990:11 [opt]
>     frame #71: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #72: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221d9a4,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000002, nargs=0,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #73: 0x0000000100146df4 emacs`funcall_lambda(fun=0x00000001021ddc05, nargs=0,
> arg_vector=0x00007ffeefbfe690) at eval.c:2990:11 [opt]
>     frame #74: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #75: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221e73c,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000002, nargs=0,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #76: 0x0000000100146df4 emacs`funcall_lambda(fun=0x000000010221e55d, nargs=0,
> arg_vector=0x00007ffeefbfe920) at eval.c:2990:11 [opt]
>     frame #77: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #78: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221e77c,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x000000000000080a, nargs=2,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #79: 0x0000000100146df4 emacs`funcall_lambda(fun=0x000000010221e4dd, nargs=2,
> arg_vector=0x00007ffeefbfeaf0) at eval.c:2990:11 [opt]
>     frame #80: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #81: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221ebfc,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000806, nargs=2,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #82: 0x0000000100146df4 emacs`funcall_lambda(fun=0x000000010221e415, nargs=2,
> arg_vector=0x00007ffeefbfecf8) at eval.c:2990:11 [opt]
>     frame #83: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #84: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x000000010221ecbc,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000000802, nargs=2,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #85: 0x0000000100146df4 emacs`funcall_lambda(fun=0x000000010221e305, nargs=2,
> arg_vector=0x00007ffeefbfefc0) at eval.c:2990:11 [opt]
>     frame #86: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #87: 0x000000010013ffba emacs`Ffuncall_interactively(nargs=<unavailable>, args=<unavailable>)
> at callint.c:254:32 [opt]
>     frame #88: 0x0000000100146b95 emacs`funcall_subr(subr=0x0000000100253dc8, numargs=3,
> args=<unavailable>) at eval.c:0 [opt]
>     frame #89: 0x000000010014625c emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:2795:11 [opt]
>     frame #90: 0x0000000100146021 emacs`Fapply(nargs=<unavailable>, args=0x00007ffeefbff0f8) at
> eval.c:2425:24 [opt]
>     frame #91: 0x00000001001402f5 emacs`Fcall_interactively(function=0x0000000001bd3c40,
> record_flag=0x0000000000000000, keys=0x0000000101c437f5) at callint.c:342:36 [opt]
>     frame #92: 0x0000000100146bec emacs`funcall_subr(subr=0x0000000100253d98, numargs=3,
> args=<unavailable>) at eval.c:2873:19 [opt]
>     frame #93: 0x000000010014625c emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:2795:11 [opt]
>     frame #94: 0x000000010017feb5 emacs`exec_byte_code(bytestr=0x0000000102242774,
> vector=<unavailable>, maxdepth=<unavailable>, args_template=0x0000000000001006, nargs=1,
> args=<unavailable>) at bytecode.c:633:12 [opt]
>     frame #95: 0x0000000100146df4 emacs`funcall_lambda(fun=0x0000000102242295, nargs=1,
> arg_vector=0x00007ffeefbff4b0) at eval.c:2990:11 [opt]
>     frame #96: 0x0000000100146243 emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at
> eval.c:0:4 [opt]
>     frame #97: 0x000000010014683c emacs`call1(fn=<unavailable>, arg1=<unavailable>) at eval.c:2655:10
> [opt]
>     frame #98: 0x00000001000c01f3 emacs`command_loop_1 at keyboard.c:1463:13 [opt]
>     frame #99: 0x0000000100144d22 emacs`internal_condition_case(bfun=(emacs`command_loop_1 at
> keyboard.c:1236), handlers=<unavailable>, hfun=(emacs`cmd_error at keyboard.c:919)) at eval.c:1356:25
> [opt]
>     frame #100: 0x00000001000cecae emacs`command_loop_2(ignore=0x0000000000000000) at
> keyboard.c:1091:11 [opt]
>     frame #101: 0x00000001001448cb emacs`internal_catch(tag=<unavailable>, func=(emacs
> `command_loop_2 at keyboard.c:1087), arg=0x0000000000000000) at eval.c:1117:25 [opt]
>     frame #102: 0x00000001001f7e2a emacs`command_loop.cold.1 at keyboard.c:1070:2 [opt]
>     frame #103: 0x00000001000bf42e emacs`command_loop at keyboard.c:0 [opt]
>     frame #104: 0x00000001000bf354 emacs`recursive_edit_1 at keyboard.c:714:9 [opt]
>     frame #105: 0x00000001000bf55e emacs`Frecursive_edit at keyboard.c:786:3 [opt]
>     frame #106: 0x00000001000bd818 emacs`main(argc=<unavailable>, argv=0x00007ffeefbff888) at
> emacs.c:2067:3 [opt]
>     frame #107: 0x00007fff203bbf3d libdyld.dylib`start + 1
>     frame #108: 0x00007fff203bbf3d libdyld.dylib`start + 1

This backtrace is very strange.  This part:

    frame #30: 0x00000001001bde9b emacs`ns_run_loop_break at nsterm.m:4760:5 [opt]
    frame #31: 0x00000001001a9e6e emacs`sys_cond_broadcast(cond=<unavailable>) at systhread.c:183:3 [opt]
    frame #32: 0x00000001001a9c59 emacs`lisp_mutex_unlock(mutex=<unavailable>) at thread.c:230:3 [opt]
    frame #33: 0x00000001001a8af6 emacs`mutex_unlock_callback(arg=<unavailable>) at thread.c:339:7 [opt]
    frame #34: 0x0000000100120264 emacs`flush_stack_call_func(func=<unavailable>, arg=<unavailable>) at alloc.c:4951:3 [opt]
    frame #35: 0x00000001001a8ac5 emacs`Fmutex_unlock(mutex=0x0000000101c46065) at thread.c:355:3 [opt]
    frame #36: 0x0000000100146bdb emacs`funcall_subr(subr=0x00000001002582f8, numargs=1, args=<unavailable>) at eval.c:2868:19 [opt]
    frame #37: 0x000000010014625c emacs`Ffuncall(nargs=<unavailable>, args=<unavailable>) at eval.c:2795:11 [opt]

says that funcall_subr calls Fmutex_unlock from line 2868 of eval.c,
but that is false.  It could be that the debugger is not presenting
the full backtrace, because this is an optimized build, and some
backtrace frames are missing due to inlining.

What was Emacs doing when this happened?  Could it be it was running
some Lisp which called mutex-unlock?  If so, the root cause for the
problem could be in that Lisp program: it could cause both lockups and
crashes related to mutexes.  Please see if such Lisp programs are
present in some packages you use.