Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Avalonia causes a deadlock in mono's runtime during Garbagge Collection in macOS #9444

Closed
ylatuya opened this issue Nov 15, 2022 · 7 comments
Labels

Comments

@ylatuya
Copy link

ylatuya commented Nov 15, 2022

Describe the bug
Avalonia 0.10.18 in macOS is causing a deadlock in mono's runtime during garbage collection. The GC is pausing the world in Thread 1 and waiting for all managed threads to finish pending operations. Meanwhile, in a managed thread, Avalonia's renderer is trying to acquire a lock for rendering in AvnGlRenderTarget::BeginDrawing that most likely needs to be released in Thread 1, causing a deadlock.

To Reproduce
I haven't been to create a demo project to reproduce it, but I can consistently reproduce it in my application, although it's racy, when a I launch a new modal dialog in a new window.

Expected behavior
Mono does not deadlock in garbage collection

Screenshots

Desktop (please complete the following information):

  • OS: Mac
  • Version: 12.3.1

Additional context

Deadlock in AvnGlRenderTarget::BeginDrawing trying to make the GL context current ``` * thread #1 * frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylib`semaphore_wait_trap + 10 frame #1: 0x000000010565bef9 mono-sgen64`mono_os_sem_timedwait [inlined] mono_os_sem_wait at mono-os-semaphore.h:84:8 [opt] frame #2: 0x000000010565bef0 mono-sgen64`mono_os_sem_timedwait(sem=, timeout_ms=, flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:103 [opt] frame #3: 0x000000010565b9b5 mono-sgen64`mono_threads_wait_pending_operations at mono-threads.c:319:8 [opt] frame #4: 0x00000001055fb123 mono-sgen64`sgen_client_stop_world at sgen-stw.c:306:3 [opt] frame #5: 0x00000001055fb10f mono-sgen64`sgen_client_stop_world(generation=0, serial_collection=0) at sgen-stw.c:124 [opt] frame #6: 0x000000010560e4e6 mono-sgen64`sgen_stop_world(generation=0, serial_collection=0) at sgen-gc.c:3871:2 [opt] frame #7: 0x000000010560b14d mono-sgen64`sgen_perform_collection [inlined] sgen_perform_collection_inner at sgen-gc.c:2566:3 [opt] frame #8: 0x000000010560b0e5 mono-sgen64`sgen_perform_collection(requested_size=2168, generation_to_collect=0, reason="Nursery full", forced_serial=0, stw=1) at sgen-gc.c:2679 [opt] frame #9: 0x000000010560b097 mono-sgen64`sgen_ensure_free_space(size=2168, generation=) at sgen-gc.c:2545:2 [opt] frame #10: 0x0000000105600e0d mono-sgen64`sgen_alloc_obj_nolock(vtable=0x00007fb8da30c4c0, size=2168) at sgen-alloc.c:258:6 [opt] frame #11: 0x00000001055fd7d1 mono-sgen64`mono_gc_alloc_vector(vtable=0x00007fb8da30c4c0, size=2168, max_length=89) at sgen-mono.c:1322:20 [opt] frame #12: 0x105b42636 (wrapper managed-to-native) object:__icall_wrapper_mono_gc_alloc_vector (intptr,intptr,intptr) [{0x7fb8cf043888} + 0xc6] (0x105b42570 0x105b4270a) [0x7fb8ceb042d0 - LongoMatch.exe]

thread #2
frame #0: 0x00007ff803bb73ea libsystem_kernel.dylib__psynch_cvwait + 10 frame #1: 0x00007ff803bf1a6f libsystem_pthread.dylib_pthread_cond_wait + 1249
frame #2: 0x0000000105641b1e mono-sgen64thread_func [inlined] mono_os_cond_wait(mutex=<unavailable>) at mono-os-mutex.h:219:8 [opt] frame #3: 0x0000000105641b0b mono-sgen64thread_func at sgen-thread-pool.c:165 [opt]
frame #4: 0x0000000105641afd mono-sgen64thread_func(data=0x0000000000000000) at sgen-thread-pool.c:196 [opt] frame #5: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125
frame #6: 0x00007ff803becf6b libsystem_pthread.dylib`thread_start + 15

thread #3
frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylibsemaphore_wait_trap + 10 frame #1: 0x00000001055ee6da mono-sgen64finalizer_thread [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:84:8 [opt]
frame #2: 0x00000001055ee6cf mono-sgen64finalizer_thread at mono-coop-semaphore.h:41 [opt] frame #3: 0x00000001055ee6b5 mono-sgen64finalizer_thread(unused=) at gc.c:965 [opt]
frame #4: 0x00000001055acc4d mono-sgen64start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt] frame #5: 0x00000001055acc0a mono-sgen64start_wrapper(data=0x00006000034989c0) at threads.c:1308 [opt]
frame #6: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125 frame #7: 0x00007ff803becf6b libsystem_pthread.dylibthread_start + 15

thread #4
frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylibsemaphore_wait_trap + 10 frame #1: 0x000000010565b808 mono-sgen64mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
frame #2: 0x000000010565b7f9 mono-sgen64mono_thread_info_wait_for_resume(info=0x00007fb8cf820000) at mono-threads.c:233 [opt] frame #3: 0x0000000105661c18 mono-sgen64mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x00007fb8cf820000, stackdata=) at mono-threads-coop.c:391:3 [opt]
frame #4: 0x00000001054cab0f mono-sgen64socket_transport_recv(buf=2001-01-01 00:00:00 UTC, len=11) at debugger-agent.c:1178:2 [opt] frame #5: 0x00000001054b9406 mono-sgen64debugger_thread [inlined] transport_recv(len=11) at debugger-agent.c:1578:9 [opt]
frame #6: 0x00000001054b93cd mono-sgen64debugger_thread(arg=<unavailable>) at debugger-agent.c:10196 [opt] frame #7: 0x00000001055acc4d mono-sgen64start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
frame #8: 0x00000001055acc0a mono-sgen64start_wrapper(data=0x0000600003498a40) at threads.c:1308 [opt] frame #9: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125
frame #10: 0x00007ff803becf6b libsystem_pthread.dylib`thread_start + 15

thread #5
frame #0: 0x00007ff803bb497a libsystem_kernel.dylibmach_msg_trap + 10 frame #1: 0x00007ff803bb4ce8 libsystem_kernel.dylibmach_msg + 56
frame #2: 0x00007ff803cb7cdd CoreFoundation__CFRunLoopServiceMachPort + 319 frame #3: 0x00007ff803cb6368 CoreFoundation__CFRunLoopRun + 1276
frame #4: 0x00007ff803cb57ac CoreFoundationCFRunLoopRunSpecific + 562 frame #5: 0x00007ff806849f5e AppKit_NSEventThread + 132
frame #6: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125 frame #7: 0x00007ff803becf6b libsystem_pthread.dylibthread_start + 15

thread #6
frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylibsemaphore_wait_trap + 10 frame #1: 0x000000010565b808 mono-sgen64mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
frame #2: 0x000000010565b7f9 mono-sgen64mono_thread_info_wait_for_resume(info=0x00007fb8d48bfc00) at mono-threads.c:233 [opt] frame #3: 0x0000000105661c18 mono-sgen64mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x00007fb8d48bfc00, stackdata=) at mono-threads-coop.c:391:3 [opt]
frame #4: 0x00000001055b9516 mono-sgen64mono_w32handle_timedwait_signal_handle at mono-coop-mutex.h:105:2 [opt] frame #5: 0x00000001055b94dc mono-sgen64mono_w32handle_timedwait_signal_handle [inlined] mono_w32handle_timedwait_signal_naked(poll=0, alerted=) at w32handle.c:652 [opt]
frame #6: 0x00000001055b94dc mono-sgen64mono_w32handle_timedwait_signal_handle(handle_data=<unavailable>, timeout=<unavailable>, poll=0, alerted=<unavailable>) at w32handle.c:767 [opt] frame #7: 0x00000001055b93d1 mono-sgen64mono_w32handle_wait_one(handle=, timeout=, alertable=) at w32handle.c:892:13 [opt]
frame #8: 0x00000001055b9649 mono-sgen64mono_w32handle_wait_multiple(handles=0x000070000e685860, nhandles=1, waitall=0, timeout=<unavailable>, alertable=1, error=0x000070000e685708) at w32handle.c:1002:10 [opt] frame #9: 0x00000001055a623d mono-sgen64ves_icall_System_Threading_WaitHandle_Wait_internal(handles=, numhandles=, waitall=, timeout=-1, error=0x000070000e685708) at threads.c:2314:9 [opt]
frame #10: 0x000000010553f308 mono-sgen64ves_icall_System_Threading_WaitHandle_Wait_internal_raw(a0=0x000070000e685860, a1=1, a2='\0', a3=11) at icall-def.h:1100:1 [opt] frame #11: 0x0000000118f7f8f1 frame #12: 0x0000000118f7f0db frame #13: 0x0000000118f7b4ba frame #14: 0x0000000118f79383 frame #15: 0x0000000105372352 mono-sgen64mono_jit_runtime_invoke(method=, obj=, params=0x000070000e685f68, exc=, error=) at mini-runtime.c:3217:12 [opt]
frame #16: 0x0000000105581e07 mono-sgen64mono_runtime_invoke_checked [inlined] do_runtime_invoke(method=<unavailable>, obj=0x0000000105fcff78, params=0x000070000e685f68, exc=<unavailable>, error=0x000070000e685f18) at object.c:3052:11 [opt] frame #17: 0x0000000105581dd2 mono-sgen64mono_runtime_invoke_checked(method=0x00007fb8d4965980, obj=0x0000000105fcff78, params=0x000070000e685f68, error=0x000070000e685f18) at object.c:3220 [opt]
frame #18: 0x0000000105588700 mono-sgen64mono_runtime_delegate_try_invoke(delegate=0x0000000105fcff78, params=0x000070000e685f68, exc=0x0000000000000000, error=0x000070000e685f18) at object.c:4438:7 [opt] frame #19: 0x00000001055acc8d mono-sgen64start_wrapper at threads.c:1255:3 [opt]
frame #20: 0x00000001055acc0a mono-sgen64start_wrapper(data=0x00006000034fa580) at threads.c:1308 [opt] frame #21: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125
frame #22: 0x00007ff803becf6b libsystem_pthread.dylib`thread_start + 15

thread #7
frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylibsemaphore_wait_trap + 10 frame #1: 0x000000010565b808 mono-sgen64mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
frame #2: 0x000000010565b7f9 mono-sgen64mono_thread_info_wait_for_resume(info=0x00007fb8d4a45c00) at mono-threads.c:233 [opt] frame #3: 0x0000000105661c18 mono-sgen64mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x00007fb8d4a45c00, stackdata=) at mono-threads-coop.c:391:3 [opt]
frame #4: 0x000000010565e459 mono-sgen64mono_thread_info_sleep at mono-coop-mutex.h:93:2 [opt] frame #5: 0x000000010565e419 mono-sgen64mono_thread_info_sleep [inlined] sleep_interruptable(ms=, alerted=) at mono-threads.c:1643 [opt]
frame #6: 0x000000010565e393 mono-sgen64mono_thread_info_sleep(ms=500, alerted=<unavailable>) at mono-threads.c:1673 [opt] frame #7: 0x00000001054e4092 mono-sgen64monitor_thread(unused=) at threadpool-worker-default.c:728:8 [opt]
frame #8: 0x00000001055acc4d mono-sgen64start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt] frame #9: 0x00000001055acc0a mono-sgen64start_wrapper(data=0x000060000342a980) at threads.c:1308 [opt]
frame #10: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125 frame #11: 0x00007ff803becf6b libsystem_pthread.dylibthread_start + 15

thread #8
frame #0: 0x00007ff803bb49b6 libsystem_kernel.dylibsemaphore_wait_trap + 10 frame #1: 0x000000010565b808 mono-sgen64mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
frame #2: 0x000000010565b7f9 mono-sgen64mono_thread_info_wait_for_resume(info=0x00007fb8d2863400) at mono-threads.c:233 [opt] frame #3: 0x0000000105661c18 mono-sgen64mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x00007fb8d2863400, stackdata=) at mono-threads-coop.c:391:3 [opt]
frame #4: 0x00000001054e45b6 mono-sgen64worker_thread at mono-coop-semaphore.h:57:2 [opt] frame #5: 0x00000001054e44da mono-sgen64worker_thread at threadpool-worker-default.c:388 [opt]
frame #6: 0x00000001054e4430 mono-sgen64worker_thread(unused=<unavailable>) at threadpool-worker-default.c:490 [opt] frame #7: 0x00000001055acc4d mono-sgen64start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
frame #8: 0x00000001055acc0a mono-sgen64start_wrapper(data=0x0000600003425e40) at threads.c:1308 [opt] frame #9: 0x00007ff803bf14e1 libsystem_pthread.dylib_pthread_start + 125
frame #10: 0x00007ff803becf6b libsystem_pthread.dylib`thread_start + 15

thread #9
frame #0: 0x00007ff803bb6bd2 libsystem_kernel.dylib__psynch_mutexwait + 10 frame #1: 0x00007ff803beee7e libsystem_pthread.dylib_pthread_mutex_firstfit_lock_wait + 76
frame #2: 0x00007ff803beccbb libsystem_pthread.dylib_pthread_mutex_firstfit_lock_slow + 205 frame #3: 0x00007ffa1bc98d00 OpenGLCGLLockContext + 34
frame #4: 0x00000001190bd909 libAvaloniaNative.dylibAvnGlContext::MakeCurrent(IUnknown**) + 75 frame #5: 0x00000001190bcda5 libAvaloniaNative.dylibAvnGlRenderTarget::BeginDrawing(IAvnGlSurfaceRenderingSession**) + 113
frame #6: 0x000000011b880ecb
mono-sgen64 was compiled with optimization - stepping may behave oddly; variables may not be available.
frame #7: 0x000000011b87f99a
frame #8: 0x000000011b83a93d
[...]
```

Deadlock in AvnGlRenderTarget::BeginDrawing acquiring the `IAvnGlSurfaceRenderingSession` lock
* thread #1, name = 'tid_103', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001002fdef9 mono`mono_os_sem_timedwait [inlined] mono_os_sem_wait at mono-os-semaphore.h:84:8 [opt]
    frame #2: 0x00000001002fdef0 mono`mono_os_sem_timedwait(sem=<unavailable>, timeout_ms=<unavailable>, flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:103 [opt]
    frame #3: 0x00000001002fd9b5 mono`mono_threads_wait_pending_operations at mono-threads.c:319:8 [opt]
    frame #4: 0x000000010029d123 mono`sgen_client_stop_world at sgen-stw.c:306:3 [opt]
    frame #5: 0x000000010029d10f mono`sgen_client_stop_world(generation=0, serial_collection=0) at sgen-stw.c:124 [opt]
    frame #6: 0x00000001002b04e6 mono`sgen_stop_world(generation=0, serial_collection=0) at sgen-gc.c:3871:2 [opt]
    frame #7: 0x00000001002ad14d mono`sgen_perform_collection [inlined] sgen_perform_collection_inner at sgen-gc.c:2566:3 [opt]
    frame #8: 0x00000001002ad0e5 mono`sgen_perform_collection(requested_size=2168, generation_to_collect=0, reason="Nursery full", forced_serial=0, stw=1) at sgen-gc.c:2679 [opt]
    frame #9: 0x00000001002ad097 mono`sgen_ensure_free_space(size=2168, generation=<unavailable>) at sgen-gc.c:2545:2 [opt]
    frame #10: 0x00000001002a2e0d mono`sgen_alloc_obj_nolock(vtable=0x0000000120a40fa0, size=2168) at sgen-alloc.c:258:6 [opt]
    frame #11: 0x000000010029f7d1 mono`mono_gc_alloc_vector(vtable=0x0000000120a40fa0, size=2168, max_length=89) at sgen-mono.c:1322:20 [opt]
    frame #12: 0x00000001016d33e9
    frame #13: 0x00000001059ffc1a mscorlib.dll.dylib`System_Collections_Generic_Dictionary_2_TKey_REF_TValue_REF_Resize_int_bool + 106
    frame #14: 0x00000001059ffb9d mscorlib.dll.dylib`System_Collections_Generic_Dictionary_2_TKey_REF_TValue_REF_Resize + 61
    frame #15: 0x00000001059ff664 mscorlib.dll.dylib`System_Collections_Generic_Dictionary_2_TKey_REF_TValue_REF_TryInsert_TKey_REF_TValue_REF_System_Collections_Generic_InsertionBehavior + 1588
    frame #16: 0x00000001059fdc8e mscorlib.dll.dylib`System_Collections_Generic_Dictionary_2_TKey_REF_TValue_REF_Add_TKey_REF_TValue_REF + 62
    frame #17: 0x00000001296ec193
  thread #2, name = 'SGen worker'
    frame #0: 0x00007ff8158713ea libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007ff8158aba6f libsystem_pthread.dylib`_pthread_cond_wait + 1249
    frame #2: 0x00000001002e3b1e mono`thread_func [inlined] mono_os_cond_wait(mutex=<unavailable>) at mono-os-mutex.h:219:8 [opt]
    frame #3: 0x00000001002e3b0b mono`thread_func at sgen-thread-pool.c:165 [opt]
    frame #4: 0x00000001002e3afd mono`thread_func(data=0x0000000000000000) at sgen-thread-pool.c:196 [opt]
    frame #5: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #6: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #3, name = 'Finalizer'
    frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001002906da mono`finalizer_thread [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:84:8 [opt]
    frame #2: 0x00000001002906cf mono`finalizer_thread at mono-coop-semaphore.h:41 [opt]
    frame #3: 0x00000001002906b5 mono`finalizer_thread(unused=<unavailable>) at gc.c:965 [opt]
    frame #4: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #5: 0x000000010024ec0a mono`start_wrapper(data=0x000000010100e670) at threads.c:1308 [opt]
    frame #6: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #7: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #4
    frame #0: 0x00007ff8158a6f48 libsystem_pthread.dylib`start_wqthread
  thread #6
    frame #0: 0x00007ff81587005a libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x00007ff8158a8034 libsystem_pthread.dylib`_pthread_wqthread + 426
    frame #2: 0x00007ff8158a6f57 libsystem_pthread.dylib`start_wqthread + 15
  thread #8, name = 'com.apple.NSEventThread'
    frame #0: 0x00007ff81586e97a libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x00007ff81586ece8 libsystem_kernel.dylib`mach_msg + 56
    frame #2: 0x00007ff815971cdd CoreFoundation`__CFRunLoopServiceMachPort + 319
    frame #3: 0x00007ff815970368 CoreFoundation`__CFRunLoopRun + 1276
    frame #4: 0x00007ff81596f7ac CoreFoundation`CFRunLoopRunSpecific + 562
    frame #5: 0x00007ff818503f5e AppKit`_NSEventThread + 132
    frame #6: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #7: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #9, name = 'Timer-Scheduler'
    frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001002fd808 mono`mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
    frame #2: 0x00000001002fd7f9 mono`mono_thread_info_wait_for_resume(info=0x0000000112eba600) at mono-threads.c:233 [opt]
    frame #3: 0x0000000100303c18 mono`mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x0000000112eba600, stackdata=<unavailable>) at mono-threads-coop.c:391:3 [opt]
    frame #4: 0x000000010025b516 mono`mono_w32handle_timedwait_signal_handle at mono-coop-mutex.h:105:2 [opt]
    frame #5: 0x000000010025b4dc mono`mono_w32handle_timedwait_signal_handle [inlined] mono_w32handle_timedwait_signal_naked(poll=0, alerted=<unavailable>) at w32handle.c:652 [opt]
    frame #6: 0x000000010025b4dc mono`mono_w32handle_timedwait_signal_handle(handle_data=<unavailable>, timeout=<unavailable>, poll=0, alerted=<unavailable>) at w32handle.c:767 [opt]
    frame #7: 0x000000010025b3d1 mono`mono_w32handle_wait_one(handle=<unavailable>, timeout=<unavailable>, alertable=<unavailable>) at w32handle.c:892:13 [opt]
    frame #8: 0x000000010025b649 mono`mono_w32handle_wait_multiple(handles=0x0000700001f759f0, nhandles=1, waitall=0, timeout=<unavailable>, alertable=1, error=0x0000700001f758d8) at w32handle.c:1002:10 [opt]
    frame #9: 0x000000010024823d mono`ves_icall_System_Threading_WaitHandle_Wait_internal(handles=<unavailable>, numhandles=<unavailable>, waitall=<unavailable>, timeout=-1, error=0x0000700001f758d8) at threads.c:2314:9 [opt]
    frame #10: 0x00000001001e1308 mono`ves_icall_System_Threading_WaitHandle_Wait_internal_raw(a0=0x0000700001f759f0, a1=1, a2='\0', a3=16) at icall-def.h:1100:1 [opt]
    frame #11: 0x000000011b927479
    frame #12: 0x00000001056add56 mscorlib.dll.dylib`System_Threading_WaitHandle_InternalWaitOne_System_Runtime_InteropServices_SafeHandle_long_bool_bool + 86
    frame #13: 0x00000001056adcf1 mscorlib.dll.dylib`System_Threading_WaitHandle_WaitOne_long_bool + 65
    frame #14: 0x00000001056adac7 mscorlib.dll.dylib`System_Threading_WaitHandle_WaitOne_int_bool + 71
    frame #15: 0x00000001056adc49 mscorlib.dll.dylib`System_Threading_WaitHandle_WaitOne_int + 57
    frame #16: 0x00000001056b43aa mscorlib.dll.dylib`System_Threading_Timer_Scheduler_SchedulerThread + 282
    frame #17: 0x00000001056a556b mscorlib.dll.dylib`System_Threading_ThreadHelper_ThreadStart_Context_object + 171
    frame #18: 0x00000001056a2c23 mscorlib.dll.dylib`System_Threading_ExecutionContext_Run_System_Threading_ExecutionContext_System_Threading_ContextCallback_object_bool + 67
    frame #19: 0x00000001056a2b98 mscorlib.dll.dylib`System_Threading_ExecutionContext_Run_System_Threading_ExecutionContext_System_Threading_ContextCallback_object + 104
    frame #20: 0x00000001056a56f3 mscorlib.dll.dylib`System_Threading_ThreadHelper_ThreadStart + 67
    frame #21: 0x0000000115c4cfc1
    frame #22: 0x0000000100014352 mono`mono_jit_runtime_invoke(method=<unavailable>, obj=<unavailable>, params=0x0000700001f75f68, exc=<unavailable>, error=<unavailable>) at mini-runtime.c:3217:12 [opt]
    frame #23: 0x0000000100223e07 mono`mono_runtime_invoke_checked [inlined] do_runtime_invoke(method=<unavailable>, obj=0x0000000102bce498, params=0x0000700001f75f68, exc=<unavailable>, error=0x0000700001f75f18) at object.c:3052:11 [opt]
    frame #24: 0x0000000100223dd2 mono`mono_runtime_invoke_checked(method=0x0000000112f8a4b8, obj=0x0000000102bce498, params=0x0000700001f75f68, error=0x0000700001f75f18) at object.c:3220 [opt]
    frame #25: 0x000000010022a700 mono`mono_runtime_delegate_try_invoke(delegate=0x0000000102bce498, params=0x0000700001f75f68, exc=0x0000000000000000, error=0x0000700001f75f18) at object.c:4438:7 [opt]
    frame #26: 0x000000010024ec8d mono`start_wrapper at threads.c:1255:3 [opt]
    frame #27: 0x000000010024ec0a mono`start_wrapper(data=0x000000011ce5b220) at threads.c:1308 [opt]
    frame #28: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #29: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #10, name = 'tid_bf03'
    frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001002fd808 mono`mono_thread_info_wait_for_resume [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:84:8 [opt]
    frame #2: 0x00000001002fd7f9 mono`mono_thread_info_wait_for_resume(info=0x00000001113c8a00) at mono-threads.c:233 [opt]
    frame #3: 0x0000000100303c18 mono`mono_threads_exit_gc_safe_region_unbalanced_internal(cookie=0x00000001113c8a00, stackdata=<unavailable>) at mono-threads-coop.c:391:3 [opt]
    frame #4: 0x0000000100300459 mono`mono_thread_info_sleep at mono-coop-mutex.h:93:2 [opt]
    frame #5: 0x0000000100300419 mono`mono_thread_info_sleep [inlined] sleep_interruptable(ms=<unavailable>, alerted=<unavailable>) at mono-threads.c:1643 [opt]
    frame #6: 0x0000000100300393 mono`mono_thread_info_sleep(ms=500, alerted=<unavailable>) at mono-threads.c:1673 [opt]
    frame #7: 0x0000000100186092 mono`monitor_thread(unused=<unavailable>) at threadpool-worker-default.c:728:8 [opt]
    frame #8: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #9: 0x000000010024ec0a mono`start_wrapper(data=0x000000011cf12a00) at threads.c:1308 [opt]
    frame #10: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #11: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #11, name = 'Thread Pool Worker'
    frame #0: 0x00007ff81586e9ce libsystem_kernel.dylib`semaphore_timedwait_trap + 10
    frame #1: 0x000000010018655d mono`worker_thread [inlined] mono_os_sem_timedwait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:118:8 [opt]
    frame #2: 0x00000001001864f1 mono`worker_thread at mono-coop-semaphore.h:55 [opt]
    frame #3: 0x00000001001864da mono`worker_thread at threadpool-worker-default.c:388 [opt]
    frame #4: 0x0000000100186430 mono`worker_thread(unused=<unavailable>) at threadpool-worker-default.c:490 [opt]
    frame #5: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #6: 0x000000010024ec0a mono`start_wrapper(data=0x000000011cf12bc0) at threads.c:1308 [opt]
    frame #7: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #8: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #12, name = 'Thread Pool Worker'
    frame #0: 0x00007ff81586e9ce libsystem_kernel.dylib`semaphore_timedwait_trap + 10
    frame #1: 0x000000010018655d mono`worker_thread [inlined] mono_os_sem_timedwait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:118:8 [opt]
    frame #2: 0x00000001001864f1 mono`worker_thread at mono-coop-semaphore.h:55 [opt]
    frame #3: 0x00000001001864da mono`worker_thread at threadpool-worker-default.c:388 [opt]
    frame #4: 0x0000000100186430 mono`worker_thread(unused=<unavailable>) at threadpool-worker-default.c:490 [opt]
    frame #5: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #6: 0x000000010024ec0a mono`start_wrapper(data=0x000000011cf13390) at threads.c:1308 [opt]
    frame #7: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #8: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #13, name = 'Thread Pool Worker'
    frame #0: 0x00007ff81586e9ce libsystem_kernel.dylib`semaphore_timedwait_trap + 10
    frame #1: 0x000000010018655d mono`worker_thread [inlined] mono_os_sem_timedwait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:118:8 [opt]
    frame #2: 0x00000001001864f1 mono`worker_thread at mono-coop-semaphore.h:55 [opt]
    frame #3: 0x00000001001864da mono`worker_thread at threadpool-worker-default.c:388 [opt]
    frame #4: 0x0000000100186430 mono`worker_thread(unused=<unavailable>) at threadpool-worker-default.c:490 [opt]
    frame #5: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #6: 0x000000010024ec0a mono`start_wrapper(data=0x000000011a5a89c0) at threads.c:1308 [opt]
    frame #7: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #8: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #14, name = 'Thread Pool Worker'
    frame #0: 0x00007ff81586e9ce libsystem_kernel.dylib`semaphore_timedwait_trap + 10
    frame #1: 0x000000010018655d mono`worker_thread [inlined] mono_os_sem_timedwait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:118:8 [opt]
    frame #2: 0x00000001001864f1 mono`worker_thread at mono-coop-semaphore.h:55 [opt]
    frame #3: 0x00000001001864da mono`worker_thread at threadpool-worker-default.c:388 [opt]
    frame #4: 0x0000000100186430 mono`worker_thread(unused=<unavailable>) at threadpool-worker-default.c:490 [opt]
    frame #5: 0x000000010024ec4d mono`start_wrapper [inlined] start_wrapper_internal at threads.c:1233:3 [opt]
    frame #6: 0x000000010024ec0a mono`start_wrapper(data=0x000000012113b240) at threads.c:1308 [opt]
    frame #7: 0x00007ff8158ab4e1 libsystem_pthread.dylib`_pthread_start + 125
    frame #8: 0x00007ff8158a6f6b libsystem_pthread.dylib`thread_start + 15
  thread #15, name = 'Thread Pool Worker'
    frame #0: 0x00007ff8158700ea libsystem_kernel.dylib`__ulock_wait + 10
    frame #1: 0x00007ff8158bf27e libsystem_platform.dylib`_os_unfair_lock_lock_slow + 155
    frame #2: 0x00007ff81574646e libobjc.A.dylib`objc_sync_enter + 27
    frame #3: 0x000000011d808d89 libAvaloniaNative.dylib`AvnGlRenderTarget::BeginDrawing(IAvnGlSurfaceRenderingSession**) + 85
    frame #4: 0x0000000124b0f58a
    frame #5: 0x0000000124b0e9f2
[...]

Add any other context about the problem here.

@ylatuya ylatuya added the bug label Nov 15, 2022
@ylatuya
Copy link
Author

ylatuya commented Nov 15, 2022

This might be related: 84c04bc
cc: @kekekeks

@kekekeks
Copy link
Member

when a I launch a new modal dialog in a new window

Yes, #9376 fixes exactly that scenario. I don't see [AvnView updateLayer] in your stack traces though.

@ylatuya
Copy link
Author

ylatuya commented Nov 15, 2022

I am trying to test against 11.0.0-preview4, after migrating everything I now have a segfault in Avalonia's initialization:

(lldb) monobt
* thread #1
  * frame #0: 0x00007ff8555ad398 libc++abi.dylib`vtable for __cxxabiv1::__si_class_type_info + 16
    frame #1: 0x11c360ebb Avalonia.Native.AvaloniaNativePlatform:Initialize (intptr,Avalonia.AvaloniaNativePlatformOptions) [{0x1160e6728} + 0xcb]  (0x11c360df0 0x11c360ed0) [0x10100c350 - LongoMatch.exe]
    frame #2: 0x0000000100014352 mono`mono_jit_runtime_invoke(method=<unavailable>, obj=<unavailable>, params=0x0000000000000000, exc=<unavailable>, error=<unavailable>) at mini-runtime.c:3217:12 [opt]

I will try a rebuild from scratch just in case.

@ylatuya
Copy link
Author

ylatuya commented Nov 15, 2022

when a I launch a new modal dialog in a new window

Yes, #9376 fixes exactly that scenario. I don't see [AvnView updateLayer] in your stack traces though.

I have been able to rebuild Avalonia and test with the stable release. I can confirm that it's a different issue and that the original guess was correct. The deadlock happens with the following scenario:

  1. BeginDrawing starts in Thread 1 and takes the GL Context lock
  2. BeginDrawing finishes in Thread 1 the GL Context is still locked
  3. A Garbage Collection starts in Thread 1
  4. BeginDrawing starts in a ThreadPool thread

Thread 1 needs all threads to finish their pending operations and the thread that is performing the rendering operations needs the GL Context lock to be released.

2022-11-15 18:20:21.770876+0100 mono[21412:373812] BeginDrawing Locked <_NSMainThread: 0x100707ce0>{number = 1, name = main}
2022-11-15 18:20:21.770927+0100 mono[21412:373812] MakeCurrent Try Lock <_NSMainThread: 0x100707ce0>{number = 1, name = main}
2022-11-15 18:20:21.770947+0100 mono[21412:373812] MakeCurrent Locked <_NSMainThread: 0x100707ce0>{number = 1, name = main}
2022-11-15 18:20:21.771064+0100 mono[21412:373812] BeginDrawing Unlocked
2022-11-15 18:20:21.776280+0100 mono[21412:374147] BeginDrawing Locked <NSThread: 0x12216c170>{number = 18, name = (null)}
2022-11-15 18:20:21.776330+0100 mono[21412:374147] MakeCurrent Try Lock <NSThread: 0x12216c170>{number = 18, name = (null)}

Process 21412 stopped
* thread #1, name = 'tid_103', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
    frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
libsystem_kernel.dylib`semaphore_wait_trap:
->  0x7ff81586e9b6 <+10>: retq   
    0x7ff81586e9b7 <+11>: nop    

libsystem_kernel.dylib`semaphore_wait_signal_trap:
    0x7ff81586e9b8 <+0>:  movq   %rcx, %r10
    0x7ff81586e9bb <+3>:  movl   $0x1000025, %eax          ; imm = 0x1000025 
Target 0: (mono) stopped.
(lldb) bt all
* thread #1, name = 'tid_103', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007ff81586e9b6 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001002fdef9 mono`mono_os_sem_timedwait [inlined] mono_os_sem_wait at mono-os-semaphore.h:84:8 [opt]
    frame #2: 0x00000001002fdef0 mono`mono_os_sem_timedwait(sem=<unavailable>, timeout_ms=<unavailable>, flags=MONO_SEM_FLAGS_NONE) at mono-os-semaphore.h:103 [opt]
    frame #3: 0x00000001002fd9b5 mono`mono_threads_wait_pending_operations at mono-threads.c:319:8 [opt]
    frame #4: 0x000000010029d123 mono`sgen_client_stop_world at sgen-stw.c:306:3 [opt]
    frame #5: 0x000000010029d10f mono`sgen_client_stop_world(generation=0, serial_collection=0) at sgen-stw.c:124 [opt]
    frame #6: 0x00000001002b04e6 mono`sgen_stop_world(generation=0, serial_collection=0) at sgen-gc.c:3871:2 [opt]
    frame #7: 0x00000001002ad14d mono`sgen_perform_collection [inlined] sgen_perform_collection_inner at sgen-gc.c:2566:3 [opt]
    frame #8: 0x00000001002ad0e5 mono`sgen_perform_collection(requested_size=4096, generation_to_collect=0, reason="Nursery full", forced_serial=0, stw=1) at sgen-gc.c:2679 [opt]
    frame #9: 0x00000001002ad097 mono`sgen_ensure_free_space(size=4096, generation=<unavailable>) at sgen-gc.c:2545:2 [opt]
    frame #10: 0x00000001002a2d45 mono`sgen_alloc_obj_nolock(vtable=0x0000000121399e78, size=40) at sgen-alloc.c:279:6 [opt]
    frame #11: 0x00000001002a329e mono`sgen_alloc_obj(vtable=0x0000000121399e78, size=40) at sgen-alloc.c:454:8 [opt]
    frame #12: 0x000000010029ee0b mono`mono_gc_alloc_obj(vtable=<unavailable>, size=<unavailable>) at sgen-mono.c:921:20 [opt]
    frame #13: 0x00000001016df93e
    
  thread #23, name = 'Thread Pool Worker'
    frame #0: 0x00007ff815870bd2 libsystem_kernel.dylib`__psynch_mutexwait + 10
    frame #1: 0x00007ff8158a8e7e libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_wait + 76
    frame #2: 0x00007ff8158a6cbb libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_slow + 205
    frame #3: 0x00007ffa2d952d00 OpenGL`CGLLockContext + 34
    frame #4: 0x000000011d77c344 libAvaloniaNative.dylib`AvnGlContext::MakeCurrent(this=0x000000011d816ba0, ppv=0x00007000050b80c8) at cgl.mm:86:9 [opt]
    frame #5: 0x000000011d77b806 libAvaloniaNative.dylib`AvnGlRenderTarget::BeginDrawing(this=0x00000001221b4010, ret=0x00007000050b8118) at rendertarget.mm:307:34 [opt]
    frame #6: 0x0000000123232e6a
    frame #7: 0x00000001232322d2

@kekekeks
Copy link
Member

Try changing MONO_THREAD_SUSPEND environment variable to hybrid/coop/preemptive.

@ylatuya
Copy link
Author

ylatuya commented Nov 15, 2022

The issues does not reproduces with MONO_THREADS_SUSPEND=preemptive.

Is it possible that the AvnGlRenderingSession containing the SavedGlContext that holds the GL Context lock is hanging around and hasn't been explicitly disposed?

@kekekeks
Copy link
Member

kekekeks commented Nov 15, 2022

Holding a native lock in one managed thread while attempting to take it from another is completely normal and expected scenario. Mono seems to not expect it by default for some reason, so it's a Mono issue.

Since it's fixed by changing Mono's thread suspend mode I'm going to close the issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants