xamarin / xamarin-macios

.NET for iOS, Mac Catalyst, macOS, and tvOS provide open-source bindings of the Apple SDKs for use with .NET managed languages such as C#
Other
2.49k stars 515 forks source link

mono_threads_state_poll_with_info crashes with error: Cannot transition thread from STATE_BLOCKING with STATE_POLL #7742

Open praeclarum opened 4 years ago

praeclarum commented 4 years ago

I ran into this error today while running on the latest macOS (10.15.2). I continually run into this error and wonder if anyone know what causes it and whether there is a way to recover. This error makes it impossible to debug since it just keeps crashing with these native exceptions.

2020-01-22 15:17:08.511 iCircuit2[1064:17218] error: Cannot transition thread 0x70000baae000 from STATE_BLOCKING with STATE_POLL

=================================================================
    Native Crash Reporting
=================================================================
Got a SIGABRT while executing native code. This usually indicates
a fatal error in the mono runtime or one of the native libraries 
used by your application.
=================================================================

=================================================================
    Native stacktrace:
=================================================================
    0x10e8c88f8 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_dump_native_crash_info
    0x10e8bc115 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_handle_native_crash
    0x10e8c7e6b - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : sigabrt_signal_handler
    0x7fff7074942d - /usr/lib/system/libsystem_platform.dylib : _sigtramp
    0x70000baab008 - Unknown
    0x7fff7061ea1c - /usr/lib/system/libsystem_c.dylib : abort
    0x10e7dbc60 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : _ZL12log_callbackPKcS0_S0_iPv
    0x10eb06e35 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : monoeg_g_logv_nofree
    0x10eb06ef2 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : monoeg_g_log
    0x10eaf7546 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_threads_transition_state_poll
    0x10eaf526a - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_threads_state_poll_with_info
    0x160efd623 - Unknown
    0x11c323db3 - Unknown
    0x15287470d - Unknown
    0x147c7eda7 - Unknown
    0x147c7e0aa - Unknown
    0x10e8d3167 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_jit_runtime_invoke
    0x10ea0ec47 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_runtime_invoke_checked
    0x10ea1358e - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_runtime_invoke
    0x10e7e5a62 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_invoke_trampoline
    0x10e7e6f5b - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_arch_trampoline
    0x10e7e8162 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_x86_64_common_trampoline
    0x7fff450e3a78 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _update:]
    0x7fff450e6482 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawSceneWithNewRenderer:]
    0x7fff450e6a41 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawScene:]
    0x7fff450e6f46 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawAtTime:]
    0x7fff450d3fc3 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNView _drawAtTime:WithContext:]
    0x7fff450d38ee - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNView SCN_displayLinkCallback:]
    0x7fff4506e25c - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : __69-[NSObject(SCN_DisplayLinkExtensions) SCN_setupDisplayLinkWithQueue:]_block_invoke
    0x7fff45160ad8 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : __36-[SCNDisplayLink _callbackWithTime:]_block_invoke.13

Steps to Reproduce

  1. Use SceneKit
  2. Implement code in the scene renderer update function

Expected Behavior

No crash

Actual Behavior

Above mono error.

Environment

=== Visual Studio Community 2019 for Mac ===

Version 8.4.2 (build 59)
Installation UUID: 4ba352e1-73e8-4dab-a9db-28012ca05af8
    GTK+ 2.24.23 (Raleigh theme)
    Xamarin.Mac 5.16.1.25 (issue-7441-d16-3-vsmac / 881172e73)

    Package version: 606000155

=== Mono Framework MDK ===

Runtime:
    Mono 6.6.0.155 (2019-08/296a9afdb24) (64-bit)
    Package version: 606000155

=== Roslyn (Language Service) ===

3.4.0-beta4-19562-05+ff930dec4565e2bc424ad3bf3e22ecb20542c87d

=== NuGet ===

Version: 5.3.0.6192

=== .NET Core SDK ===

SDK: /usr/local/share/dotnet/sdk/3.1.101/Sdks
SDK Versions:
    3.1.101
    3.0.100
    3.0.100-preview5-011568
    3.0.100-preview-009812
    2.2.203
    2.2.103
    2.1.302
    2.1.300-preview2-008530
    2.0.3
MSBuild SDKs: /Library/Frameworks/Mono.framework/Versions/6.6.0/lib/mono/msbuild/Current/bin/Sdks

=== .NET Core Runtime ===

Runtime: /usr/local/share/dotnet/dotnet
Runtime Versions:
    3.1.1
    3.0.0
    3.0.0-preview5-27626-15
    3.0.0-preview-27122-01
    2.2.4
    2.2.1
    2.1.15
    2.1.13
    2.1.2
    2.1.0-preview2-26406-04
    2.0.3

=== Xamarin.Profiler ===

Version: 1.6.12.26
Location: /Applications/Xamarin Profiler.app/Contents/MacOS/Xamarin Profiler

=== Updater ===

Version: 11

=== Apple Developer Tools ===

Xcode 11.3.1 (15715)
Build 11C504

=== Xamarin Designer ===

Version: 16.4.0.478
Hash: 95f0ab363
Branch: remotes/origin/d16-4
Build date: 2020-01-08 23:59:46 UTC

=== Xamarin.Mac ===

Version: 6.10.0.17 (Visual Studio Community)
Hash: 5f802ef53
Branch: xcode11.3
Build date: 2020-01-07 11:53:06-0500

=== Xamarin.iOS ===

Version: 13.10.0.17 (Visual Studio Community)
Hash: 5f802ef53
Branch: xcode11.3
Build date: 2020-01-07 11:53:06-0500

=== Xamarin.Android ===

Version: 10.1.3.7 (Visual Studio Community)
Commit: xamarin-android/d16-4/d66aed0
Android SDK: /Users/fak/Library/Developer/Xamarin/android-sdk-macosx
    Supported Android versions:
        4.4 (API level 19)
        7.0 (API level 24)
        7.1 (API level 25)
        8.1 (API level 27)

SDK Tools Version: 26.1.1
SDK Platform Tools Version: 26.0.2
SDK Build Tools Version: 26.0.3

Build Information: 
Mono: fd9f379
Java.Interop: xamarin/java.interop/d16-4@c4e569f
ProGuard: xamarin/proguard/master@905836d
SQLite: xamarin/sqlite/3.28.0@46204c4
Xamarin.Android Tools: xamarin/xamarin-android-tools/master@9f4ed4b

=== Microsoft Mobile OpenJDK ===

Java SDK: /Users/fak/Library/Developer/Xamarin/jdk/microsoft_dist_openjdk_8.0.25
1.8.0-25
Android Designer EPL code available here:
https://github.com/xamarin/AndroidDesigner.EPL

=== Android SDK Manager ===

Version: 16.4.0.9
Hash: 3f7256f
Branch: remotes/origin/d16-4
Build date: 2020-01-14 22:19:04 UTC

=== Android Device Manager ===

Version: 16.4.0.30
Hash: f9172e2
Branch: remotes/origin/d16-4
Build date: 2020-01-14 22:19:24 UTC

=== Xamarin Inspector ===

Version: 1.4.3
Hash: db27525
Branch: 1.4-release
Build date: Mon, 09 Jul 2018 21:20:18 GMT
Client compatibility: 1

=== Build Information ===

Release ID: 804020059
Git revision: eb6fcdd83a227678e487aa733df3c8745f54fafc
Build date: 2020-01-17 12:12:02+00
Build branch: release-8.4
Xamarin extensions: ec32c90978c94f03d72f507b01f5aee70952ce87

=== Operating System ===

Mac OS X 10.15.2
Darwin 19.2.0 Darwin Kernel Version 19.2.0
    Sat Nov  9 03:47:04 PST 2019
    root:xnu-6153.61.1~20/RELEASE_X86_64 x86_64

=== Enabled user installed extensions ===

MSBuild Editor 2.3.1

Build Logs

Build Log.txt

chamons commented 4 years ago

Possibly related to one of these?

https://github.com/mono/mono/issues/10800 https://github.com/mono/mono/issues/7981 https://github.com/mono/mono/issues/6921

@praeclarum - Can you reproduce this at all?

@marek-safar - Thoughts?

praeclarum commented 4 years ago

@chamons It's happened 3 times to me now. It's always in that callback from SceneKit - so it's at least somewhat reproducible. I don't have any strict steps yet though, will keep working on it.

I should also note that I didn't start getting this until upgrading macOS to 10.15.2, Xcode to 10.3 and whatever Xamarin Stable is right now - it has been stable for over a year prior. Unfortunately, I made all those changes at once so am not sure which one is the culprit.

praeclarum commented 4 years ago

@chamons It's becoming more and more common - still no repro steps other than use the app for awhile :-(

marek-safar commented 4 years ago

@lambdageek do we have any better way to debug this?

praeclarum commented 4 years ago

@chamons is there any way to get symbols for those mono methods? I tried to make an AOT build but still didn't get symbols.

Also, this may anecdotal at the moment, the crash has only happened with the debugger attached. I had 1 instance run all night without a crash.

praeclarum commented 4 years ago

Ah, it turns out that it's an assert triggering:

socket_transport_send Cannot transition thread 0x700009b66000 from STATE_BLOCKING with DO_BLOCKING
* Assertion at /Users/builder/jenkins/workspace/archive-mono/2019-08/mac/release/mono/metadata/threads.c:6455, condition `this_thread_controls == thread_given_control' not met

https://github.com/mono/mono/blob/fd9f379d294e8208a63dd3f63d104057180c9789/mono/metadata/threads.c#L6446-L6456

static gboolean
mono_threads_summarize_execute_internal (MonoContext *ctx, gchar **out, MonoStackHash *hashes, gboolean silent, gchar *working_mem, size_t provided_size, gboolean this_thread_controls)
{
    static SummarizerGlobalState state;

    int current_idx;
    MonoNativeThreadId current = mono_native_thread_id_get ();
    gboolean thread_given_control = summarizer_state_init (&state, current, &current_idx);

    g_assert (this_thread_controls == thread_given_control);
lambdageek commented 4 years ago

Not a super great way to debug, but you can try:

  1. Get monobt.py; save it in ~/monobt/monobt.py and edit ~/.lldbinit to add
      command script import ~/monobt/monobt.py
  2. Pass MONO_DEBUG=suspend-on-sigsegv to your app. For the SceneKit sample in VS, I do this from the command line
      MONO_DEBUG=suspend-on-sigsegv MONOMAC_LOGDIR=~/Projects/helloworld/ open helloworld.app
  3. Wait for the app to crash. It will print Received SIGABRT, suspending... after it crashes. to stdout.log (in the log dir)
  4. start lldb and do attach nnnnn where nnnnn is the process id of the app
  5. run the lldb command monobt to get a stack trace that includes managed frames.

When you're done, kill from lldb to close the app. (detaching from it is not useful, it's stuck in a busy loop in a signal handler)


I guess what I expect to see is that we're in some kind of wrapper calling from managed code to native code. Specifically we switched to GC Safe mode and we're about to call the actual native function, but now we called the GC polling function for some reason.


You can probably get the crash to happen more often if you start a background thread that just does something like this:

  while (true) {
    GC.Collect ();
    Thread.Sleep (200);
  }
praeclarum commented 4 years ago

@lambdageek Some good and bad news:

Your GC.Collect certainly does speed up the bug. It's basically 100% repro now (still can take a few seconds of playing though).

It seems to only repro with the debugger attached. :-( Without the debugger, it seems to run fine even with your GC.Collect.

So it's good that it doesn't repro outside the dev environment, but bad because I can't use the debugger.

chamons commented 4 years ago

We have a private sample and @lambdageek is going to take a look, so no more need-info.

praeclarum commented 4 years ago

FWIW, I just ran into the error on a totally different app (with a similar name :-)).

This time it was in OpenGL code from SkiaSharp.

I makes me wonder if the "Cannot transition thread from STATE_BLOCKING with STATE_POLL" is a red-herring and just occurs when there is a native crash.

=================================================================
    Native stacktrace:
=================================================================
    0x104df1888 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_dump_native_crash_info
    0x104de50a5 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_handle_native_crash
    0x105144e13 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : altstack_handle_and_restore.cold.1
    0x104d631fc - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : altstack_handle_and_restore
    0x1056db784 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MonoBundle/libSkiaSharp.dylib : gr_backendrendertarget_get_gl_framebufferinfo
    0x110247d26 - Unknown
    0x1102242d1 - Unknown
    0x104dfc0f7 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_jit_runtime_invoke
    0x104f37bd7 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_runtime_invoke_checked
    0x104f3c51e - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_runtime_invoke
    0x104d0e9f2 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : xamarin_invoke_trampoline
    0x104d0feeb - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : xamarin_arch_trampoline
    0x104d110f2 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : xamarin_x86_64_common_trampoline
    0x7fff3533105d - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : -[_NSOpenGLViewBackingLayer display]
    0x7fff432949f1 - /System/Library/Frameworks/QuartzCore.framework/Versions/A/QuartzCore : _ZN2CA5Layer17display_if_neededEPNS_11TransactionE
    0x7fff432733da - /System/Library/Frameworks/QuartzCore.framework/Versions/A/QuartzCore : _ZN2CA7Context18commit_transactionEPNS_11TransactionEd
    0x7fff43272002 - /System/Library/Frameworks/QuartzCore.framework/Versions/A/QuartzCore : _ZN2CA11Transaction6commitEv
    0x7fff34dd3e87 - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : __62+[CATransaction(NSCATransaction) NS_setFlushesWithDisplayLink]_block_invoke
    0x7fff354ef77d - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : ___NSRunLoopObserverCreateWithHandler_block_invoke
    0x7fff37a6c0ee - /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation : __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__
    0x7fff37a6c014 - /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation : __CFRunLoopDoObservers
    0x7fff37a6b70b - /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation : __CFRunLoopRun
    0x7fff37a6abd3 - /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation : CFRunLoopRunSpecific
    0x7fff365c165d - /System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox : RunCurrentEventLoopInMode
    0x7fff365c139d - /System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox : ReceiveNextEventCommon
    0x7fff365c1127 - /System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox : _BlockUntilNextEventMatchingListInModeWithFilter
    0x7fff34c32eb4 - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : _DPSNextEvent
    0x7fff34c31690 - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]
    0x7fff34c233ae - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : -[NSApplication run]
    0x7fff34bf5775 - /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit : NSApplicationMain
    0x10c3a457c - Unknown
    0x10c3a421b - Unknown
    0x104dfc0f7 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_jit_runtime_invoke
    0x104f37bd7 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_runtime_invoke_checked
    0x104f3efdc - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_runtime_exec_main_checked
    0x104d59422 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_jit_exec
    0x104d5c514 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : mono_main
    0x104d11aa8 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : xamarin_main
    0x104d12904 - /Users/fak/Dropbox/Projects/Circuit/CircuitMac/bin/Debug/iCircuit.app/Contents/MacOS/iCircuit : main
    0x7fff6f0c77fd - /usr/lib/system/libdyld.dylib : start
    0x2 - Unknown

=================================================================
    Telemetry Dumper:
=================================================================
Pkilling 0x700006ab1000 from 0x111dc3dc0
Pkilling 0x70000628a000 from 0x111dc3dc0
Pkilling 0x700006bb7000 from 0x111dc3dc0
Pkilling 0x70000661f000 from 0x111dc3dc0
Pkilling 0x700006b34000 from 0x111dc3dc0
Pkilling 0x700006087000 from 0x111dc3dc0
Entering thread summarizer pause from 0x111dc3dc0
Finished thread summarizer pause from 0x111dc3dc0.

Waiting for dumping threads to resume
socket_transport_send Cannot transition thread 0x111dc3dc0 from STATE_BLOCKING with DO_BLOCKING
lambdageek commented 4 years ago

makes me wonder if the "Cannot transition thread from STATE_BLOCKING with STATE_POLL" is a red-herring and just occurs when there is a native crash.

socket_transport_send Cannot transition thread 0x111dc3dc0 from STATE_BLOCKING with DO_BLOCKING

This is a different bug - in this case we collected a crash report on a thread that's in the middle of a pinvoke and then we try to call a debugger callback and thus in GC Safe mode and then we called the debugger callback to send an event over the debug protocol which tries to do another GC Safe transition.
I created a separate issue - mono/mono#18794 for it.

So in the above, the crash happens first, and then the bad state transition. In the original issue, the bad transition happens, and the runtime asserts/crashes.

praeclarum commented 4 years ago

Ah yeah that makes sense, thanks for the explanation. I was going to mention that the debugger keeps deadlocking but it seems you know already :-)

praeclarum commented 4 years ago

@lambdageek @chamons Any updates on this? Been a few months since I've been able to use the debugger...

chamons commented 4 years ago

@lambdageek Was taking another stab today at reproducing.

praeclarum commented 4 years ago

Cool, thanks! I've found that most OpenGL/Metal (not sure which) apps trigger it on Mac (with the debugger).

lambdageek commented 4 years ago

Sorry about that, this fell off my radar a bit.

I couldn't get the crash to happen with VS for Mac 8.5. (XM 6.14.1.39). Not sure if that means anything yet.

Got a stack trace from VS for Mac 8.4 (XM 6.10.0.21), relevant frames below (with identifying info stripped). Not sure how the debugger plays into it yet. The debugger thread is idle.

thread #10, name = 'tid_1400b', queue = 'com.apple.scenekit.renderingQueue.MySceneView0x7fe81a51eba0'
    ...
    frame #17: 0x000000010defbc60 App`log_callback(log_domain=0x0000000000000000, log_level="error", message="Cannot transition thread 0x7000027da000 from STATE_BLOCKING with STATE_POLL", fatal=4, user_data=0x0000000000000000) at runtime.m:1251:3
    frame #18: 0x000000010e226e35 App`monoeg_g_logv_nofree [inlined] monoeg_g_logstr(log_domain=0x0000000000000000, log_level=G_LOG_LEVEL_ERROR, msg=<unavailable>) at goutput.c:134:2 [opt]
    frame #19: 0x000000010e226e0c App`monoeg_g_logv_nofree(log_domain=0x0000000000000000, log_level=G_LOG_LEVEL_ERROR, format=<unavailable>, args=<unavailable>) at goutput.c:149 [opt]
    frame #20: 0x000000010e226ef2 App`monoeg_g_log [inlined] monoeg_g_logv(log_domain=<unavailable>, log_level=<unavailable>, format=<unavailable>, args=0x0000003000000028) at goutput.c:156:10 [opt]
    frame #21: 0x000000010e226eed App`monoeg_g_log(log_domain=<unavailable>, log_level=<unavailable>, format=<unavailable>) at goutput.c:165 [opt]
    frame #22: 0x000000010e217546 App`mono_threads_transition_state_poll(info=0x00007fe81b0f9600) at mono-threads-state-machine.c:394:3 [opt]
    frame #23: 0x000000010e21526a App`mono_threads_state_poll_with_info(info=0x00007fe81b0f9600) at mono-threads-coop.c:144:10 [opt]
  * frame #24: 0x13ab7f36e (wrapper managed-to-native) object:__icall_wrapper_mono_threads_state_poll () [{0x7fe81d0236e8} + 0x7e]  (0x13ab7f2f0 0x13ab7f40d) [0x7fe81a402ef0 - App.exe]
    frame #25: 0x113e77b53 string:memcpy (byte*,byte*,int) [{0x7fe81a8569c0} + 0x53]  (0x113e77b00 0x113e77bcb) [0x7fe81a402ef0 - App.exe]
    frame #26: 0x1175e0f4b (wrapper managed-to-native) ObjCRuntime.Messaging:void_objc_msgSend_SCNMatrix4 (intptr,intptr,SceneKit.SCNMatrix4) [{0x7fe81aa80b58} + 0x12b]  (0x1175e0e20 0x1175e1106) [0x7fe81a402ef0 - App.exe]
    frame #27: 0x1175e0c13 SceneKit.SCNNode:set_Transform (SceneKit.SCNMatrix4) [{0x7fe81c8d25d0} + 0x263] [/Library/Frameworks/Xamarin.Mac.framework/Versions/6.10.0.21/src/Xamarin.Mac/SCNNode.g.cs :: 2348u] (0x1175e09b0 0x1175e0e00) [0x7fe81a402ef0 - App.exe]
    frame #28: 0x15cbc354a ....Connection:UpdateAfterPhysics (...Element/UpdateInfo&) [{0x7fe81c874810} + 0x3caa] [.../Connection.cs :: 523u] (0x15cbbf8a0 0x15cbc3da4) [0x7fe81a402ef0 - App.exe]
...

So just taking this at face value, the call to the setter for SCNNode.Transform is where the bad things happen.

var x = new SCNMatrix4 (...)

nodes[i].Transform = x;

The setter ends up calling String:memcpy (byte*, byte*,int) which ends up doing a GC safepoint, but we're already in GC Safe mode. Which seems like an issue in the managed-to-native marshalling wrapper (doing the GC transition before calling the marshalling method). But:

  1. I can't find this call to memcpy
  2. I don't understand how the debugger is involved

it's difficult to reproduce in a smaller example because the GC actually needs to try and stop the world because that call to mono_threads_state_poll_with_info is usually not taken.

praeclarum commented 4 years ago

Thanks for the info that's very interesting.

I updated to 8.5, but get the same crash:

=================================================================
    Native stacktrace:
=================================================================
    0x100549968 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_dump_native_crash_info
    0x10053d325 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_handle_native_crash
    0x100548f7b - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : sigabrt_signal_handler
    0x7fff6b0c942d - /usr/lib/system/libsystem_platform.dylib : _sigtramp
    0x1009e1000 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : GCC_except_table2
    0x7fff6af9ea1c - /usr/lib/system/libsystem_c.dylib : abort
    0x10045bd70 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : _ZL12log_callbackPKcS0_S0_iPv
    0x10077b935 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : monoeg_g_logv_nofree
    0x10077b9f2 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : monoeg_g_log
    0x10076c036 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_threads_transition_state_poll
    0x100769d45 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_threads_state_poll_with_info
    0x10a5b7e1e - Unknown
    0x1063bcb63 - Unknown
    0x10a5fc9cb - Unknown
    0x10a5fc693 - Unknown
    0x110798825 - Unknown
    0x11025373f - Unknown
    0x110252a6a - Unknown
    0x100553e2e - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_jit_runtime_invoke
    0x100685f58 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_runtime_invoke_checked
    0x10068a8de - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : mono_runtime_invoke
    0x100465992 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_invoke_trampoline
    0x100466f5b - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_arch_trampoline
    0x100468186 - /Users/fak/Dropbox/Projects/Circuit2/CircuitMac/bin/Debug/iCircuit2.app/Contents/MacOS/iCircuit2 : xamarin_x86_64_common_trampoline
    0x7fff3fa1ba78 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _update:]
    0x7fff3fa1e482 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawSceneWithNewRenderer:]
    0x7fff3fa1ea41 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawScene:]
    0x7fff3fa1ef46 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNRenderer _drawAtTime:]
    0x7fff3fa0bfc3 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNView _drawAtTime:WithContext:]
    0x7fff3fa0b8ee - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNView SCN_displayLinkCallback:]
    0x7fff3f9a625c - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : __69-[NSObject(SCN_DisplayLinkExtensions) SCN_setupDisplayLinkWithQueue:]_block_invoke
    0x7fff3fa98ad8 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : __36-[SCNDisplayLink _callbackWithTime:]_block_invoke.13
    0x7fff6ae7750e - /usr/lib/system/libdispatch.dylib : _dispatch_client_callout
    0x7fff6ae83567 - /usr/lib/system/libdispatch.dylib : _dispatch_lane_barrier_sync_invoke_and_complete
    0x7fff3fa98a35 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : -[SCNDisplayLink _callbackWithTime:]
    0x7fff3fa98741 - /System/Library/Frameworks/SceneKit.framework/Versions/A/SceneKit : _cvDisplayLinkCallback
    0x7fff357c5d12 - /System/Library/Frameworks/CoreVideo.framework/Versions/A/CoreVideo : _ZN13CVDisplayLink9performIOEP11CVTimeStamp
    0x7fff357c5148 - /System/Library/Frameworks/CoreVideo.framework/Versions/A/CoreVideo : _ZN13CVDisplayLink11runIOThreadEv
    0x7fff6b0d4e65 - /usr/lib/system/libsystem_pthread.dylib : _pthread_start
    0x7fff6b0d083b - /usr/lib/system/libsystem_pthread.dylib : thread_start
lambdageek commented 4 years ago

Talked through this issue with @CoffeeFlux, and I have a guess for why this is only showing up when debugging.

The String.memcpy(byte*,byte*,int) call is from here https://github.com/mono/mono/blob/bf75db119979f074d85a22bb2bbb5e12ca0dc508/mono/mini/method-to-ir.c#L9907-L9918

We probably make different inlining decisions when we JIT this code with debugging on. Without debugging, since the size is known at JIT time, we probably unroll the loops in Buffer.Memcpy and don't insert a safepoint.


That said, the underlying issue is that the call to create a new array is in some marshalling code after we already switched to GC Safe mode, so we shouldn't be optimizing it to do a call to managed code.


Update:

Hm. Marshalling doesn't insert any calls to System.Runtime.CompilerServices.RuntimeHelpers::InitializeArray, so it's unclear how it would add the call to String.memcpy.

DamianMehers commented 4 years ago

I'm getting this error for a brand new WatchOS app .. it crashes on launch. I've not added any code to it, it is just what VS produces by default.

Release build, VS 8.5.1 (build 43), WatchOS 6.2 (17T529)

[Edit: Seems like this is a known issue: https://github.com/mono/mono/issues/19372 ]

These are the only messages produced by the app in the WatchOS console. It crashes immediately.

default 10:15:12.759032+0200    WatchGitWatchOSWatchOSExtension Xamarin.WatchOS: Skipping assembly registration for Xamarin.WatchOS since it's not needed (dynamic registration is not supported)
default 10:15:12.760153+0200    WatchGitWatchOSWatchOSExtension Xamarin.WatchOS: Skipping assembly registration for WatchGitWatchOSWatchOSExtension since it's not needed (dynamic registration is not supported)
default 10:15:12.760518+0200    WatchGitWatchOSWatchOSExtension error: mono_gc_pthread_create Cannot transition thread 0x76f13c0 from STATE_BLOCKING with DO_BLOCKING
DamianMehers commented 4 years ago

@praeclarum I don't know if this is related but a fix for the same error message was merged here

CoffeeFlux commented 4 years ago

The watchOS issue is separate – in both cases it's due to state transition issues, but in very different parts of the code.

Also, Aleksey is out for the next few weeks, so I'm taking a look at this.

DamianMehers commented 4 years ago

The watchOS issue is separate – in both cases it's due to state transition issues, but in very different parts of the code.

Also, Aleksey is out for the next few weeks, so I'm taking a look at this.

The WatchOS fix won't apply, but I thought perhaps the underlying issue might be the similar

it's most likely because mono_gc_init_finalizer_thread now needs a MONO_ENTER_GC_UNSAFE.

https://github.com/mono/mono/issues/19372#issuecomment-606173580

Starting with mono/mono#16907 , the Mono runtime ends in GC-Safe state (mode) after mono_jit_init_version() is called. The monotouch code did not expect that, and calls mono_gc_init_finalizer_thread() which also tries to enter GC-safe mode.

https://github.com/xamarin/xamarin-macios/commit/4b94e3073bbfb7ef3c7ad55f657b31a354369c64