Repository navigation
Crashes on startup significantly increased after migration to .NET6 #7335
Description
Activity
@tipa unfortunately, the log fragments don't include enough information. We can see that it's a failed assertion, most likely int he runtime, but we can't see where it happens and what's the
actual message. We will need a more detailed logcat output, alas. On the devices where you can reproduce the issue, could you make sure these commands are ran:$ adb shell setprop debug.mono.log default,assembly,mono_log_level=debug,mono_log_mask=all $ adb logcat -G 16M $ adb logcat -c # Run the app here and when it crashes, invoke $ adb logcat -d > log.txt
@grendello thanks for the info on how to produced more detailed output. The log.txt contained this part:
--------- beginning of crash 09-06 10:41:36.004 3269 3975 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 3975 (.NET ThreadPool), pid 3269 (partl.Diarium) 09-06 10:41:36.015 3269 3977 E : AOT Runtime could not load method due to Method not found: !!0 System.Text.Json.JsonSerializer.Deserialize<!0>(System.ReadOnlySpan`1<byte>,System.Text.Json.JsonSerializerOptions) Due to: Signature claims method has generic parameters, but generic_params table says it doesn't for method 0x00000332 from image System.Text.Json.dll 09-06 10:41:36.016 1548 1548 V SettingsProvider: Notifying for 0: content://settings/system/rading_mode_status_auto 09-06 10:41:36.017 2634 14535 I OIMC : notified , mode ColorReadMode changeTo 2 09-06 10:41:36.017 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@7d43ca6 09-06 10:41:36.017 2634 2681 I OIMC_CORE: The mode: ColorReadMode is not entered 09-06 10:41:36.018 2634 14535 I OIMC : notified , mode ReadMode changeTo 2 09-06 10:41:36.018 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@e3c96e7 09-06 10:41:36.018 2634 2681 I OIMC_CORE: The mode: ReadMode is not entered 09-06 10:41:36.018 1548 1548 V SettingsProvider: Notifying for 0: content://settings/system/rading_mode_status_auto 09-06 10:41:36.044 3981 3981 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone 09-06 10:41:36.044 1250 1250 I /system/bin/tombstoned: received crash request for pid 3975 09-06 10:41:36.045 3981 3981 I crash_dump64: performing dump of process 3269 (target tid = 3975) 09-06 10:41:36.053 3981 3981 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** 09-06 10:41:36.053 3981 3981 F DEBUG : Build fingerprint: 'OnePlus/OnePlus5/OnePlus5:10/QKQ1.191014.012/2010292059:user/release-keys' 09-06 10:41:36.053 3981 3981 F DEBUG : Revision: '0' 09-06 10:41:36.053 3981 3981 F DEBUG : ABI: 'arm64' 09-06 10:41:36.054 3981 3981 F DEBUG : Timestamp: 2022-09-06 10:41:36+0200 09-06 10:41:36.054 3981 3981 F DEBUG : pid: 3269, tid: 3975, name: .NET ThreadPool >>> partl.Diarium <<< 09-06 10:41:36.054 3981 3981 F DEBUG : uid: 10766 09-06 10:41:36.054 3981 3981 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr -------- 09-06 10:41:36.054 3981 3981 F DEBUG : x0 0000000000000000 x1 0000000000000f87 x2 0000000000000006 x3 00000072ef530250 09-06 10:41:36.054 3981 3981 F DEBUG : x4 0080000000000000 x5 0080000000000000 x6 0080000000000000 x7 0000000000008000 09-06 10:41:36.054 3981 3981 F DEBUG : x8 00000000000000f0 x9 608d0c77eedf1b8d x10 0000000000000001 x11 0000000000000000 09-06 10:41:36.054 3981 3981 F DEBUG : x12 fffffff0fffffbdf x13 0000000000000030 x14 ffffffffffffffff x15 0000c8b7ded40c7a 09-06 10:41:36.054 3981 3981 F DEBUG : x16 00000073ea2098c0 x17 00000073ea1e5900 x18 00000072ef002000 x19 0000000000000cc5 09-06 10:41:36.054 3981 3981 F DEBUG : x20 0000000000000f87 x21 00000000ffffffff x22 00000072fa2dea6c x23 00000072f9f10000 09-06 10:41:36.054 3981 3981 F DEBUG : x24 00000073ed8a8640 x25 00000072fa3ab240 x26 0000000000000001 x27 00000072fa2b35b8 09-06 10:41:36.054 3981 3981 F DEBUG : x28 0000000000000028 x29 00000072ef5302f0 09-06 10:41:36.054 3981 3981 F DEBUG : sp 00000072ef530230 lr 00000073ea1970c4 pc 00000073ea1970f0 09-06 10:41:36.131 595 595 I hwservicemanager: getTransport: Cannot find entry [email protected]::IIop/default in either framework or device manifest. 09-06 10:41:36.131 1055 30963 E ANDR-IOP: IIop:: Iop HAL Service is not available. 09-06 10:41:36.143 3981 3981 F DEBUG : 09-06 10:41:36.143 3981 3981 F DEBUG : backtrace: 09-06 10:41:36.143 3981 3981 F DEBUG : #00 pc 00000000000830f0 /apex/com.android.runtime/lib64/bionic/libc.so (abort+160) (BuildId: e55e6e4c631509598633769798683023) 09-06 10:41:36.143 3981 3981 F DEBUG : #01 pc 0000000000029b1c /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmono-android.release.so (offset 0xb37000) (xamarin::android::internal::MonodroidRuntime::mono_log_handler(char const*, char const*, char const*, int, void*)+144) (BuildId: 29c5a3805a0bedee1eede9b6668d7c676aa63371) 09-06 10:41:36.143 3981 3981 F DEBUG : #02 pc 00000000002680bc /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.143 3981 3981 F DEBUG : #03 pc 0000000000268144 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.143 3981 3981 F DEBUG : #04 pc 00000000001dc9e0 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.143 3981 3981 F DEBUG : #05 pc 00000000001dfc88 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.143 3981 3981 F DEBUG : #06 pc 00000000001dab24 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #07 pc 00000000001dbe64 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #08 pc 00000000001db500 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #09 pc 0000000000162e24 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #10 pc 0000000000162ae4 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #11 pc 00000000001edf78 /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #12 pc 00000000001eda9c /data/app/partl.Diarium-p2XRiJL6KmXM75MHlE41hQ==/split_config.arm64_v8a.apk!libmonosgen-2.0.so (offset 0xb95000) (BuildId: 4a5dd4396e8816b7f69881838bd549285213d53b) 09-06 10:41:36.144 3981 3981 F DEBUG : #13 pc 00000000000042f8 <anonymous:734c588000>Appears to be some problem with AOT and System.Text.Json
Running it again produces a similar but different stack trace:
09-06 10:54:18.553 11416 12275 E : AOT Runtime could not load method due to Could not load file or assembly 'System.Private.CoreLib, Version=6.0.0.0, Culture=£D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010, PublicKeyToken=7cec85d7bea7798e' or one of its dependencies. --------- beginning of crash 09-06 10:54:18.554 11416 12275 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 12275 (.NET ThreadPool), pid 11416 (partl.Diarium) 09-06 10:54:18.575 1548 1548 V SettingsProvider: Notifying for 0: content://settings/system/rading_mode_status_auto 09-06 10:54:18.576 2634 14535 I OIMC : notified , mode ColorReadMode changeTo 2 09-06 10:54:18.577 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@7239afe 09-06 10:54:18.577 2634 2681 I OIMC_CORE: The mode: ColorReadMode is not entered 09-06 10:54:18.577 2634 14535 I OIMC : notified , mode ReadMode changeTo 2 09-06 10:54:18.578 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@1d6925f 09-06 10:54:18.578 2634 2681 I OIMC_CORE: The mode: ReadMode is not entered 09-06 10:54:18.578 11416 12274 E : AOT Runtime could not load method due to Could not resolve type with token 01000150 from typeref (expected class 'System.Text.Json.JsonSerializerOptions' in assembly 'System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51') assembly:System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 type:System.Text.Json.JsonSerializerOptions member:(null)Edit: Another few tests and it shows this now:
2022-09-06 10:59:01.206 14770-15174/? E/: AOT Runtime could not load method due to Could not resolve type with token 01000366 from typeref (expected class 'System.Text.Json.JsonSerializer' in assembly 'System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51') assembly:System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 type:System.Text.Json.JsonSerializer member:(null)So all somehow related to
System.Text.Json.
Is there any quick fix I can do to prevent these crashes? I am currently using profiled AOT with a custom AOT profile.AndroidLinkModeis set toFull@tipa in your log I spotted this weird thing:
09-06 10:54:18.553 11416 12275 W monodroid-assembly: Assembly '£D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010/System.Private.CoreLib' (hash 0xdb08fc0a5fd4f2ea) not found 09-06 10:54:18.553 11416 12275 W monodroid-assembly: open_from_bundles: failed to load assembly £D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010/System.Private.CoreLib 09-06 10:54:18.553 11416 12275 W monodroid-assembly: Assembly '£D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010/System.Private.CoreLib' (hash 0xdb08fc0a5fd4f2ea) not found 09-06 10:54:18.553 11416 12275 W monodroid-assembly: open_from_bundles: failed to load assembly £D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010/System.Private.CoreLib 09-06 10:54:18.553 11416 12275 E : AOT Runtime could not load method due to Could not load file or assembly 'System.Private.CoreLib, Version=6.0.0.0, Culture=£D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010, PublicKeyToken=7cec85d7bea7798e' or one o f its dependencies.Note the assembly name:
£D0067CAD9A63E0813759A2BB841051CA73570C0DA2E08E840A8EB45DB6A7A010/System.Private.CoreLib- the part before/should not be there. The runtime fails to load it because I doubt we saw this kind of
name at the build time when we process assemblies. Would you be able to come up with a small repro for this issue? I'd need to examine the generated code.Edit: the part before
/is normally treated as culture name, which it definitely is not what it is in this instance@tipa also, would you be able to find full log output of this crash? This is likely a failed assertion or
abort()as well, but I'd like to see the message (which should be somewhere above theSIGABRTline)Not sure what part exactly I should include in a small repro...
Are you sure the problem is caused by the line withSystem.Private.CoreLib? In my other crashes there is no mention of this, e.g. here:09-06 10:59:00.942 14770 14770 W monodroid-gc: GREF GC Threshold: 46080 09-06 10:59:01.009 14770 14770 V Font : Change font:1 09-06 10:59:01.009 14770 14770 V Font : Default family:android.graphics.Typeface@91f6875e 09-06 10:59:01.094 3120 3334 D MainServiceImplHandler: : handleMessage msg.what = 1002 09-06 10:59:01.095 3120 3334 D MainServiceImplHandler: : EVENT_STATE_INIT 09-06 10:59:01.138 1548 1587 W AlarmManager: Unrecognized alarm listener com.android.server.b@f9a8816 09-06 10:59:01.139 2636 2636 D KeyguardUpdateMonitor: received broadcast android.intent.action.BATTERY_CHANGED 09-06 10:59:01.189 14770 15171 E : AOT Runtime could not load method due to Could not resolve type with token 01000366 from typeref (expected class 'System.Text.Json.JsonSerializer' in assembly 'System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51') assembly:System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 type:System.Text.Json.JsonSerializer member:(null) --------- beginning of crash 09-06 10:59:01.190 14770 15171 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 15171 (.NET ThreadPool), pid 14770 (partl.Diarium) 09-06 10:59:01.206 14770 15174 E : AOT Runtime could not load method due to Could not resolve type with token 01000366 from typeref (expected class 'System.Text.Json.JsonSerializer' in assembly 'System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51') assembly:System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 type:System.Text.Json.JsonSerializer member:(null) 09-06 10:59:01.215 1548 1548 V SettingsProvider: Notifying for 0: content://settings/system/rading_mode_status_auto 09-06 10:59:01.216 2634 2691 I OIMC : notified , mode ColorReadMode changeTo 2 09-06 10:59:01.216 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@a902d36 09-06 10:59:01.216 2634 2681 I OIMC_CORE: The mode: ColorReadMode is not entered 09-06 10:59:01.216 2634 2691 I OIMC : notified , mode ReadMode changeTo 2 09-06 10:59:01.216 2634 2681 I OIMC_CORE: handleMessage: MODE_EXIT, arg1: 0, arg2: 0, obj: com.oneplus.server.oimc.gwy@aede437 09-06 10:59:01.216 2634 2681 I OIMC_CORE: The mode: ReadMode is not entered 09-06 10:59:01.217 1548 1548 V SettingsProvider: Notifying for 0: content://settings/system/rading_mode_status_auto 09-06 10:59:01.227 15178 15178 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone 09-06 10:59:01.228 1250 1250 I /system/bin/tombstoned: received crash request for pid 15171 09-06 10:59:01.229 15178 15178 I crash_dump64@tipa also, would you be able to find full log output of this crash? This is likely a failed assertion or
abort()as well, but I'd like to see the message (which should be somewhere above theSIGABRTline)I don't have the full output of that particular crash any more, but as I am now able to reproduce it faster, I did another log:
log.txtNot sure what part exactly I should include in a small repro... Are you sure the problem is caused by the line with
System.Private.CoreLib? In my other crashes there is no mention of this, e.g. here:As sure as I can be without seeing the app source (or at least its
obj/build directory) - the "culture" name is definitely invalid and I doubt it was this particular string at the build time. Something's broken there.09-06 10:59:01.189 14770 15171 E : AOT Runtime could not load method due to Could not resolve type with token 01000366 from typeref (expected class 'System.Text.Json.JsonSerializer' in assembly 'System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51') assembly:System.Text.Json, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 type:System.Text.Json.JsonSerializer member:(null)The above line and another one:
09-06 11:15:06.831 16500 17035 E : AOT Runtime could not load method due to Method not found: !!0 System.Text.Json.JsonSerializer.Deserialize<!0>(string,System.Text.Json.JsonSerializerOptions)suggest that it's a problem with the linker, it is probably linking out too much. You might try turning off linking completely, just to see if the app works then.
40 remaining items
- added a commit that references this issue
on Jan 23, 2023 PR #7732 fixes the issue for me. I ran the test app provided by @tipa 5000 times in quick succession (on Pixel 6 Pro) without any SIGABRT being signaled.
Before that fix lands, you might work around it by disabling assembly compression (set the
AndroidEnableAssemblyCompressionMSBuild property toFalse)Commit d236af5 introduced embedded assembly compression,
using the lz4 algorithm, which speeds up startup and reduces final package size.Assemblies are compressed at build time and, at the same time, pre-allocated buffers for
the decompressed data are allocated inlibxamarin-app.so. The buffers are then passed
to the LZ4 APIs, all threads using the same output buffer. The assumption was that we can
do fine without locking as even if overlapped decompression happens, the output data will be
the same and so even if two threads do the same thing at the same time, the data will be valid
at all times, so long as at least one thread completes the decompression.This assumption proved to be largely true, but it appears that in high concurrency cases it
is possible that the data in decompression buffer differs. My guess is that LZ4 either uses the
output buffer as a scratchpad area when decompressing or that it initializes/modifies the buffer
before writing actual data in it. With overlapped decompression, it may lead to one thread
overwriting valid data previously written by another thread, so that when the latter returns the
buffer it thought to have had valid data may contain certain bytes temporarily overwritten by the
decompression session in the other, still running, thread. It may happen that MonoVM reads the
corrupted data just when it is still invalid (before the still running decompression session actually
writes the valid data), a classic race condition.To fix this, the decompression block is now protected with a startup-aware mutex. Mutex will be held
only after the initial startup phase is completed, so there should not be much loss of startup
performance.Reacted by George Josh KarabinReacted by Timo Partl, Yunus Efendi and tranb3r- added 5 commits that reference this issue
on Jan 26, 2023 - added a commit that references this issue
on Feb 21, 2023 - ghost locked as resolved and limited conversation to collaborators
on Feb 26, 2023 - added a commit that references this issue
on Feb 27, 2023
Android application type
Android for .NET (net6.0-android, etc.)
Affected platform version
VS 2022 17.3
Description
After I ported my Xamarin app to .NET6 and publishing it to the store, I noticed a significant increase in startup crashes reported in the Play Store developer console:
I have also experienced these crashes locally on my own devices, e.g. when launching the app repeatedly while profiling using this script.
The crash seems to appear randomly, that means it can crash even when it previously launched successfully and the app will launch successfully even after the crash happened.
This is the logcat output of when the crash happened locally on my own device:
I also found it weird that when I ported multiple of my apps to .NET6, first only one app was affected by this increased crash rate.
Later on I pushed an update to an app that was not affected previously and it then started to show the same problem and the crashes jumped significantly. So maybe the process how the app bundle was built has some influence on this. I use both the stable as well as the Preview version of VS 22 and create the app bundle using the IDE and the "Archive..." menu button
Steps to Reproduce
Unfortunately I have no way to reliably reproduce this crash, but when automating app launches and launching the app many times (e.g. using this) I can occasionally see the crash in the logcat output.