dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.14k stars 4.71k forks source link

[Android] Arm32 Android running out of memory at PfxIterationCountTests_X509Certificate2 tests #105325

Open matouskozak opened 2 months ago

matouskozak commented 2 months ago

Build Information

Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=751577 Build error leg or test failing: System.Security.Cryptography.Tests Affected CI: android_arm_release_allsubsets_mono (runtime-extra-platforms) Range of commits: https://github.com/dotnet/runtime/compare/c5e8f83d...6effb8f6 (not 100% sure this is the correct range as the issue doesn't reproduce 100% of time)

Stack trace example:

07-23 03:23:15.682 25786 26432 I DOTNET  :    Test case: System.Security.Cryptography.X509Certificates.Tests.PfxIterationCountTests_X509Certificate2.ImportWithPasswordOrFileName_IterationCountLimitExceeded
07-23 03:23:17.104 25700 25747 I GMS_MM_Logger: Memory Metric Logging not allowed. Stopping.
07-23 03:23:27.102 25786 25801 I ptography.Test: Background young concurrent copying GC freed 462488(21MB) AllocSpace objects, 0(0B) LOS objects, 74% free, 6952KB/26MB, paused 27us total 173.749ms
07-23 03:23:29.203 25786 25801 I ptography.Test: Background concurrent copying GC freed 283213(10MB) AllocSpace objects, 0(0B) LOS objects, 75% free, 21MB/86MB, paused 56us total 583.682ms
07-23 03:23:29.951 31591 31640 I BistoHotwordHelper: (REDACTED) getHotwordActive::active query: %s, watch: %s, devices connected: %s
07-23 03:23:34.949 25786 25828 I ptography.Test: Waiting for a blocking GC ProfileSaver
07-23 03:23:35.695 25786 25801 I ptography.Test: Background young concurrent copying GC freed 555762(25MB) AllocSpace objects, 0(0B) LOS objects, 9% free, 78MB/86MB, paused 29us total 1.596s
07-23 03:23:35.695 25786 25828 I ptography.Test: WaitForGcToComplete blocked ProfileSaver on HeapTrim for 745.894ms
07-23 03:23:37.648 25786 25801 I ptography.Test: Background concurrent copying GC freed 1408538(42MB) AllocSpace objects, 0(0B) LOS objects, 61% free, 59MB/155MB, paused 38us total 1.376s
07-23 03:23:39.707   893   893 I android.hardware.health@2.1-service: Recording a sample at time 334204
07-23 03:23:39.708   893   893 E BatteryDefender: Failed to read /sys/class/power_supply/wireless/online
07-23 03:23:39.714   893   893 E BatteryDefender: Failed to read /sys/class/power_supply/wireless/online
07-23 03:23:39.720  2129  5772 D PowerUI : can't show warning due to - plugged: true status unknown: false
07-23 03:23:47.773 25786 25801 I ptography.Test: Background young concurrent copying GC freed 832473(38MB) AllocSpace objects, 0(0B) LOS objects, 7% free, 143MB/155MB, paused 87us total 2.584s
07-23 03:23:50.179 25786 25803 I scudo   : Scudo ERROR: out of memory trying to allocate 64 bytes
--------- beginning of crash
07-23 03:23:50.198 25786 25803 F libc    : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 25803 (FinalizerDaemon), pid 25786 (ptography.Tests)
07-23 03:23:50.199 25786 25814 W libc    : pthread_create failed: couldn't allocate 1052672-bytes mapped space: Out of memory
07-23 03:23:50.199 25786 25814 E libutils.threads: androidCreateRawThreadEtc failed (entry=0xf5be3905, res=11, Success)
07-23 03:23:50.199 25786 25814 E libutils.threads: (android threadPriority=0)
07-23 03:23:50.432 25786 25801 I ptography.Test: Background concurrent copying GC freed 3122319(90MB) AllocSpace objects, 0(0B) LOS objects, 54% free, 79MB/175MB, paused 142us total 1.750s
07-23 03:23:50.613 26436 26436 I crash_dump32: obtaining output fd from tombstoned, type: kDebuggerdTombstone
07-23 03:23:50.628   855   855 I tombstoned: received crash request for pid 25803
07-23 03:23:50.629 26436 26436 I crash_dump32: performing dump of process 25786 (target tid = 25803)
07-23 03:23:50.654 26436 26436 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
07-23 03:23:50.654 26436 26436 F DEBUG   : Build fingerprint: 'google/sunfish/sunfish:11/RP1A.200720.011/6746289:user/release-keys'
07-23 03:23:50.654 26436 26436 F DEBUG   : Revision: 'MP1.0'
07-23 03:23:50.654 26436 26436 F DEBUG   : ABI: 'arm'
07-23 03:23:50.655 26436 26436 F DEBUG   : Timestamp: 2024-07-23 03:23:50-0700
07-23 03:23:50.655 26436 26436 F DEBUG   : pid: 25786, tid: 25803, name: FinalizerDaemon  >>> net.dot.System.Security.Cryptography.Tests <<<
07-23 03:23:50.655 26436 26436 F DEBUG   : uid: 18687
07-23 03:23:50.655 26436 26436 F DEBUG   : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
07-23 03:23:50.655 26436 26436 F DEBUG   : Abort message: 'Scudo ERROR: out of memory trying to allocate 64 bytes
07-23 03:23:50.655 26436 26436 F DEBUG   : '
07-23 03:23:50.655 26436 26436 F DEBUG   :     r0  00000000  r1  000064cb  r2  00000006  r3  ca096708
07-23 03:23:50.655 26436 26436 F DEBUG   :     r4  ca09671c  r5  ca096700  r6  000064ba  r7  0000016b
07-23 03:23:50.655 26436 26436 F DEBUG   :     r8  ca096708  r9  ca096718  r10 ca096738  r11 ca096728
07-23 03:23:50.655 26436 26436 F DEBUG   :     ip  000064cb  sp  ca0966d8  lr  f56503e1  pc  f56503f4
07-23 03:23:51.146 26436 26436 F DEBUG   : backtrace:
07-23 03:23:51.146 26436 26436 F DEBUG   :       #00 pc 000383f4  /apex/com.android.runtime/lib/bionic/libc.so (abort+172) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.146 26436 26436 F DEBUG   :       #01 pc 0002e46b  /apex/com.android.runtime/lib/bionic/libc.so (scudo::die()+2) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.146 26436 26436 F DEBUG   :       #02 pc 0002e859  /apex/com.android.runtime/lib/bionic/libc.so (scudo::ScopedErrorReport::~ScopedErrorReport()+16) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.146 26436 26436 F DEBUG   :       #03 pc 0002e997  /apex/com.android.runtime/lib/bionic/libc.so (scudo::reportOutOfMemory(unsigned long)+34) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #04 pc 00031023  /apex/com.android.runtime/lib/bionic/libc.so (scudo::SizeClassAllocatorLocalCache<scudo::SizeClassAllocator32<scudo::TableSizeClassMap<scudo::AndroidSizeClassConfig>, 18ul, 1000, 1000> >::drain(scudo::SizeClassAllocatorLocalCache<scudo::SizeClassAllocator32<scudo::TableSizeClassMap<scudo::AndroidSizeClassConfig>, 18ul, 1000, 1000> >::PerClass*, unsigned long)+218) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #05 pc 000318cd  /apex/com.android.runtime/lib/bionic/libc.so (scudo::Allocator<scudo::AndroidConfig, &(scudo_malloc_postinit)>::quarantineOrDeallocateChunk(void*, scudo::Chunk::UnpackedHeader*, unsigned long)+412) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #06 pc 0002f66f  /apex/com.android.runtime/lib/bionic/libc.so (scudo::Allocator<scudo::AndroidConfig, &(scudo_malloc_postinit)>::deallocate(void*, scudo::Chunk::Origin, unsigned long, unsigned long)+166) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #07 pc 0002f5bb  /apex/com.android.runtime/lib/bionic/libc.so (scudo_free+18) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #08 pc 0009b34f  /apex/com.android.conscrypt/lib/libcrypto.so (HMAC_CTX_cleanup+10) (BuildId: 1238bd7e0151aef96193423650016c5b)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #09 pc 0001daf7  /apex/com.android.conscrypt/lib/libjavacrypto.so (NativeCrypto_HMAC_CTX_free(_JNIEnv*, _jclass*, long long)+38) (BuildId: 27367302542dcfb47396a2c65f69a288)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #10 pc 02024707  /memfd:jit-cache (deleted) (offset 0x2000000) (art_jni_trampoline+102)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #11 pc 02010b23  /memfd:jit-cache (deleted) (offset 0x2000000) (com.android.org.conscrypt.NativeRef$HMAC_CTX.doFree+42)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #12 pc 02004dcf  /memfd:jit-cache (deleted) (offset 0x2000000) (com.android.org.conscrypt.NativeRef.finalize+54)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #13 pc 0200652d  /memfd:jit-cache (deleted) (offset 0x2000000) (java.lang.Daemons$FinalizerDaemon.doFinalize+92)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #14 pc 02004feb  /memfd:jit-cache (deleted) (offset 0x2000000) (java.lang.Daemons$FinalizerDaemon.runInternal+450)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #15 pc 000d362f  /apex/com.android.art/lib/libart.so (art_quick_osr_stub+46) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #16 pc 0025d7e7  /apex/com.android.art/lib/libart.so (art::jit::Jit::MaybeDoOnStackReplacement(art::Thread*, art::ArtMethod*, unsigned int, int, art::JValue*)+286) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #17 pc 004ec50f  /apex/com.android.art/lib/libart.so (MterpMaybeDoOnStackReplacement+130) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.147 26436 26436 F DEBUG   :       #18 pc 000d2bf4  /apex/com.android.art/lib/libart.so (MterpHelpers+244) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #19 pc 0002cfca  /apex/com.android.art/javalib/core-libart.jar (java.lang.Daemons$FinalizerDaemon.runInternal+178)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #20 pc 004e0881  /apex/com.android.art/lib/libart.so (MterpInvokeVirtual+1276) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #21 pc 000ce014  /apex/com.android.art/lib/libart.so (mterp_op_invoke_virtual+20) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #22 pc 0002ccc2  /apex/com.android.art/javalib/core-libart.jar (java.lang.Daemons$Daemon.run+50)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #23 pc 004e1f49  /apex/com.android.art/lib/libart.so (MterpInvokeInterface+1548) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #24 pc 000ce214  /apex/com.android.art/lib/libart.so (mterp_op_invoke_interface+20) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #25 pc 000eb7d0  /apex/com.android.art/javalib/core-oj.jar (java.lang.Thread.run+8)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #26 pc 0023142b  /apex/com.android.art/lib/libart.so (art::interpreter::Execute(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame&, art::JValue, bool, bool) (.llvm.2939591179090543404)+254) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #27 pc 00237c3d  /apex/com.android.art/lib/libart.so (art::interpreter::EnterInterpreterFromEntryPoint(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*)+120) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #28 pc 004d1d9b  /apex/com.android.art/lib/libart.so (artQuickToInterpreterBridge+686) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #29 pc 000d8161  /apex/com.android.art/lib/libart.so (art_quick_to_interpreter_bridge+32) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #30 pc 000d35d5  /apex/com.android.art/lib/libart.so (art_quick_invoke_stub_internal+68) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #31 pc 004ef1a7  /apex/com.android.art/lib/libart.so (art_quick_invoke_stub+282) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #32 pc 0012c681  /apex/com.android.art/lib/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+148) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #33 pc 003fbb3f  /apex/com.android.art/lib/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValues<art::ArtMethod*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, art::ArtMethod*, jvalue const*)+374) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #34 pc 003fbc4f  /apex/com.android.art/lib/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValues<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, jvalue const*)+42) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #35 pc 0043d37d  /apex/com.android.art/lib/libart.so (art::Thread::CreateCallback(void*)+1068) (BuildId: ff1ad245b994a97d59c926d97e9a909e)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #36 pc 0008061f  /apex/com.android.runtime/lib/bionic/libc.so (__pthread_start(void*)+40) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)
07-23 03:23:51.148 26436 26436 F DEBUG   :       #37 pc 00039905  /apex/com.android.runtime/lib/bionic/libc.so (__start_thread+30) (BuildId: 09f5dc86ced902a66ebda24ea42c217d)

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "Scudo ERROR: out of memory trying to allocate 64 bytes",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: :mag_right: https://dev.azure.com/dnceng-public/public/_build/results?buildId=751577 Error message validated: [Scudo ERROR: out of memory trying to allocate 64 bytes] Result validation: :x: Known issue did not match with the provided build. Validation performed at: 7/25/2024 6:27:11 AM UTC

Report

Summary

24-Hour Hit Count 7-Day Hit Count 1-Month Count
0 0 0
dotnet-policy-service[bot] commented 2 months ago

Tagging subscribers to 'arch-android': @vitek-karas, @simonrozsival, @steveisok, @akoeplinger See info in area-owners.md if you want to be subscribed.

dotnet-policy-service[bot] commented 2 months ago

Tagging subscribers to this area: @dotnet/area-system-security, @bartonjs, @vcsjones See info in area-owners.md if you want to be subscribed.

matouskozak commented 2 months ago

Could the out-of-memory issue be introduced by https://github.com/dotnet/runtime/pull/102167, causing that the imports are allocating more memory than the previous version @bartonjs ? Or it is possible that Mono is leaking memory somewhere and this change made it more prelevant...

bartonjs commented 2 months ago

The replacement loader changes the allocation pattern, which might affect what the peak is... but I don't have hard data here, so I can't authoritatively say. It shouldn't be anything with lasting effect.

akoeplinger commented 2 months ago

I'd just disable this test on 32bit, we already do this for other tests with [ConditionalFact(typeof(PlatformDetection), nameof(PlatformDetection.Is64BitProcess))].