android-test
android-test copied to clipboard
Seemingly random 'process crashed' for the instrumentation runner
Description
What appears to randomly process crashes of the test runner. I understand this may not be the best example on how to present the issue (without the full code), but I was unable to reproduce this on a fresh project :(
Steps to Reproduce
In our app, the test is really simple. When I run it from the IDE it runs almost 100% correctly, from command line via
./gradlew connectedProductionDebugAndroidTest -i
it often fails with the error provided below.
class MyTest {
private val mockViewModel = mockk<FeedViewModel>(relaxed = true, relaxUnitFun = true)
@get:Rule
val mockInjectionRule = MockInjectionRule {
every { it.myViewModel() } returns mockViewModel
every { mockViewModel.shouldDoSomething() } returns false
}
@Test
fun myFragment_titleDisplays() {
launchFragmentInContainer(themeResId = R.style.AppTheme) { MyFragment() }
onView(withText(R.string.title))
.check(ViewAssertions.matches(isDisplayed()))
.check(matches(withParent(withId(R.id.toolbar))))
onView(withId(R.id.action_settings))
.check(matches(isDisplayed()))
}
}
Expected Results
Tests run/pass
Actual Results
Tests pass on average 7/10 times, when they fail, this is logged in Logcat
ActivityManager I Start proc 23437:com.android.chrome:sandboxed_process0/u0i50 for webview_service Ïd
ebug/org.chromium.content.app.SandboxedProcessService0
W Slow operation: 57ms so far, now at startProcess: starting to update pids map
W Slow operation: 57ms so far, now at startProcess: done updating pids map
dboxed_process W Unexpected CPU variant for X86 using defaults: x86
ercentral.debu I Background concurrent copying GC freed 161195(5MB) AllocSpace objects, 5(88KB) LOS objects, 36% free, 10MB/1
6MB, paused 1.468ms total 178.354ms
ActivityManager W Slow operation: 70ms so far, now at attachApplicationLocked: after mServices.attachApplicationLocked
cr_ChildProcessService I Creating new ChildProcessService pid=23437
ActivityManager I Process com.examplepackage.debug (pid 23395) has died: fore TOP
Zygote I Process 23395 exited due to signal (11)
InputDispatcher W channel '81514ff com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$EmptyFragmen
tActivity (server)' ~ Consumer closed input channel or an error occurred. events=0x9
E channel '81514ff com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$EmptyFragmen
tActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
libprocessgroup W kill(-23395, 9) failed: No such process
I Successfully killed process cgroup uid 10097 pid 23395 in 4ms
cr_ChildProcessService I Destroying ChildProcessService pid=23437
WindowManager I WIN DEATH: Window{81514ff u0 com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$
EmptyFragmentActivity}
D HostConnection::get() New Host Connection established 0xe9c0a840, tid 1973
InputDispatcher W Attempted to unregister already unregistered input channel '81514ff com.examplepackage.debug/androidx
.fragment.app.testing.FragmentScenario$EmptyFragmentActivity (server)'
gralloc_ranchu D gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
dboxed_process I System.exit called, status: 0
AndroidRuntime I VM exiting with result code 0, cleanup skipped.
D HostConnection::get() New Host Connection established 0xe9c0a840, tid 1973
gralloc_ranchu D gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
D HostConnection::get() New Host Connection established 0xe9c0a840, tid 1973
gralloc_ranchu D gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
Zygote I Process 23437 exited cleanly (0)
D HostConnection::get() New Host Connection established 0xe9c0a840, tid 1973
GnssLocationProvider I WakeLock acquired by sendMessage(REPORT_SV_STATUS, 0, com.android.server.location.GnssLocationProvider$SvSta
tusInfo@453db8e)
gralloc_ranchu D gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
GnssLocationProvider I WakeLock released by handleMessage(REPORT_SV_STATUS, 0, com.android.server.location.GnssLocationProvider$SvS
tatusInfo@453db8e)
SurfaceFlinger W couldn't log to binary event log: overflow.
ActivityManager W Force removing ActivityRecord{82ebca5 u0 com.examplepackage.debug/androidx.fragment.app.testing.Fragm
entScenario$EmptyFragmentActivity t300}: app died, no saved state
W Crash of app com.examplepackage.debug running instrumentation ComponentInfo{com.examplepackage
.debug.test/com.examplepackage.myapp.CustomTestRunner}
I Force stopping com.examplepackage.debug appid=10097 user=0: finished inst
Process com.android.chrome:sandboxed_process0 (PID: 23437) ended
ActivityManager I Killing 23437:com.android.chrome:sandboxed_process0/u0a97i50 (adj 0): isolated not needed
libprocessgroup W Failed to open process cgroup uid 99050 pid 23437: No such file or directory
--
--
E channel '81514ff com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$EmptyFragmen
tActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
libprocessgroup W kill(-23395, 9) failed: No such process
I Successfully killed process cgroup uid 10097 pid 23395 in 4ms
cr_ChildProcessService I Destroying ChildProcessService pid=23437
WindowManager I WIN DEATH: Window{81514ff u0 com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$
EmptyFragmentActivity}
AndroidX Test and Android OS Versions
debugImplementation ("androidx.fragment:fragment-testing:1.1.0-alpha08") {
exclude group: "androidx.test", module: "core"
}
androidTestImplementation 'androidx.test.ext:junit:1.1.1-beta01'
androidTestImplementation 'androidx.test:runner:1.1.1'
androidTestImplementation 'androidx.test:rules:1.1.1'
androidTestImplementation 'androidx.test.espresso:espresso-core:3.1.1'
androidTestImplementation 'androidx.test.espresso:espresso-contrib:3.1.1'
androidTestImplementation 'androidx.test.espresso:espresso-web:3.1.1'
androidTestImplementation 'androidx.test.espresso:espresso-intents:3.1.1'
androidTestImplementation "androidx.arch.core:core-testing:2.0.0"
androidTestUtil 'androidx.test:orchestrator:1.1.1'
Emulator is API 28 Nexus 5, animations turned off.
Link to a public git repo demonstrating the problem:
N/A
Strange. Nothing in the posted stack trace gives me any clue to what might be wrong.
Can you post a sample that reproduces this issue?
Strange. Nothing in the posted stack trace gives me any clue to what might be wrong.
Can you post a sample that reproduces this issue?
I'm trying to set up a minimal project where the same issue would occur consistently. Still no luck, but will post an update here if I succeed.
Any update about this issue? I m getting Test instrumentation process crashed., randomly. Adding a bit wait before starting the Test process solved it. but, I don't think is the right way.
Not sure if it can be related but by creating TestSubscriber even without using it increases chances for process to crash by ~80%, without - ~20%
Same as topic starter I use mockk(1.9.3) and launchFragment(1.2.0)
Same here, also mockk 1.9.3 and launchFragment 1.2.0. Running clean before the test seems to solve the issue.
Same here, also mockk 1.9.3 and launchFragment 1.2.0. Running clean before the test seems to solve the issue.
Thank you @yuriykulikov, mockk 1.9.3 works with 1.2.0-beta02 (as in - the tests run now). Just had to force objenesis version:
allprojects {
configurations.all {
resolutionStrategy {
force("org.objenesis:objenesis:2.6")
}
}
}
But I still get process crashed randomly, unfortunately.
closing due to lack of info
Also seeing this. Getting random crashes that we've narrowed down to use of mockk. Tried various combinations of versions but still happening
We;re seeing this and the last erroring logcat is suggesting an interplay of Jacoco, Garbage Collector (finalizers) and native. It happens after ~10 minutes of successful test executions. Failure rate is about 3-5%, so not possible to repro.
02-11 09:58:09.992 2831 2842 I art : Background partial concurrent mark sweep GC freed 15522(954KB) AllocSpace objects, 48(42MB) LOS objects, 5% free, 75MB/79MB, paused 3.303ms total 160.332ms
02-11 09:58:10.141 2831 2842 W art : Suspending all threads took: 6.671ms
02-11 09:58:10.170 2831 2842 I art : Background partial concurrent mark sweep GC freed 79588(5MB) AllocSpace objects, 59(91MB) LOS objects, 5% free, 70MB/74MB, paused 8.203ms total 155.791ms
02-11 09:58:10.357 2831 2842 W art : Suspending all threads took: 33.815ms
02-11 09:58:10.375 2831 2839 W System.err: java.lang.Error: Cleaner terminated abnormally
02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner$1.run(Cleaner.java:147)
02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner$1.run(Cleaner.java:145)
02-11 09:58:10.376 2831 2839 W System.err: at java.security.AccessController.doPrivileged(AccessController.java:41)
02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner.clean(Cleaner.java:144)
02-11 09:58:10.376 2831 2839 W System.err: at java.lang.ref.ReferenceQueue.enqueueLocked(ReferenceQueue.java:75)
02-11 09:58:10.376 2831 2839 W System.err: at java.lang.ref.ReferenceQueue.enqueuePending(ReferenceQueue.java:243)
02-11 09:58:10.376 2831 2839 W System.err: at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:160)
02-11 09:58:10.376 2831 2839 W System.err: at java.lang.Thread.run(Thread.java:761)
02-11 09:58:10.376 2831 2842 I art : Background partial concurrent mark sweep GC freed 24256(1469KB) AllocSpace objects, 63(92MB) LOS objects, 5% free, 63MB/67MB, paused 35.146ms total 191.839ms
02-11 09:58:10.376 2831 2839 W System.err: Caused by: java.lang.RuntimeException: Attempted to free 98 native bytes with only 80 native bytes registered as allocated
02-11 09:58:10.376 2831 2839 W System.err: at dalvik.system.VMRuntime.registerNativeFree(Native Method)
02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry.registerNativeFree(NativeAllocationRegistry.java:223)
02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry.-wrap0(NativeAllocationRegistry.java)
02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry$CleanerThunk.run(NativeAllocationRegistry.java:196)
02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner.clean(Cleaner.java:142)
02-11 09:58:10.376 2831 2839 W System.err: ... 4 more
02-11 09:58:10.378 2831 11893 W System.err: java.io.FileNotFoundException: /jacoco.exec (Read-only file system)
02-11 09:58:10.378 2831 11893 W System.err: at java.io.FileOutputStream.open(Native Method)
02-11 09:58:10.378 2831 11893 W System.err: at java.io.FileOutputStream.<init>(FileOutputStream.java:221)
02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.output.FileOutput.openFile(FileOutput.java:67)
02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.output.FileOutput.writeExecutionData(FileOutput.java:53)
02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.Agent.shutdown(Agent.java:137)
02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.Agent$1.run(Agent.java:54)
02-11 09:58:10.387 2831 2839 I art : System.exit called, status: 1
Did anyone find a proper fix for this?
Got exactly the same issue with multiple projects. I'm pretty sure this come from mockk from a way or another. Is there any way to have more info about process crashes when there are absolutly no stack trace in the logcat @brettchabot ? I'll try to work on a sample because after a few year I can't bear having my CI jobs failing each 1/2 time for no reason 😢
I have exactly the same issue and I also believe MockK could be behind it. I have posted the issue on SO: https://stackoverflow.com/questions/63059986/android-ui-tests-with-espresso-mockk-crash-with-sigsegv
Looking at OP crash log, I found one common error message:
channel '81514ff com.examplepackage.debug/androidx.fragment.app.testing.FragmentScenario$EmptyFragmentActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
In my case, this log message is always right before the crash, usually alongside a SIGSEGV.
I am using Espresso to write a login + pwd to test a LoginActivity and I use MockK to mock all the Repositories / Services logic in a MVP architecture. Also, none of this has happened on my physical devices.
I reproduced it on my system: https://github.com/NitroG42/CrashDuringTestSample I will make another issue.
Or can this one with some infos be opened again @brettchabot ?
EDIT: it does seems like the bug is coming from mockk after all but I wonder if there anything that can be done on the testing/emulator part.
I agree with @NitroG42 .
I have migrated the few UI tests I had written to on a new mobile app project Mockito believing it would be way more stable thanks to its history and active development.
At first, it seemed the crashs were completely gone, but at some point they did reappear, still at random with the dreadful message from InputDispatcher and occasional SIGSEGV.
On the Android TV project we have (which is way more advanced), the handful tests I developped, which required a lot more mocking, tended to crash a lot more (still on the emulator).
When migrating to Mockito, I noticed the same issues and restrictions:
- minimum API 28 (Android P)
- "the mocking agent could not be attached to the JVMTI" -> added
android:extractNativeLibs="true"as a workaround in the test manifest - attempting to run on lower API printed the same logs than MockK.
So, if I understand correctly, MockK & Mockito uses the same APIs (from Android Test Instrumentation?) to perform mocking in Android UI tests.
While Mockito seemed, at first, a lot more stable, the crash eventually did reappear, for the same reasons. Could it be possible neither of them are the culprit?
Finally, I noticed that manually rebooting the emulators greatly reduced the random crash. Surely because it resets all the memory allocations, right?
@brettchabot could you help? Do you have any idea what could be the real issue?
Also experiencing the same problem with UI test. my solution is to use the fake class implementation instead of mocking it and the problem is gone 🤔
I had exactly the same issue. In my case it was com.linkedin.dexmaker:dexmaker-mockito-inline causing the random crashes. For details see my answer on stackoverflow:
Same here, also mockk 1.9.3 and launchFragment 1.2.0. Running clean before the test seems to solve the issue.
What type of cleaning you mean? Clean cache or clean user data?
I am facing exactly the same issue on a project I am working on. Have you found anything?
I have not solve the problem yet, but meybe it hass been caused memmory leaks.
Using an x64 emulator solved the problem for me, as cristan commented here: https://github.com/mockk/mockk/issues/466#issuecomment-734758479
My project uses mockk, and using an x86_64 emulator (API 28+) also solved the problem for me, too https://github.com/mockk/mockk/issues/466#issuecomment-743264258 mockK 1.10.0 and mockK Android 1.9.3 with objenesis forced at 2.6. I hope the Androidx test team can fix this bug. In Firebase Test Lab, you can't specify the ABI of the emulators used, so it appears basically impossible to run your UI tests in Firebase Test Lab on emulators if you use mockK or mockito
Follow up: I also tried removing mockk as an android test dependency and removed all tests that used it. Once I did that, I found that I could once again run UI tests on non 64 bit emulators
When I do run my tests on a non x86_64 bit emulator using mockk version 1.10.3-jdk8, I notice this log in logcat:
2020-12-16 18:55:46.423 com.my.package.dev. W/.android.dev.q: DexFile /data/user/0/com.my.package.dev/cache/mockk-boot3284438913886633948.jar is in boot class path but is not in a known location
Using an x86_64 emulator also solved the issue for me. Anyone knows why is this fix working?
We;re seeing this and the last erroring logcat is suggesting an interplay of Jacoco, Garbage Collector (finalizers) and native. It happens after ~10 minutes of successful test executions. Failure rate is about 3-5%, so not possible to repro.
02-11 09:58:09.992 2831 2842 I art : Background partial concurrent mark sweep GC freed 15522(954KB) AllocSpace objects, 48(42MB) LOS objects, 5% free, 75MB/79MB, paused 3.303ms total 160.332ms 02-11 09:58:10.141 2831 2842 W art : Suspending all threads took: 6.671ms 02-11 09:58:10.170 2831 2842 I art : Background partial concurrent mark sweep GC freed 79588(5MB) AllocSpace objects, 59(91MB) LOS objects, 5% free, 70MB/74MB, paused 8.203ms total 155.791ms 02-11 09:58:10.357 2831 2842 W art : Suspending all threads took: 33.815ms 02-11 09:58:10.375 2831 2839 W System.err: java.lang.Error: Cleaner terminated abnormally 02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner$1.run(Cleaner.java:147) 02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner$1.run(Cleaner.java:145) 02-11 09:58:10.376 2831 2839 W System.err: at java.security.AccessController.doPrivileged(AccessController.java:41) 02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner.clean(Cleaner.java:144) 02-11 09:58:10.376 2831 2839 W System.err: at java.lang.ref.ReferenceQueue.enqueueLocked(ReferenceQueue.java:75) 02-11 09:58:10.376 2831 2839 W System.err: at java.lang.ref.ReferenceQueue.enqueuePending(ReferenceQueue.java:243) 02-11 09:58:10.376 2831 2839 W System.err: at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:160) 02-11 09:58:10.376 2831 2839 W System.err: at java.lang.Thread.run(Thread.java:761) 02-11 09:58:10.376 2831 2842 I art : Background partial concurrent mark sweep GC freed 24256(1469KB) AllocSpace objects, 63(92MB) LOS objects, 5% free, 63MB/67MB, paused 35.146ms total 191.839ms 02-11 09:58:10.376 2831 2839 W System.err: Caused by: java.lang.RuntimeException: Attempted to free 98 native bytes with only 80 native bytes registered as allocated 02-11 09:58:10.376 2831 2839 W System.err: at dalvik.system.VMRuntime.registerNativeFree(Native Method) 02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry.registerNativeFree(NativeAllocationRegistry.java:223) 02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry.-wrap0(NativeAllocationRegistry.java) 02-11 09:58:10.376 2831 2839 W System.err: at libcore.util.NativeAllocationRegistry$CleanerThunk.run(NativeAllocationRegistry.java:196) 02-11 09:58:10.376 2831 2839 W System.err: at sun.misc.Cleaner.clean(Cleaner.java:142) 02-11 09:58:10.376 2831 2839 W System.err: ... 4 more 02-11 09:58:10.378 2831 11893 W System.err: java.io.FileNotFoundException: /jacoco.exec (Read-only file system) 02-11 09:58:10.378 2831 11893 W System.err: at java.io.FileOutputStream.open(Native Method) 02-11 09:58:10.378 2831 11893 W System.err: at java.io.FileOutputStream.<init>(FileOutputStream.java:221) 02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.output.FileOutput.openFile(FileOutput.java:67) 02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.output.FileOutput.writeExecutionData(FileOutput.java:53) 02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.Agent.shutdown(Agent.java:137) 02-11 09:58:10.378 2831 11893 W System.err: at org.jacoco.agent.rt.internal_8ff85ea.Agent$1.run(Agent.java:54) 02-11 09:58:10.387 2831 2839 I art : System.exit called, status: 1
Did you ever figure out what was causing this / find a workaround? I'm seeing the same exception when running instrumented tests on physical devices.
I agree with @NitroG42 .
I have migrated the few UI tests I had written to on a new mobile app project Mockito believing it would be way more stable thanks to its history and active development.
At first, it seemed the crashs were completely gone, but at some point they did reappear, still at random with the dreadful message from
InputDispatcherand occasionalSIGSEGV.On the Android TV project we have (which is way more advanced), the handful tests I developped, which required a lot more mocking, tended to crash a lot more (still on the emulator).
When migrating to Mockito, I noticed the same issues and restrictions:
- minimum API 28 (Android P)
- "the mocking agent could not be attached to the JVMTI" -> added
android:extractNativeLibs="true"as a workaround in the test manifest- attempting to run on lower API printed the same logs than MockK.
So, if I understand correctly, MockK & Mockito uses the same APIs (from Android Test Instrumentation?) to perform mocking in Android UI tests.
While Mockito seemed, at first, a lot more stable, the crash eventually did reappear, for the same reasons. Could it be possible neither of them are the culprit?
Finally, I noticed that manually rebooting the emulators greatly reduced the random crash. Surely because it resets all the memory allocations, right?
@brettchabot could you help? Do you have any idea what could be the real issue?
@ricard-v one year later, any update on this? I'm still stuck on this bug, which prevents me from running any UI tests that use mocking in Firebase Test Lab. Wondering if I just need to bite the bullet and removing all mockking libraries if I want my instrumentation tests to run on FTL virtual devices.
Sorry for the lack of response on this issue. I wish I could help more but TBH I don't have expertise on mocking libraries . This github project probably isn't the right forum to address this issue, as it doesn't seem to be related to the androidx.test libraries.
Perhaps the mockk/mockito maintainers or Android ART team could be more help?
Apologies, I should have commented in the mockk repository. Here's the corresponding issue https://github.com/mockk/mockk/issues/466
Since this issue is still open, I'll share my minimal reproducible example: https://github.com/SimonMarquis/FTL-segfault I've also added more details in https://github.com/mockk/mockk/issues/466#issuecomment-1217887879 I hope this will be helpful.