Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Flaky test: io.realm.kotlin.test.common.VersionTrackingTests.initialVersionDereferencedAfterFirstWrite #1582

Closed
cmelchior opened this issue Nov 27, 2023 · 2 comments · Fixed by #1599
Closed

Flaky test: io.realm.kotlin.test.common.VersionTrackingTests.initialVersionDereferencedAfterFirstWrite #1582

cmelchior opened this issue Nov 27, 2023 · 2 comments · Fixed by #1599

Comments

@cmelchior
Copy link
Contributor

cmelchior commented Nov 27, 2023 •
edited by sync-by-unito bot
Loading

On Github Actions: https://github.com/realm/realm-kotlin/runs/19051481379

kotlinx.coroutines.TimeoutCancellationException: Timeout: null
at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invokeSuspend(Utils.kt:102)
at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invoke(Unknown Source:8)
at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invoke(Unknown Source:2)
at kotlinx.coroutines.selects.SelectImplementation$ClauseData.invokeBlock(Select.kt:818)
at kotlinx.coroutines.selects.SelectImplementation.complete(Select.kt:692)
at kotlinx.coroutines.selects.SelectImplementation.doSelectSuspend(Select.kt:434)
at kotlinx.coroutines.selects.SelectImplementation.access$doSelectSuspend(Select.kt:243)
at kotlinx.coroutines.selects.SelectImplementation$doSelectSuspend$1.invokeSuspend(Unknown Source:14)
at 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:280)
at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
at io.realm.kotlin.test.common.VersionTrackingTests.initialVersionDereferencedAfterFirstWrite(VersionTrackingTests.kt:227)

I wonder if our Scheduler changes have somehow exposed race conditions that was hidden before
@cmelchior cmelchior mentioned this issue Nov 27, 2023
Closed
@cmelchior
Copy link
Contributor Author

From a failing test:

11-27 14:25:57.772  2824  2840 I TestRunner: started: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)
11-27 14:25:57.779  2824  2840 D REALM   : [Sdk] Realm opened: RealmImpl[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:25:57.784  2824  2840 D REALM   : [Core] DB: 60503 Thread 132530503863536: Open file: /data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm
11-27 14:25:57.815  2824  2840 D REALM   : [Core] DB: 60503 Thread 132530503863536: Initiate commit version: 2
11-27 14:25:57.873  2824  2840 D REALM   : [Core] DB: 60503 Thread 132530503863536: Commit of size 77616 done in 55772 us ref 23208
11-27 14:25:57.883  2824  2840 W REALM   : Received from realm.asFlow(). Sending: io.realm.kotlin.notifications.internal.InitialRealmImpl@ca23e4f
11-27 14:25:57.886  2824  4906 D REALM   : [Sdk] Realm opened: NotifierRealm[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:25:57.891  2824  4907 D REALM   : [Sdk] Realm opened: WriterRealm[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:25:57.900  2824  4907 D REALM   : [Core] DB: 60503 Thread 132530450418928: Initiate commit version: 3
11-27 14:25:57.921  2824  4907 D REALM   : [Core] DB: 60503 Thread 132530450418928: Commit of size 328 done in 21234 us ref 23336
11-27 14:25:57.927  2824  2840 W REALM   : Received from realm.asFlow(). Sending: io.realm.kotlin.notifications.internal.UpdatedRealmImpl@2ac9dc
11-27 14:26:00.094   881  1009 D EGL_emulation: app_time_stats: avg=59657.77ms min=59657.77ms max=59657.77ms count=1
11-27 14:26:04.774     0     0 W healthd : battery l=100 v=5000 t=25.0 h=2 st=2 c=900000 fc=3000000 cc=10 chg=a
11-27 14:26:11.611   881  1009 D EGL_emulation: app_time_stats: avg=11513.06ms min=11513.06ms max=11513.06ms count=1
11-27 14:26:12.255   584   695 E ActivityManager: Sending non-protected broadcast com.android.bluetooth.btservice.BLUETOOTH_COUNTER_METRICS_ACTION from system uid 1002 pkg com.android.bluetooth
11-27 14:26:12.255   584   695 E ActivityManager: java.lang.Throwable
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.ActivityManagerService.checkBroadcastFromSystem(ActivityManagerService.java:13550)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:14268)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.ActivityManagerService.broadcastIntentInPackage(ActivityManagerService.java:14468)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.ActivityManagerService$LocalService.broadcastIntentInPackage(ActivityManagerService.java:16971)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.PendingIntentRecord.sendInner(PendingIntentRecord.java:526)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.PendingIntentRecord.sendWithResult(PendingIntentRecord.java:311)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.am.ActivityManagerService.sendIntentSender(ActivityManagerService.java:5373)
11-27 14:26:12.255   584   695 E ActivityManager: 	at android.app.PendingIntent.sendAndReturnResult(PendingIntent.java:1012)
11-27 14:26:12.255   584   695 E ActivityManager: 	at android.app.PendingIntent.send(PendingIntent.java:983)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService$DeliveryTracker.deliverLocked(AlarmManagerService.java:5544)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService.deliverAlarmsLocked(AlarmManagerService.java:4444)
11-27 14:26:12.255   584   695 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService$AlarmThread.run(AlarmManagerService.java:4755)
11-27 14:26:12.268   584   620 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
11-27 14:26:12.282   584   620 I ActivityManager: Killing 1530:com.android.managedprovisioning/u0a54 (adj 975): empty #17
11-27 14:26:12.326   584   620 I ActivityManager: Killing 2230:com.android.dynsystem:dynsystem/1000 (adj 975): empty #18
11-27 14:26:12.327   584   620 I ActivityManager: Killing 2216:com.android.dynsystem/1000 (adj 985): empty #19
11-27 14:26:12.328   584   622 I libprocessgroup: Successfully killed process cgroup uid 10054 pid 1530 in 0ms
11-27 14:26:12.329   584   620 I ActivityManager: Killing 1329:com.android.deskclock/u0a92 (adj 985): empty #20
11-27 14:26:12.330   584   620 I ActivityManager: Killing 2176:com.android.contacts/u0a84 (adj 995): empty #21
11-27 14:26:12.331   584   620 I ActivityManager: Killing 2146:com.android.camera2/u0a88 (adj 995): empty #22
11-27 14:26:12.332   584   620 I ActivityManager: Killing 1916:com.android.cellbroadcastreceiver/u0a64 (adj 999): empty #23
11-27 14:26:12.334   584   620 I ActivityManager: Killing 2116:com.android.calendar/u0a98 (adj 999): empty #24
11-27 14:26:12.334   584   620 I ActivityManager: Killing 2056:com.android.traceur/u0a81 (adj 999): empty #25
11-27 14:26:12.335   584   620 I ActivityManager: Killing 2020:com.android.carrierconfig/u0a105 (adj 999): empty #26
11-27 14:26:12.342   584   620 I ActivityManager: Killing 1785:com.android.quicksearchbox/u0a94 (adj 999): empty #27
11-27 14:26:12.343   584   620 I ActivityManager: Killing 1482:com.android.keychain/1000 (adj 999): empty #28
11-27 14:26:12.344   584   620 I ActivityManager: Killing 1749:com.android.printspooler/u0a74 (adj 999): empty #29
11-27 14:26:12.347   584   620 I ActivityManager: Killing 1623:com.android.externalstorage/u0a48 (adj 999): empty #30
11-27 14:26:12.350   584   620 I ActivityManager: Killing 1692:com.android.localtransport/1000 (adj 999): empty #31
11-27 14:26:12.351   584   620 I ActivityManager: Killing 1641:com.android.provision/u0a100 (adj 999): empty #32
11-27 14:26:12.352   584   620 I ActivityManager: Killing 1466:com.android.documentsui/u0a60 (adj 999): empty #33
11-27 14:26:12.516   584   677 W DeviceIdleController: motion timeout went off and device isn't stationary
11-27 14:26:12.932  2642  2642 I BluetoothMetricsLogger: drainBufferedCounters().
11-27 14:26:13.583   361   361 I Zygote  : Process 2146 exited due to signal 9 (Killed)
11-27 14:26:13.584   361   361 I Zygote  : Process 1482 exited due to signal 9 (Killed)
11-27 14:26:13.769   361   361 I Zygote  : Process 2216 exited due to signal 9 (Killed)
11-27 14:26:13.878   584   603 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=0 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 258ms
11-27 14:26:14.057   361   361 I Zygote  : Process 1329 exited due to signal 9 (Killed)
11-27 14:26:14.105   361   361 I Zygote  : Process 2230 exited due to signal 9 (Killed)
11-27 14:26:14.150   361   361 I Zygote  : Process 2020 exited due to signal 9 (Killed)
11-27 14:26:14.150   361   361 I Zygote  : Process 1623 exited due to signal 9 (Killed)
11-27 14:26:14.151   361   361 I Zygote  : Process 1466 exited due to signal 9 (Killed)
11-27 14:26:14.151   361   361 I Zygote  : Process 2116 exited due to signal 9 (Killed)
11-27 14:26:14.152   361   361 I Zygote  : Process 2056 exited due to signal 9 (Killed)
11-27 14:26:14.163   361   361 I Zygote  : Process 1916 exited due to signal 9 (Killed)
11-27 14:26:14.165   361   361 I Zygote  : Process 1641 exited due to signal 9 (Killed)
11-27 14:26:14.172   361   361 I Zygote  : Process 1692 exited due to signal 9 (Killed)
11-27 14:26:14.457   584   622 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 2230 in 0ms
11-27 14:26:14.459   584   622 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 2216 in 0ms
11-27 14:26:14.461   584   622 I libprocessgroup: Successfully killed process cgroup uid 10092 pid 1329 in 0ms
11-27 14:26:14.738   361   361 I Zygote  : Process 1749 exited due to signal 9 (Killed)
11-27 14:26:14.738   361   361 I Zygote  : Process 2176 exited due to signal 9 (Killed)
11-27 14:26:14.785   361   361 I Zygote  : Process 1785 exited due to signal 9 (Killed)
11-27 14:26:14.790   361   361 I Zygote  : Process 1530 exited due to signal 9 (Killed)
11-27 14:26:14.800   584   622 I libprocessgroup: Successfully killed process cgroup uid 10084 pid 2176 in 0ms
11-27 14:26:14.806   584   622 I libprocessgroup: Successfully killed process cgroup uid 10088 pid 2146 in 0ms
11-27 14:26:14.809   584   622 I libprocessgroup: Successfully killed process cgroup uid 10064 pid 1916 in 0ms
11-27 14:26:14.812   584   622 I libprocessgroup: Successfully killed process cgroup uid 10098 pid 2116 in 0ms
11-27 14:26:14.816   584   622 I libprocessgroup: Successfully killed process cgroup uid 10081 pid 2056 in 0ms
11-27 14:26:14.818   584   622 I libprocessgroup: Successfully killed process cgroup uid 10105 pid 2020 in 0ms
11-27 14:26:14.820   584   622 I libprocessgroup: Successfully killed process cgroup uid 10094 pid 1785 in 0ms
11-27 14:26:14.823   584   622 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 1482 in 0ms
11-27 14:26:14.825   584   622 I libprocessgroup: Successfully killed process cgroup uid 10074 pid 1749 in 0ms
11-27 14:26:14.912   584  2583 W system_server: Long monitor contention with owner binder:584_2 (603) at com.android.server.am.ProcessRecord com.android.server.am.ProcessList.removeProcessNameLocked(java.lang.String, int, com.android.server.am.ProcessRecord)(ProcessList.java:3054) waiters=0 in boolean com.android.server.am.ActivityManagerService.isUidActive(int, java.lang.String) for 384ms
11-27 14:26:14.942   584   622 I libprocessgroup: Successfully killed process cgroup uid 10048 pid 1623 in 0ms
11-27 14:26:14.948   584   622 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 1692 in 0ms
11-27 14:26:14.951   584   622 I libprocessgroup: Successfully killed process cgroup uid 10100 pid 1641 in 0ms
11-27 14:26:14.953   584   622 I libprocessgroup: Successfully killed process cgroup uid 10060 pid 1466 in 0ms
11-27 14:26:15.079   584   603 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=3 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 280ms
11-27 14:26:15.166   584   609 W Looper  : Slow dispatch took 698ms android.fg h=com.android.server.DropBoxManagerService$DropBoxManagerBroadcastHandler c=null m=2
11-27 14:26:15.174   584   609 W Looper  : Slow delivery took 215ms android.fg h=android.os.Handler c=com.android.server.power.hint.HintManagerService$UidObserver$$ExternalSyntheticLambda0@21be2f1 m=0
11-27 14:26:15.280   584  1478 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=5 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 434ms
11-27 14:26:15.292   584  2453 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=6 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 408ms
11-27 14:26:15.315   584  1668 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=7 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 429ms
11-27 14:26:15.324   584  4911 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=8 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 438ms
11-27 14:26:15.336   584  4919 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=9 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 445ms
11-27 14:26:15.356   584  4921 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=11 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 467ms
11-27 14:26:15.364   584  4922 W system_server: Long monitor contention with owner binder:584_11 (1670) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=12 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 473ms
11-27 14:26:15.372   584   610 W Looper  : Slow dispatch took 104ms android.ui h=com.android.server.am.ActivityManagerService$UiHandler c=null m=31
11-27 14:26:19.171   881   938 D ControlsListingControllerImpl: Subscribing callback, service count: 0
11-27 14:26:19.295   881   938 D ControlsListingControllerImpl: Unsubscribing callback
11-27 14:26:19.500   881   938 W ndroid.systemui: Long monitor contention with owner main (881) at android.content.res.ApkAssets[] android.content.res.AssetManager.getApkAssets()(AssetManager.java:393) waiters=0 in java.lang.CharSequence android.content.res.AssetManager.getResourceText(int) for 101ms
11-27 14:26:20.080   881   938 W ndroid.systemui: Long monitor contention with owner main (881) at android.content.res.ApkAssets[] android.content.res.AssetManager.getApkAssets()(AssetManager.java:393) waiters=0 in java.lang.CharSequence android.content.res.AssetManager.getResourceText(int) for 139ms
11-27 14:26:32.573   584   598 I system_server: Background young concurrent copying GC freed 160947(11MB) AllocSpace objects, 8(160KB) LOS objects, 47% free, 13MB/25MB, paused 2.030ms,342us total 376.751ms
11-27 14:26:51.861   881  1009 D EGL_emulation: app_time_stats: avg=40243.60ms min=40243.60ms max=40243.60ms count=1
11-27 14:26:57.933  2824  4907 D REALM   : [Sdk] Realm closed: WriterRealm[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:26:57.934  2824  4906 D REALM   : [Sdk] Realm closed: NotifierRealm[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:26:57.936  2824  2840 D REALM   : [Core] DB: 60503 Thread 132530503863536: DB closed
11-27 14:26:57.937  2824  2840 D REALM   : [Sdk] Realm closed: RealmImpl[/data/user/0/io.realm.testapp.test/cache/M3Cco29h9Ub7JsdU-android_tests2699206672845785568/default.realm}]
11-27 14:26:57.944  2824  2840 E TestRunner: failed: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)
11-27 14:26:57.944  2824  2840 E TestRunner: ----- begin exception -----
11-27 14:26:57.945  2824  2840 E TestRunner: kotlinx.coroutines.TimeoutCancellationException: Timeout after 1m: Update event was not received
11-27 14:26:57.945  2824  2840 E TestRunner: 	at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invokeSuspend(Utils.kt:102)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invoke(Unknown Source:8)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$2$2.invoke(Unknown Source:2)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.selects.SelectImplementation$ClauseData.invokeBlock(Select.kt:818)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.selects.SelectImplementation.complete(Select.kt:692)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.selects.SelectImplementation.doSelectSuspend(Select.kt:434)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.selects.SelectImplementation.access$doSelectSuspend(Select.kt:243)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.selects.SelectImplementation$doSelectSuspend$1.invokeSuspend(Unknown Source:14)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:280)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at io.realm.kotlin.test.common.VersionTrackingTests.initialVersionDereferencedAfterFirstWrite(VersionTrackingTests.kt:227)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at java.lang.reflect.Method.invoke(Native Method)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at androidx.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at androidx.test.internal.runner.junit4.statement.RunAfters.evaluate(RunAfters.java:61)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.Suite.runChild(Suite.java:128)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.Suite.runChild(Suite.java:27)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:56)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:444)
11-27 14:26:57.945  2824  2840 E TestRunner: 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2361)
11-27 14:26:57.946  2824  2840 E TestRunner: ----- end exception -----
11-27 14:26:57.955  2824  2840 I TestRunner: finished: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)

I added some logging inside our own asFlow() method, which does seem to receive the correct events which implies that it is the Channel failing to send/receive the events somehow

@cmelchior
Copy link
Contributor Author

Also failing here:

11-29 16:45:56.839  3815  3831 I TestRunner: started: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)
11-29 16:45:56.853  3815  3831 D REALM   : [Sdk] Realm opened: RealmImpl[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:45:56.857  3815  3831 D REALM   : [Core] DB: 15178 Thread 140051152395504: Open file: /data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm
11-29 16:45:56.880  3815  3831 D REALM   : [Core] DB: 15178 Thread 140051152395504: Initiate commit version: 2
11-29 16:45:56.935  3815  3831 D REALM   : [Core] DB: 15178 Thread 140051152395504: Commit of size 77744 done in 54729 us ref 23320
11-29 16:45:56.945  3815  3831 W REALM   : Received from realm.asFlow(). Sending: io.realm.kotlin.notifications.internal.InitialRealmImpl@766f5c7
11-29 16:45:56.954  3815  5914 D REALM   : [Sdk] Realm opened: NotifierRealm[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:45:56.960  3815  5915 D REALM   : [Sdk] Realm opened: WriterRealm[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:45:56.965  3815  5915 D REALM   : [Core] DB: 15178 Thread 140051144916208: Initiate commit version: 3
11-29 16:45:56.988  3815  5915 D REALM   : [Core] DB: 15178 Thread 140051144916208: Commit of size 328 done in 23308 us ref 23448
11-29 16:45:56.996  3815  3820 I lm.testapp.test: JIT allocated 138KB for compiled code of io.realm.kotlin.entities.SerializableSample io.realm.kotlin.entities.SerializableSample$$serializer.deserialize(kotlinx.serialization.encoding.Decoder)
11-29 16:45:57.000  3815  3820 I lm.testapp.test: Compiler allocated 11MB to compile io.realm.kotlin.entities.SerializableSample io.realm.kotlin.entities.SerializableSample$$serializer.deserialize(kotlinx.serialization.encoding.Decoder)
11-29 16:46:00.068  2036  2176 D EGL_emulation: app_time_stats: avg=9909.98ms min=9909.98ms max=9909.98ms count=1
11-29 16:46:21.111  1857  1943 E ActivityManager: Sending non-protected broadcast com.android.bluetooth.btservice.BLUETOOTH_COUNTER_METRICS_ACTION from system uid 1002 pkg com.android.bluetooth
11-29 16:46:21.111  1857  1943 E ActivityManager: java.lang.Throwable
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.ActivityManagerService.checkBroadcastFromSystem(ActivityManagerService.java:13550)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:14268)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.ActivityManagerService.broadcastIntentInPackage(ActivityManagerService.java:14468)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.ActivityManagerService$LocalService.broadcastIntentInPackage(ActivityManagerService.java:16971)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.PendingIntentRecord.sendInner(PendingIntentRecord.java:526)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.PendingIntentRecord.sendWithResult(PendingIntentRecord.java:311)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.am.ActivityManagerService.sendIntentSender(ActivityManagerService.java:5373)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at android.app.PendingIntent.sendAndReturnResult(PendingIntent.java:1012)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at android.app.PendingIntent.send(PendingIntent.java:983)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService$DeliveryTracker.deliverLocked(AlarmManagerService.java:5544)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService.deliverAlarmsLocked(AlarmManagerService.java:4444)
11-29 16:46:21.111  1857  1943 E ActivityManager: 	at com.android.server.alarm.AlarmManagerService$AlarmThread.run(AlarmManagerService.java:4755)
11-29 16:46:21.124  1857  1891 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
11-29 16:46:21.130  1857  1933 W DeviceIdleController: motion timeout went off and device isn't stationary
11-29 16:46:21.140  1857  1891 I ActivityManager: Killing 3277:com.android.onetimeinitializer/u0a82 (adj 965): empty #17
11-29 16:46:21.149  1857  1891 I ActivityManager: Killing 2945:com.android.managedprovisioning/u0a55 (adj 975): empty #18
11-29 16:46:21.150  1857  1891 I ActivityManager: Killing 3207:com.android.dynsystem:dynsystem/1000 (adj 975): empty #19
11-29 16:46:21.151  1857  1891 I ActivityManager: Killing 3194:com.android.dynsystem/1000 (adj 985): empty #20
11-29 16:46:21.152  1857  1891 I ActivityManager: Killing 2480:com.android.deskclock/u0a96 (adj 985): empty #21
11-29 16:46:21.153  1857  1891 I ActivityManager: Killing 3173:com.android.contacts/u0a85 (adj 995): empty #22
11-29 16:46:21.154  1857  1891 I ActivityManager: Killing 3139:com.android.camera2/u0a90 (adj 995): empty #23
11-29 16:46:21.155  1857  1891 I ActivityManager: Killing 3118:com.android.calendar/u0a97 (adj 999): empty #24
11-29 16:46:21.155  1857  1891 I ActivityManager: Killing 3059:com.android.traceur/u0a81 (adj 999): empty #25
11-29 16:46:21.156  1857  1891 I ActivityManager: Killing 2853:com.android.quicksearchbox/u0a94 (adj 999): empty #26
11-29 16:46:21.157  1857  1891 I ActivityManager: Killing 2770:com.android.externalstorage/u0a47 (adj 999): empty #27
11-29 16:46:21.158  1857  1891 I ActivityManager: Killing 2841:com.android.keychain/1000 (adj 999): empty #28
11-29 16:46:21.159  1857  1891 I ActivityManager: Killing 2807:com.android.printspooler/u0a78 (adj 999): empty #29
11-29 16:46:21.160  1857  1891 I ActivityManager: Killing 2780:com.android.localtransport/1000 (adj 999): empty #30
11-29 16:46:21.161  1857  1891 I ActivityManager: Killing 2684:com.android.documentsui/u0a64 (adj 999): empty #31
11-29 16:46:21.164  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10082 pid 3277 in 0ms
11-29 16:46:21.203  3631  3631 I BluetoothMetricsLogger: drainBufferedCounters().
11-29 16:46:21.301  1794  1794 I Zygote  : Process 3139 exited due to signal 9 (Killed)
11-29 16:46:21.303  1794  1794 I Zygote  : Process 2853 exited due to signal 9 (Killed)
11-29 16:46:21.303  1794  1794 I Zygote  : Process 3118 exited due to signal 9 (Killed)
11-29 16:46:21.304  1794  1794 I Zygote  : Process 3059 exited due to signal 9 (Killed)
11-29 16:46:21.308  1794  1794 I Zygote  : Process 3277 exited due to signal 9 (Killed)
11-29 16:46:21.341  1794  1794 I Zygote  : Process 2770 exited due to signal 9 (Killed)
11-29 16:46:21.356  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10055 pid 2945 in 0ms
11-29 16:46:21.378  1794  1794 I Zygote  : Process 3207 exited due to signal 9 (Killed)
11-29 16:46:21.381  1794  1794 I Zygote  : Process 3173 exited due to signal 9 (Killed)
11-29 16:46:21.383  1794  1794 I Zygote  : Process 2841 exited due to signal 9 (Killed)
11-29 16:46:21.383  1794  1794 I Zygote  : Process 2480 exited due to signal 9 (Killed)
11-29 16:46:21.384  1794  1794 I Zygote  : Process 2807 exited due to signal 9 (Killed)
11-29 16:46:21.386  1794  1794 I Zygote  : Process 2780 exited due to signal 9 (Killed)
11-29 16:46:21.391  1794  1794 I Zygote  : Process 3194 exited due to signal 9 (Killed)
11-29 16:46:21.395  1794  1794 I Zygote  : Process 2945 exited due to signal 9 (Killed)
11-29 16:46:21.396  1794  1794 I Zygote  : Process 2684 exited due to signal 9 (Killed)
11-29 16:46:21.398  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 3207 in 0ms
11-29 16:46:21.399  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 3194 in 0ms
11-29 16:46:21.401  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10096 pid 2480 in 0ms
11-29 16:46:21.402  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10085 pid 3173 in 0ms
11-29 16:46:21.403  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10090 pid 3139 in 0ms
11-29 16:46:21.405  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10097 pid 3118 in 0ms
11-29 16:46:21.406  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10081 pid 3059 in 0ms
11-29 16:46:21.437  1857  3630 I ActivityManager: Killing 2739:android.process.media/u0a52 (adj 985): empty #17
11-29 16:46:21.474  1857  3046 W system_server: Long monitor contention with owner binder:1857_14 (3630) at android.app.ApplicationExitInfo com.android.server.am.AppExitInfoTracker.obtainRawRecord(com.android.server.am.ProcessRecord, long)(AppExitInfoTracker.java:1013) waiters=0 in boolean com.android.server.am.ActivityManagerService.isUidActive(int, java.lang.String) for 114ms
11-29 16:46:21.486  1857  2635 W system_server: Long monitor contention with owner binder:1857_14 (3630) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=2 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 128ms
11-29 16:46:21.536  1794  1794 I Zygote  : Process 2739 exited due to signal 9 (Killed)
11-29 16:46:21.588  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10094 pid 2853 in 0ms
11-29 16:46:21.592  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10047 pid 2770 in 0ms
11-29 16:46:21.595  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 2841 in 0ms
11-29 16:46:21.599  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10078 pid 2807 in 0ms
11-29 16:46:21.633  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 1000 pid 2780 in 0ms
11-29 16:46:21.636  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10064 pid 2684 in 0ms
11-29 16:46:21.638  1857  1893 I libprocessgroup: Successfully killed process cgroup uid 10052 pid 2739 in 0ms
11-29 16:46:21.797  1857  2021 W system_server: Long monitor contention with owner binder:1857_A (2319) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1481) waiters=9 in void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied() for 244ms
11-29 16:46:30.255  2036  2157 D ControlsListingControllerImpl: Subscribing callback, service count: 0
11-29 16:46:30.305  2036  2176 D EGL_emulation: app_time_stats: avg=30233.48ms min=30233.48ms max=30233.48ms count=1
11-29 16:46:30.311  2036  2157 D ControlsListingControllerImpl: Unsubscribing callback
11-29 16:46:39.551  1857  3539 D WifiNl80211Manager: Scan result ready event
11-29 16:46:39.551  1857  3539 D WifiNative: Scan result ready event
11-29 16:46:45.843     0     0 W healthd : battery l=100 v=5000 t=25.0 h=2 st=2 c=900000 fc=3000000 cc=10 chg=a
11-29 16:46:57.011  3815  5915 D REALM   : [Sdk] Realm closed: WriterRealm[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:46:57.027  3815  5914 D REALM   : [Sdk] Realm closed: NotifierRealm[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:46:57.030  3815  3831 D REALM   : [Core] DB: 15178 Thread 140051152395504: DB closed
11-29 16:46:57.032  3815  3831 D REALM   : [Sdk] Realm closed: RealmImpl[/data/user/0/io.realm.testapp.test/cache/ePVEnyhFe4fmFQHx-android_tests603118322885044649/default.realm}]
11-29 16:46:57.038  3815  3831 E TestRunner: failed: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)
11-29 16:46:57.040  3815  3831 E TestRunner: ----- begin exception -----
11-29 16:46:57.041  3815  3831 E TestRunner: kotlinx.coroutines.TimeoutCancellationException: Timeout after 1m: Update event was not received
11-29 16:46:57.041  3815  3831 E TestRunner: 	at io.realm.kotlin.test.util.UtilsKt.receiveOrFail-dWUq8MI(Utils.kt:114)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at io.realm.kotlin.test.util.UtilsKt$receiveOrFail$1.invokeSuspend(Unknown Source:15)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:280)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source:1)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source:1)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at io.realm.kotlin.test.common.VersionTrackingTests.initialVersionDereferencedAfterFirstWrite(VersionTrackingTests.kt:228)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at java.lang.reflect.Method.invoke(Native Method)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at androidx.test.internal.runner.junit4.statement.RunBefores.evaluate(RunBefores.java:80)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at androidx.test.internal.runner.junit4.statement.RunAfters.evaluate(RunAfters.java:61)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.Suite.runChild(Suite.java:128)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.Suite.runChild(Suite.java:27)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:56)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:444)
11-29 16:46:57.041  3815  3831 E TestRunner: 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2361)
11-29 16:46:57.042  3815  3831 E TestRunner: ----- end exception -----
11-29 16:46:57.054  3815  3831 I TestRunner: finished: initialVersionDereferencedAfterFirstWrite(io.realm.kotlin.test.common.VersionTrackingTests)

This failure had extensive logging in all our realmChanged listeners, none of them triggered, which point to the problem being in Core somewhere.

The logs also indicate that the write in Core did happen:

11-29 16:45:56.965  3815  5915 D REALM   : [Core] DB: 15178 Thread 140051144916208: Initiate commit version: 3
11-29 16:45:56.988  3815  5915 D REALM   : [Core] DB: 15178 Thread 140051144916208: Commit of size 328 done in 23308 us ref 23448

@cmelchior cmelchior mentioned this issue Dec 11, 2023
Merged
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Mar 18, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
1 participant
@cmelchior