Anki-Android
Anki-Android copied to clipboard
ankidroid
CI test flakiness collection
Reproduction Steps
- make any PR request or manually trigger testing run
- watch logs
Expected Result
Tests should succeed every single time unless there is a legitimate test failure
Actual Result
They flake sometimes.
The situation has been improved recently with #11032 but this issue will collect experiences after that merge to tack it down completely
Here is one I just saw:
https://github.com/ankidroid/Anki-Android/runs/6157540326?check_suite_focus=true#step:9:275
> Task :AnkiDroid:connectedPlayDebugAndroidTest
Apr 25, 2022 12:50:33 PM com.android.tools.utp.plugins.result.listener.gradle.GradleAndroidTestResultListener$configure$responseObserver$1 onError
SEVERE: recordTestResultEvent failed with an error: io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
Apr 25, 2022 12:50:33 PM io.grpc.internal.SerializingExecutor run
SEVERE: Exception while executing runnable io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed@7c945c49
io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
at io.grpc.Status.asRuntimeException(Status.java:533)
at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399)
at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:500)
at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:65)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:592)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:508)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:632)
at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: javax.net.ssl.SSLException: handshake timed out
at io.netty.handler.ssl.SslHandler.handshake(...)(Unknown Source)
Completed successfully after re-run
Seen again once 20220430 or thereabouts https://github.com/ankidroid/Anki-Android/runs/6227166753?check_suite_focus=true#step:9:274 on #11162
This just popped up on unit tests, first time I've seen it. Logging for frequency analysis over time
https://github.com/ankidroid/Anki-Android/runs/6372125564?check_suite_focus=true#step:7:143
SchedTest > test_newBoxes_v1 FAILED
java.lang.NullPointerException
at com.ichi2.libanki.template.ParsedNode.parse_inner(ParsedNode.java:88)
at com.ichi2.libanki.Model.parsedNodes(Model.java:128)
at com.ichi2.libanki.Models._availStandardOrds(Models.java:1014)
at com.ichi2.libanki.Models.availOrds(Models.java:1006)
at com.ichi2.libanki.Collection.findTemplates(Collection.java:723)
at com.ichi2.libanki.Collection.addNote(Collection.java:668)
at com.ichi2.libanki.Collection.addNote(Collection.java:657)
at com.ichi2.libanki.sched.SchedTest.test_newBoxes_v1(SchedTest.java:310)
From #11173
Oh my, JVM OOM on windows unit test with current attempt to update dependencies. That's unexpected.
From #11310
https://github.com/ankidroid/Anki-Android/runs/6377466202?check_suite_focus=true#step:7:149
TagsListTest > test_sort_will_not_call_collectionsSort SKIPPED
#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 1774096 bytes for Chunk::new
# An error report file with more information is saved as:
# D:\a\Anki-Android\Anki-Android\AnkiDroid\hs_err_pid868.log
#
# Compiler replay data is saved as:
# D:\a\Anki-Android\Anki-Android\AnkiDroid\replay_pid868.log
Unexpected exception thrown.
org.gradle.internal.remote.internal.MessageIOException: Could not write '/127.0.0.1:51073'.
at org.gradle.internal.remote.internal.inet.SocketConnection.flush(SocketConnection.java:[140](https://github.com/ankidroid/Anki-Android/runs/6377466202?check_suite_focus=true#step:7:140))
at org.gradle.internal.remote.internal.hub.MessageHub$ConnectionDispatch.run(MessageHub.java:333)
at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.io.IOException: An existing connection was forcibly closed by the remote host
at java.base/sun.nio.ch.SocketDispatcher.write0(Native Method)
at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:51)
at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:113)
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:58)
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:50)
at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:462)
at org.gradle.internal.remote.internal.inet.SocketConnection$SocketOutputStream.writeWithNonBlockingRetry(SocketConnection.java:279)
at org.gradle.internal.remote.internal.inet.SocketConnection$SocketOutputStream.writeBufferToChannel(SocketConnection.java:267)
at org.gradle.internal.remote.internal.inet.SocketConnection$SocketOutputStream.flush(SocketConnection.java:261)
at org.gradle.internal.remote.internal.inet.SocketConnection.flush(SocketConnection.java:138)
... 6 more
This is a new one I believe, ubuntu unit test
UpgradeVolumeButtonsToBindingsTest > [0: isValid(TestData(affectedPreferenceKey=gestureVolumeUp, keyCode=24, unaffectedPreferenceKey=gestureVolumeDown, binding=com.ichi2.anki.reviewer.MappableBinding@1900db))={1}] > com.ichi2.anki.servicemodel.UpgradeVolumeButtonsToBindingsTest.gesture_set_no_conflicts[0: isValid(TestData(affectedPreferenceKey=gestureVolumeUp, keyCode=24, unaffectedPreferenceKey=gestureVolumeDown, binding=com.ichi2.anki.reviewer.MappableBinding@1900db))={1}] FAILED
java.lang.AssertionError:
Expected: iterable with items ["preferenceUpgradeVersion", "gestureVolumeUp", "binding_SHOW_ANSWER"] in any order
but: no item matches: "preferenceUpgradeVersion", "gestureVolumeUp", "binding_SHOW_ANSWER" in []
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
at com.ichi2.anki.servicemodel.UpgradeVolumeButtonsToBindingsTest.gesture_set_no_conflicts(UpgradeVolumeButtonsToBindingsTest.kt:97)
:warning: :warning: HIGH PRIORITY - this one is the current most frequent failure
Related to the one from yesterday - also in gesture preferences test, also on ubuntu, close but slightly different failure:
UpgradeVolumeButtonsToBindingsTest > [1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] > com.ichi2.anki.servicemodel.UpgradeVolumeButtonsToBindingsTest.if_gesture_already_exists_then_do_not_modify_list[1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] FAILED
java.lang.AssertionError: Binding gestures should not be changed
Expected: iterable containing ["preferenceUpgradeVersion", "gestureVolumeDown"]
but: no item was "preferenceUpgradeVersion"
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at com.ichi2.anki.servicemodel.UpgradeVolumeButtonsToBindingsTest.if_gesture_already_exists_then_do_not_modify_list(UpgradeVolumeButtonsToBindingsTest.kt:164)
Looks set to move a little when #11647 merges
UpgradeGesturesToControlsTest > [1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] > com.ichi2.anki.servicemodel.UpgradeGesturesToControlsTest.invalid_preference_value_results_in_old_null_value_and_no_new_value[1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] FAILED
java.lang.AssertionError: Binding gestures should not be changed
Expected: iterable containing ["preferenceUpgradeVersion", "gestureVolumeDown"]
but: no item was "preferenceUpgradeVersion"
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at com.ichi2.anki.servicemodel.UpgradeGesturesToControlsTest.invalid_preference_value_results_in_old_null_value_and_no_new_value(UpgradeGesturesToControlsTest.kt:145)
UpgradeGesturesToControlsTest > [1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] > com.ichi2.anki.servicemodel.UpgradeGesturesToControlsTest.if_mapped_to_non_empty_binding_then_added_to_end[1: isValid(TestData(affectedPreferenceKey=gestureVolumeDown, keyCode=25, unaffectedPreferenceKey=gestureVolumeUp, binding=com.ichi2.anki.reviewer.MappableBinding@19753a))={1}] FAILED
java.lang.AssertionError:
Expected: iterable with items ["preferenceUpgradeVersion", "gestureVolumeDown", "binding_EDIT"] in any order
but: no item matches: "preferenceUpgradeVersion", "gestureVolumeDown" in ["binding_EDIT"]
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
at com.ichi2.anki.servicemodel.UpgradeGesturesToControlsTest.if_mapped_to_non_empty_binding_then_added_to_end(UpgradeGesturesToControlsTest.kt:95)
Popped up a second time on windows CI
3 more times in PRs I went through today on 20220529 another one 20220601 another one 20220602 bunches more since then
https://github.com/ankidroid/Anki-Android/issues/10101 related but slightly different
These are failing for me semi-frequently locally as part of unit test on ubuntu
CollectionTaskSearchCardsTest > searchCardsNumberOfResultCount FAILED
Wanted but not invoked:
taskListener.onProgressUpdate(
<Capturing argument>
);
-> at com.ichi2.async.TaskListener.onProgressUpdate(TaskListener.kt:44)
However, there was exactly 1 interaction with this mock:
taskListener.onPreExecute();
-> at com.ichi2.async.CollectionTask.onPreExecute(CollectionTask.kt:140)
at com.ichi2.async.TaskListener.onProgressUpdate(TaskListener.kt:44)
at com.ichi2.async.CollectionTaskSearchCardsTest.searchCardsNumberOfResultCount(CollectionTaskSearchCardsTest.kt:53)
The cache restore step has failed on macOS once recently and windows twice recently. I'm not sure 5mins is enough for that step.
This instrumented test just flaked on my locally, API31 emulator:
com.ichi2.anki.dialogs.ModelEditorContextMenuTest > showsAllOptionsIfAboveN[TestingAVD_API-31_TAG-PLAY(AVD) - 12] FAILED
androidx.test.espresso.base.RootViewPicker$RootViewWithoutFocusException: Waited for the root of the view hierarchy to have window focus and not request layout for 10 seconds. If you specified a non default root matcher, it may be picking a root that never takes focus. Root:
Root{application-window-token=android.view.ViewRootImpl$W@f926ed8, window-token=android.view.ViewRootImpl$W@f926ed8, has-window-focus=false, layout-params-type=1, layout-params-string={(0,0)(fillxfill) sim={forwardNavigation} ty=BASE_APPLICATION wanim=0x10302fe
windows unit test gradle cache restore timeout hit at 5 minutes, perhaps slacken. Tracking failure rate here.
Local jacocoAndroidTestReport flakes
This one is really flaky for me on linux at least:
com.ichi2.anki.dialogs.ModelEditorContextMenuTest > doesNotShowLanguageHintOptionIfBelowN[TestingAVD_API-31_TAG-PLAY(AVD) - 12] FAILED
androidx.test.espresso.NoMatchingViewException: No views in hierarchy found matching: an instance of android.widget.TextView and view.getText() with or without transformation to match: is "test editor title"
Not quite as flaky but shows up
com.ichi2.anki.tests.ContentProviderTest > testAnswerCard[1][TestingAVD_API-25_TAG-GAPI(AVD) - 7.1.1] FAILED
Managed to get at least one run through these so they can pass, just flaky
Some new ones, these are odd
ReviewerNoParamTest > drawerConflictsIfRight FAILED
java.lang.AssertionError:
Expected: <true>
but: was <false>
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6)
at com.ichi2.anki.ReviewerNoParamTest.drawerConflictsIfRight(ReviewerNoParamTest.kt:234)
CollectionTaskSearchCardsTest > searchCardsNumberOfResultCount FAILED
Wanted but not invoked:
taskListener.onProgressUpdate(
<Capturing argument>
);
-> at com.ichi2.async.TaskListener.onProgressUpdate(TaskListener.kt:44)
However, there was exactly 1 interaction with this mock:
taskListener.onPreExecute();
-> at com.ichi2.async.CollectionTask.onPreExecute(CollectionTask.kt:140)
at com.ichi2.async.TaskListener.onProgressUpdate(TaskListener.kt:44)
at com.ichi2.async.CollectionTaskSearchCardsTest.searchCardsNumberOfResultCount(CollectionTaskSearchCardsTest.kt:53)
Saw this one again 20220616
Local jacocoAndroidTestReport flakes
This one is really flaky for me on linux at least:
com.ichi2.anki.dialogs.ModelEditorContextMenuTest > doesNotShowLanguageHintOptionIfBelowN[TestingAVD_API-31_TAG-PLAY(AVD) - 12] FAILED androidx.test.espresso.NoMatchingViewException: No views in hierarchy found matching: an instance of android.widget.TextView and view.getText() with or without transformation to match: is "test editor title"
The test says, doesNotShowLanguageHintOptionIfBelowN so running on AVD_AP1-31 should fail. I think the test should be skipped if on api level above 25.
@divyansh-dxn I think that is a simplistic view. The test should verify above N that the hint does show (test the positive), while below N it should verify it does not show (test the negative). If you disable the test there will be no test exercising that the hint shows up, I think?
Also, one thing I noticed running the test function individually passes always, while running the test class fails it.
One-off flakes in the past week:
com.ichi2.anki.tests.ContentProviderTest > testBuryCard[1][test(AVD) - 10] FAILED com.ichi2.anki.tests.LayoutValidationTest > ensureLayout[fragment_anki_stats_overview][test(AVD) - 10] FAILED com.ichi2.anki.tests.ContentProviderTest > testInsertTemplate[0][test(AVD) - 10] FAILED
Upon re-running the connected tests a third time in CI, I got this:
com.ichi2.anki.tests.ContentProviderTest > testQueryNextCard[1][test(AVD) - 10] FAILED java.lang.RuntimeException: android.os.DeadSystemException at android.app.ContextImpl.checkPermission(ContextImpl.java:1837)
com.ichi2.anki.tests.ContentProviderTest > testDatabaseUtilsInvocationWorks[1][test(AVD) - 10] FAILED junit.framework.AssertionFailedError: Failed to grant permissions, see logcat for details at junit.framework.Assert.fail(Assert.java:50)
com.ichi2.anki.tests.ContentProviderTest > testQueryAllDecks[1][test(AVD) - 10] FAILED junit.framework.AssertionFailedError: Failed to grant permissions, see logcat for details at junit.framework.Assert.fail(Assert.java:50)
com.ichi2.anki.tests.ContentProviderTest > testQueryNotesProjection[1][test(AVD) - 10] FAILED junit.framework.AssertionFailedError: Failed to grant permissions, see logcat for details at junit.framework.Assert.fail(Assert.java:50)
com.ichi2.anki.tests.ContentProviderTest > testQueryCurrentModel[1][test(AVD) - 10] FAILED junit.framework.AssertionFailedError: Failed to grant permissions, see logcat for details at junit.framework.Assert.fail(Assert.java:50) Tests on test(AVD) - 10 failed: There was 5 failure(s).
On the 4th try, the tests passed.
I have been seeing the same "failed to grant permissions" thing, I wonder if the latest emulator binary has a problem. That hunch is confirmation-bias affirmed by the current version of the emulator all of the sudden looking terrible on my macOS OSX-VMs (gray screen) indicating something big happened over there in Android Emulator project area. It was an update that came down sometime between a couple weeks ago and a couple days ago. I may try to bisect emulator versions, also downloading the adb logcat dump from the actions may specify something.
Either way the android emulator tests are ridiculously flaky right now, after being really solid just a month ago, not a great indicator for PRs at the moment.
Along with @oakkitten a discovery of "OutOfMemory" death spirals on the emulator has been discovered, they are visible in the tail end (maybe 100 or 200 lines remaining) of the adb logs from emulator crashes. It is intermittent though, not every time, which hints at something racy happening.
I found this: https://support.circleci.com/hc/en-us/articles/360021812453-Common-Android-memory-issues#zygote
Which leads to this: https://www.rainforestqa.com/blog/hunting-race-condition-in-android-10-emulator
There is this in the logs at zygote spawn at the top, note the -Xmx16mx arg:
08-20 09:00:16.942 1691 1691 I zygote64: option[0]=-Xzygote
08-20 09:00:16.942 1691 1691 I zygote64: option[1]=exit
08-20 09:00:16.943 1691 1691 I zygote64: option[2]=vfprintf
08-20 09:00:16.943 1691 1691 I zygote64: option[3]=sensitiveThread
08-20 09:00:16.943 1691 1691 I zygote64: option[4]=-verbose:gc
08-20 09:00:16.943 1691 1691 I zygote64: option[5]=-Xms4m
08-20 09:00:16.943 1691 1691 I zygote64: option[6]=-Xmx16m
So this appears to fit. I believe the init sequence on the emulator has a race condition between memory param detection/customization and zygote spawn that we are "losing" intermittently, and much more so with the latest emulator release. I'm going to try to implement the suggested workaround:
The simplest way to resolve this issue is to call
adb root && sleep 5 && adb setprop ctl.restart zygoteas a post-emulator-run-step
...taking care of this:
This will kill any running logging sessions, so you will have to manually restart your own logging as another post-emulator-run-step
[edit: if you use adb shell su root "setprop ctl.restart zygote" then it doesn't restart adb / kill adb logcat, but it tests out correctly as a hot reboot on a local google apis (not playstore!) emulator)
Only seen locally (macOS):
After waiting for 60000 ms, the test coroutine is not completing
kotlinx.coroutines.test.UncompletedCoroutinesError: After waiting for 60000 ms, the test coroutine is not completing
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt$runTestCoroutine$3$3.invokeSuspend(TestBuilders.kt:342)
(Coroutine boundary)
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt.runTestCoroutine(TestBuilders.kt:326)
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt$runTest$1$1.invokeSuspend(TestBuilders.kt:167)
at kotlinx.coroutines.test.TestBuildersJvmKt$createTestResult$1.invokeSuspend(TestBuildersJvm.kt:13)
Suppressed: org.robolectric.android.internal.AndroidTestEnvironment$UnExecutedRunnablesException: Main looper has queued unexecuted runnables. This might be the cause of the test failure. You might need a shadowOf(Looper.getMainLooper()).idle() call.
Caused by: kotlinx.coroutines.test.UncompletedCoroutinesError: After waiting for 60000 ms, the test coroutine is not completing
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt$runTestCoroutine$3$3.invokeSuspend(TestBuilders.kt:342)
at app//kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:284)
at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
at kotlinx.coroutines.test.TestBuildersJvmKt.createTestResult(TestBuildersJvm.kt:12)
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt.runTest(TestBuilders.kt:166)
at kotlinx.coroutines.test.TestBuildersKt.runTest(Unknown Source)
at kotlinx.coroutines.test.TestBuildersKt__TestBuildersKt.runTest(TestBuilders.kt:154)
at kotlinx.coroutines.test.TestBuildersKt.runTest(Unknown Source)
at com.ichi2.anki.RobolectricTest.runTest(RobolectricTest.kt:627)
at com.ichi2.anki.RobolectricTest.runTest$default(RobolectricTest.kt:622)
at com.ichi2.anki.stats.AnkiStatsTaskHandlerTest.testCreateReviewSummaryStatistics(AnkiStatsTaskHandlerTest.kt:59)
at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at [email protected]/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at [email protected]/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at [email protected]/java.lang.reflect.Method.invoke(Method.java:566)
at app//org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at app//org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at app//org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at app//org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at app//org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at app//org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at app//org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at app//org.robolectric.RobolectricTestRunner$HelperTestRunner$1.evaluate(RobolectricTestRunner.java:591)
at app//org.robolectric.internal.SandboxTestRunner$2.lambda$evaluate$0(SandboxTestRunner.java:274)
at app//org.robolectric.internal.bytecode.Sandbox.lambda$runOnMainThread$0(Sandbox.java:88)
at [email protected]/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at [email protected]/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at [email protected]/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at [email protected]/java.lang.Thread.run(Thread.java:829)
Can't reproduce, but does this help? Changed the test to exercise the non-null case, and removed the mutex in the process, as withCol should enforce single execution.
diff --git a/AnkiDroid/src/main/java/com/ichi2/anki/DeckPicker.kt b/AnkiDroid/src/main/java/com/ichi2/anki/DeckPicker.kt
index 7b0dab6df..c783889f5 100644
--- a/AnkiDroid/src/main/java/com/ichi2/anki/DeckPicker.kt
+++ b/AnkiDroid/src/main/java/com/ichi2/anki/DeckPicker.kt
@@ -2206,7 +2206,12 @@ open class DeckPicker :
context.renderPage()
// Update the mini statistics bar as well
deckPicker?.launchCatchingTask {
- AnkiStatsTaskHandler.createReviewSummaryStatistics(context.col, context.mReviewSummaryTextView)
+ val text = AnkiStatsTaskHandler.createReviewSummaryStatistics(context)
+ context.mReviewSummaryTextView.apply {
+ this.text = text ?: ""
+ visibility = View.VISIBLE
+ invalidate()
+ }
}
Timber.d("Startup - Deck List UI Completed")
}
diff --git a/AnkiDroid/src/main/java/com/ichi2/anki/stats/AnkiStatsTaskHandler.kt b/AnkiDroid/src/main/java/com/ichi2/anki/stats/AnkiStatsTaskHandler.kt
index f31d80d47..8cff1dc11 100644
--- a/AnkiDroid/src/main/java/com/ichi2/anki/stats/AnkiStatsTaskHandler.kt
+++ b/AnkiDroid/src/main/java/com/ichi2/anki/stats/AnkiStatsTaskHandler.kt
@@ -16,10 +16,13 @@
package com.ichi2.anki.stats
import android.R
+import android.content.Context
import android.view.View
import android.webkit.WebView
import android.widget.ProgressBar
import android.widget.TextView
+import com.ichi2.anki.CollectionManager.withOpenColOrNull
import com.ichi2.libanki.Collection
import com.ichi2.libanki.DeckId
import com.ichi2.libanki.stats.Stats
@@ -129,43 +132,32 @@ class AnkiStatsTaskHandler private constructor(
@JvmStatic
suspend fun createReviewSummaryStatistics(
- col: Collection,
- view: TextView,
- mainDispatcher: CoroutineDispatcher = Dispatchers.Main,
- defaultDispatcher: CoroutineDispatcher = Dispatchers.IO
- ): Unit = mutex.withLock {
- withContext(defaultDispatcher) {
- val todayStatString = if (!isActive || col.dbClosed) {
- Timber.d("Quitting DeckPreviewStatistics before execution")
- null
- } else {
- Timber.d("Starting DeckPreviewStatistics")
- // eventually put this in Stats (in desktop it is not though)
- var cards: Int
- var minutes: Int
- /* cards, excludes rescheduled cards https://github.com/ankidroid/Anki-Android/issues/8592 */
- val query = "select sum(case when ease > 0 then 1 else 0 end), " +
- "sum(time)/1000 from revlog where id > " + (col.sched.dayCutoff - Stats.SECONDS_PER_DAY) * 1000
- Timber.d("DeckPreviewStatistics query: %s", query)
- col.db
- .query(query).use { cur ->
- cur.moveToFirst()
- cards = cur.getInt(0)
- minutes = (cur.getInt(1) / 60.0).roundToInt()
- }
- val res = view.resources
- val span = res.getQuantityString(com.ichi2.anki.R.plurals.in_minutes, minutes, minutes)
- res.getQuantityString(com.ichi2.anki.R.plurals.studied_cards_today, cards, cards, span)
- }
- todayStatString?.let {
- withContext(mainDispatcher) {
- view.apply {
- text = it
- visibility = View.VISIBLE
- invalidate()
- }
+ context: Context,
+ ): String? {
+ return withOpenColOrNull {
+ Timber.d("Starting DeckPreviewStatistics")
+ // eventually put this in Stats (in desktop it is not though)
+ var cards: Int
+ var minutes: Int
+ /* cards, excludes rescheduled cards https://github.com/ankidroid/Anki-Android/issues/8592 */
+ val query = "select sum(case when ease > 0 then 1 else 0 end), " +
+ "sum(time)/1000 from revlog where id > " + (sched.dayCutoff - Stats.SECONDS_PER_DAY) * 1000
+ Timber.d("DeckPreviewStatistics query: %s", query)
+ db
+ .query(query).use { cur ->
+ cur.moveToFirst()
+ cards = cur.getInt(0)
+ minutes = (cur.getInt(1) / 60.0).roundToInt()
}
- }
+ val res = context.resources
+ val span =
+ res.getQuantityString(com.ichi2.anki.R.plurals.in_minutes, minutes, minutes)
+ res.getQuantityString(
+ com.ichi2.anki.R.plurals.studied_cards_today,
+ cards,
+ cards,
+ span
+ )
}
}
}
diff --git a/AnkiDroid/src/test/java/com/ichi2/anki/stats/AnkiStatsTaskHandlerTest.kt b/AnkiDroid/src/test/java/com/ichi2/anki/stats/AnkiStatsTaskHandlerTest.kt
index be542c2d1..98442b49d 100644
--- a/AnkiDroid/src/test/java/com/ichi2/anki/stats/AnkiStatsTaskHandlerTest.kt
+++ b/AnkiDroid/src/test/java/com/ichi2/anki/stats/AnkiStatsTaskHandlerTest.kt
@@ -15,8 +15,11 @@
****************************************************************************************/
package com.ichi2.anki.stats
+import android.content.Intent
import android.widget.TextView
+import androidx.test.core.app.ActivityScenario
import androidx.test.ext.junit.runners.AndroidJUnit4
+import com.ichi2.anki.DeckPicker
import com.ichi2.anki.RobolectricTest
import com.ichi2.anki.stats.AnkiStatsTaskHandler.Companion.createReviewSummaryStatistics
import com.ichi2.annotations.NeedsTest
@@ -33,34 +36,18 @@ import org.mockito.Mockito.*
import org.mockito.MockitoAnnotations
import org.mockito.kotlin.whenever
import java.util.concurrent.ExecutionException
+import kotlin.coroutines.resume
+import kotlin.coroutines.suspendCoroutine
+import kotlin.test.assertEquals
@OptIn(ExperimentalCoroutinesApi::class)
@RunWith(AndroidJUnit4::class)
class AnkiStatsTaskHandlerTest : RobolectricTest() {
- @Mock
- private lateinit var mCol: Collection
-
- @Mock
- private lateinit var mView: TextView
-
- private val testDispatcher = StandardTestDispatcher()
-
- @Before
- override fun setUp() {
- super.setUp()
- MockitoAnnotations.openMocks(this)
- whenever(mCol.db).thenReturn(null)
- whenever(mCol.dbClosed).thenReturn(true)
- }
-
@Test
- @Throws(ExecutionException::class, InterruptedException::class)
- @NeedsTest("explain this test")
- fun testCreateReviewSummaryStatistics() = runTest(testDispatcher) {
- verify(mCol, atMost(0))!!.db
- createReviewSummaryStatistics(mCol, mView, testDispatcher, testDispatcher)
- advanceUntilIdle()
- verify(mCol, atLeast(0))!!.db
- verify(mCol, atLeast(1))!!.dbClosed
+ fun testCreateReviewSummaryStatistics() = runTest {
+ val deckPicker = startActivityNormallyOpenCollectionWithIntent(
+ DeckPicker::class.java, Intent()
+ )
+ assertEquals(createReviewSummaryStatistics(deckPicker), "Studied 0 cards in 0 minutes today")
}
}
It's only occasionally flaky. The patch provided fails with:
expected: <null> but was: <Studied 0 cards in 0 minutes today>
Expected :null
Actual :Studied 0 cards in 0 minutes today
<Click to see difference>
Whoops, I changed withCol to withOpenColOrNull at the last minute, so the assert should now check for null as well. Looks like I got the arg order on the assert wrong too.
Some sort of windows flake in CI, using legacy schema
ReviewerTest > [SchedV2] > com.ichi2.anki.ReviewerTest.baseDeckName[SchedV2] FAILED
net.ankiweb.rsdroid.exceptions.BackendInvalidInputException$BackendCollectionAlreadyOpenException: CollectionAlreadyOpen
at net.ankiweb.rsdroid.exceptions.BackendInvalidInputException$Companion.fromInvalidInputError(BackendInvalidInputException.kt:34)
at net.ankiweb.rsdroid.BackendException$Companion.fromError(BackendException.kt:114)
at net.ankiweb.rsdroid.BackendKt.unpackResult(Backend.kt:323)
at net.ankiweb.rsdroid.BackendKt.access$unpackResult(Backend.kt:1)
at net.ankiweb.rsdroid.Backend$runMethodRaw$1.invoke(Backend.kt:130)
at net.ankiweb.rsdroid.Backend$runMethodRaw$1.invoke(Backend.kt:[129](https://github.com/ankidroid/Anki-Android/actions/runs/3044985621/jobs/4905989460#step:8:130))
at net.ankiweb.rsdroid.Backend.withBackend(Backend.kt:157)
at net.ankiweb.rsdroid.Backend.runMethodRaw(Backend.kt:129)
at anki.backend.GeneratedBackend.openCollectionRaw(GeneratedBackend.kt:26)
at anki.backend.GeneratedBackend.openCollection(GeneratedBackend.kt:40)
at net.ankiweb.rsdroid.Backend.openCollection(Backend.kt:109)
at net.ankiweb.rsdroid.Backend.openCollection(Backend.kt:61)
at com.ichi2.libanki.Storage.openDB$AnkiDroid_playDebug(Storage.kt:106)
at com.ichi2.libanki.Collection.reopen(Collection.kt:457)
at com.ichi2.libanki.Collection.reopen$default(Collection.kt:454)
at com.ichi2.libanki.Collection.<init>(Collection.kt:187)
at com.ichi2.libanki.Storage.collection(Storage.kt:88)
at com.ichi2.anki.CollectionManager.ensureOpenInner(CollectionManager.kt:209)
at com.ichi2.anki.CollectionManager.access$ensureOpenInner(CollectionManager.kt:36)
at com.ichi2.anki.CollectionManager$getColUnsafe$1$1.invoke(CollectionManager.kt:251)
at com.ichi2.anki.CollectionManager$getColUnsafe$1$1.invoke(CollectionManager.kt:250)
at com.ichi2.anki.CollectionManager.blockForQueue(CollectionManager.kt:230)
at com.ichi2.anki.CollectionManager.access$blockForQueue(CollectionManager.kt:36)
at com.ichi2.anki.CollectionManager$getColUnsafe$1.invoke(CollectionManager.kt:250)
at com.ichi2.anki.CollectionManager$getColUnsafe$1.invoke(CollectionManager.kt:249)
at com.ichi2.anki.CollectionManager.logUIHangs(CollectionManager.kt:266)
at com.ichi2.anki.CollectionManager.getColUnsafe(CollectionManager.kt:249)
at com.ichi2.anki.CollectionHelper.getCol(CollectionHelper.kt:88)
at com.ichi2.anki.RobolectricTest.getCol(RobolectricTest.kt:309)
at com.ichi2.anki.ReviewerTest.setUp(ReviewerTest.kt:59)
Hmm - for the emulator test it's available as an artifact uploaded to the workflow which you may access by clicking on the summary, you can see an example here https://github.com/ankidroid/Anki-Android/actions/runs/3048002169
For the unit tests though (and the windows run is unit test only), not sure...
I made some provision for android logs to flow through here https://github.com/ankidroid/Anki-Android/blob/db59ccbca9694d3d8a45a557c53e19640a421a34/AnkiDroid/src/test/java/com/ichi2/anki/RobolectricTest.kt#L107
When I run tests in Android Studio so it never occurred to me, but now that you mention it I've never seen them in my command-line runs, nor in the github actions logs
Looks like one of the configurables needs to be changed?
http://robolectric.org/configuring/ https://hanru-yeh.medium.com/ways-to-enable-robolectric-log-and-their-difference-eb99eaed2beb
Then something the output probably needs to be piped to a file somehow, as it will otherwise overwhelm the github actions output limits and make that window useless. Then upload the file similar to the androidTest strategy - https://github.com/ankidroid/Anki-Android/blob/db59ccbca9694d3d8a45a557c53e19640a421a34/.github/workflows/tests_emulator.yml#L150-L160
all looks a little fiddly to discover the exact way to get logcat flowing through to stdout or stderr, selecting which of those is best, and redirecting that to a file. Alternatively instead of binding the ShadowLog stream to System.out, maybe detecting an env var that's a desired filename and sending it there directly :thinking:
Looks like something racy that windows (just happens to be our slowest CI unit) appears to expose:
CardBrowserTest > checkDisplayOrderPersistence FAILED
java.lang.AssertionError: Modification time must change. Actual: 1596783600410
at org.junit.Assert.fail(Assert.java:89)
at org.junit.Assert.failEquals(Assert.java:187)
at org.junit.Assert.assertNotEquals(Assert.java:201)
at com.ichi2.anki.CardBrowserTest.checkDisplayOrderPersistence(CardBrowserTest.kt:573)
windows unit test just kicked out the one above :point_up: again plus this one:
ReviewerTest > [SchedV2] > com.ichi2.anki.ReviewerTest.baseDeckName[SchedV2] FAILED
net.ankiweb.rsdroid.exceptions.BackendInvalidInputException$BackendCollectionAlreadyOpenException: CollectionAlreadyOpen
at net.ankiweb.rsdroid.exceptions.BackendInvalidInputException$Companion.fromInvalidInputError(BackendInvalidInputException.kt:34)
at net.ankiweb.rsdroid.BackendException$Companion.fromError(BackendException.kt:114)
at net.ankiweb.rsdroid.BackendKt.unpackResult(Backend.kt:323)
at net.ankiweb.rsdroid.BackendKt.access$unpackResult(Backend.kt:1)
at net.ankiweb.rsdroid.Backend$runMethodRaw$1.invoke(Backend.kt:130)
at net.ankiweb.rsdroid.Backend$runMethodRaw$1.invoke(Backend.kt:129)
at net.ankiweb.rsdroid.Backend.withBackend(Backend.kt:157)
at net.ankiweb.rsdroid.Backend.runMethodRaw(Backend.kt:[129](https://github.com/ankidroid/Anki-Android/actions/runs/3077680970/jobs/4972710497#step:8:130))
at anki.backend.GeneratedBackend.openCollectionRaw(GeneratedBackend.kt:26)
at anki.backend.GeneratedBackend.openCollection(GeneratedBackend.kt:40)
at net.ankiweb.rsdroid.Backend.openCollection(Backend.kt:109)
at net.ankiweb.rsdroid.Backend.openCollection(Backend.kt:61)
at com.ichi2.libanki.Storage.openDB$AnkiDroid_playDebug(Storage.kt:106)
at com.ichi2.libanki.Collection.reopen(Collection.kt:457)
at com.ichi2.libanki.Collection.reopen$default(Collection.kt:454)
at com.ichi2.libanki.Collection.<init>(Collection.kt:187)
at com.ichi2.libanki.Storage.collection(Storage.kt:88)
at com.ichi2.anki.CollectionManager.ensureOpenInner(CollectionManager.kt:209)
at com.ichi2.anki.CollectionManager.access$ensureOpenInner(CollectionManager.kt:36)
at com.ichi2.anki.CollectionManager$getColUnsafe$1$1.invoke(CollectionManager.kt:251)
at com.ichi2.anki.CollectionManager$getColUnsafe$1$1.invoke(CollectionManager.kt:250)
at com.ichi2.anki.CollectionManager.blockForQueue(CollectionManager.kt:230)
at com.ichi2.anki.CollectionManager.access$blockForQueue(CollectionManager.kt:36)
at com.ichi2.anki.CollectionManager$getColUnsafe$1.invoke(CollectionManager.kt:250)
at com.ichi2.anki.CollectionManager$getColUnsafe$1.invoke(CollectionManager.kt:249)
at com.ichi2.anki.CollectionManager.logUIHangs(CollectionManager.kt:266)
at com.ichi2.anki.CollectionManager.getColUnsafe(CollectionManager.kt:249)
at com.ichi2.anki.CollectionHelper.getCol(CollectionHelper.kt:88)
at com.ichi2.anki.RobolectricTest.getCol(RobolectricTest.kt:309)
at com.ichi2.anki.ReviewerTest.setUp(ReviewerTest.kt:59)
In my latest PR CardBrowserTest > checkDisplayOrderPersistence FAILED happened on both Ubuntu and Windows; retrying now.