akka / akka-persistence-r2dbc

https://doc.akka.io/docs/akka-persistence-r2dbc/current/index.html
Other
24 stars 17 forks source link

Flaky failure in ChaosSpec #54

Closed octonato closed 3 years ago

octonato commented 3 years ago

https://github.com/akka/akka-persistence-r2dbc/runs/3968156162?check_suite_focus=true#step:7:11286 for PR #52

[akka.projection.r2dbc.ChaosSpec: A R2DBC projection under random conditions must handle all events exactlyOnce] End of log messages of test that [Failed(java.lang.AssertionError: Timeout (15 seconds) during receiveMessage while waiting for message.)]
[info] - must handle all events exactlyOnce *** FAILED *** (23 seconds, 779 milliseconds)
[info]   java.lang.AssertionError: Timeout (15 seconds) during receiveMessage while waiting for message.
[info]   at akka.actor.testkit.typed.internal.TestProbeImpl.assertFail(TestProbeImpl.scala:399)
[info]   at akka.actor.testkit.typed.internal.TestProbeImpl.$anonfun$receiveMessage_internal$1(TestProbeImpl.scala:182)
[info]   at scala.Option.getOrElse(Option.scala:201)
[info]   at akka.actor.testkit.typed.internal.TestProbeImpl.receiveMessage_internal(TestProbeImpl.scala:182)
[info]   at akka.actor.testkit.typed.internal.TestProbeImpl.receiveMessage(TestProbeImpl.scala:179)
[info]   at akka.projection.r2dbc.ChaosSpec.$anonfun$new$7(ChaosSpec.scala:194)
[info]   at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:190)
[info]   at akka.projection.r2dbc.ChaosSpec.verify$1(ChaosSpec.scala:191)
[info]   at akka.projection.r2dbc.ChaosSpec.$anonfun$new$15(ChaosSpec.scala:298)
[info]   at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:190)
[info]   at akka.projection.r2dbc.ChaosSpec.$anonfun$new$2(ChaosSpec.scala:228)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
patriknw commented 3 years ago

From the logs:

[2021-10-21 19:21:07,368] [DEBUG] [akka.projection.r2dbc.ChaosSpec] [] [] [pool-1-thread-1-ScalaTest-running-ChaosSpec] - Persisting event [e00135], it will fail in projection [2] times
[2021-10-21 19:21:07,375] [DEBUG] [akka.projection.r2dbc.EndToEndSpec$Persister$] [akka://ChaosSpec] [] [ChaosSpec-akka.actor.default-dispatcher-14] - Persist [e00135], pid [TestEntity-2|p14], seqNr [1]

Error: 0-21 19:21:07,506] [ERROR] [akka.projection.r2dbc.internal.R2dbcProjectionImpl$R2dbcInternalProjectionState] [akka://ChaosSpec] [] [ChaosSpec-akka.actor.default-dispatcher-15] - [a3cd047a-bcd7-4884-941c-cdd975e50da7-64-127] Failed to process envelope with offset [TimestampOffset(2021-10-21T19:21:07.378910Z,2021-10-21T19:21:07.497873Z,Map(TestEntity-2|p14 -> 1))]. Projection will stop as defined by recovery strategy.
12543
akka.actor.testkit.typed.TestException: Fail event [e00135]

[2021-10-21 19:21:08,047] [DEBUG] [akka.projection.r2dbc.internal.R2dbcProjectionImpl] [] [] [ChaosSpec-akka.actor.default-dispatcher-8] - Filtering out rejected sequence number (might be accepted later): EventEnvelope(TimestampOffset(2021-10-21T19:21:07.378910Z,2021-10-21T19:21:08.045711Z,Map(TestEntity-2|p14 -> 1)), TestEntity-2|p14, 1)

[2021-10-21 19:21:13,267] [DEBUG] [akka.projection.r2dbc.ChaosSpec$FailingTestHandler] [] [] [ChaosSpec-akka.actor.default-dispatcher-8] - 64-127 Processed event [e00231], pid [TestEntity-2|p14], seqNr [2]

So it's an event that is simulated to fail, and after that it is rejected. After such fail it should read offset again from OffsetStore and then the state is cleared. The mistake (introduced in a recent PR) is that the seen isn't cleared there. I'll fix this.