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

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

Open
praeclarum opened this issue Jan 22, 2020 · 22 comments
Assignees
Labels
bug If an issue is a bug or a pull request a bug fix macOS Issues affecting macOS
Milestone

Comments

@praeclarum
Copy link
Contributor

praeclarum commented Jan 22, 2020

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
Copy link
Contributor

chamons commented Jan 23, 2020

Possibly related to one of these?

mono/mono#10800
mono/mono#7981
mono/mono#6921

@praeclarum - Can you reproduce this at all?

@marek-safar - Thoughts?

@chamons chamons added bug If an issue is a bug or a pull request a bug fix macOS Issues affecting macOS need-info Waiting for more information before the bug can be investigated labels Jan 23, 2020
@chamons chamons added this to the Future milestone Jan 23, 2020
@praeclarum
Copy link
Contributor Author

@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
Copy link
Contributor Author

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

@marek-safar
Copy link
Contributor

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

@praeclarum
Copy link
Contributor Author

@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
Copy link
Contributor Author

praeclarum commented Jan 24, 2020

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
Copy link
Member

lambdageek commented Jan 24, 2020

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
  1. Wait for the app to crash. It will print Received SIGABRT, suspending... after it crashes. to stdout.log (in the log dir)
  2. start lldb and do attach nnnnn where nnnnn is the process id of the app
  3. 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
Copy link
Contributor Author

@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 chamons removed the need-info Waiting for more information before the bug can be investigated label Jan 29, 2020
@chamons
Copy link
Contributor

chamons commented Jan 29, 2020

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

@praeclarum
Copy link
Contributor Author

praeclarum commented Jan 29, 2020

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
Copy link
Member

lambdageek commented Feb 11, 2020

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
Copy link
Contributor Author

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
Copy link
Contributor Author

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

@chamons
Copy link
Contributor

chamons commented Mar 20, 2020

@lambdageek Was taking another stab today at reproducing.

@praeclarum
Copy link
Contributor Author

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

@lambdageek
Copy link
Member

lambdageek commented Mar 20, 2020

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
Copy link
Contributor Author

praeclarum commented Mar 23, 2020

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
Copy link
Member

lambdageek commented Mar 23, 2020

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
Copy link

DamianMehers commented Apr 4, 2020

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
Copy link

DamianMehers commented Apr 4, 2020

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

@CoffeeFlux CoffeeFlux self-assigned this Apr 4, 2020
@CoffeeFlux
Copy link

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
Copy link

DamianMehers commented Apr 5, 2020

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.

mono/mono#19372 (comment)

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.

4b94e30

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug If an issue is a bug or a pull request a bug fix macOS Issues affecting macOS
Projects
None yet
Development

No branches or pull requests

7 participants