dnvriend / akka-persistence-inmemory

Akka-persistence-inmemory is a plugin for akka-persistence that stores journal and snapshot messages memory, which is very useful when testing persistent actors, persistent FSM and akka cluster
Apache License 2.0
134 stars 41 forks source link

fix race condition in cleanup helper #22

Closed acjay closed 8 years ago

acjay commented 8 years ago

I cut-and-pasted cleanup into my own project and was experiencing test failures about 50% of the time. With the rearrangement, I've run my tests 25 times in a row without any failures. (This is using v1.2.1 of this library, to prevent the error mentioned https://github.com/dnvriend/akka-persistence-inmemory/issues/21#issuecomment-191596529.)

I haven't been able to convince myself of exactly where the race is, so I don't think I can write a test to replicate the problem. So feel free to not merge if that makes you uncomfortable.

In case it's helpful, when it errored, I saw the following in the logging/diagnostic printing:

[info] - must work correct if ValidationResponse is sent directly back to the log
Instantiating log
Log instantiated.
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
[DEBUG] [03/03/2016 01:26:04.719] [default-akka.persistence.dispatchers.default-plugin-dispatcher-6] [akka://default/system/inmemory-snapshot-store] Loading for persistenceId: domainEvents:test-12, criteria: SnapshotSelectionCriteria(9223372036854775807,9223372036854775807,0,0)
[DEBUG] [03/03/2016 01:26:04.720] [default-akka.persistence.dispatchers.default-plugin-dispatcher-5] [akka://default/system/inmemory-journal] Async read for highest sequence number for processorId: domainEvents:test-12 (hint, seek from  nr: 0)
Recovery completed
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
QueryEvents (data: EventLogData(None,List(Timestamped(TestEvent1(test-12),2016-03-03T01:26:04.721-05:00), Timestamped(TestEvent2(test-12),2016-03-03T01:26:04.724-05:00))))
Logs: Map(test-12 -> Actor[akka://default/user/$p/test-12#1823397508])
Log terminated. Logs: Map()
[INFO] [03/03/2016 01:26:04.742] [default-akka.actor.default-dispatcher-4] [akka://default/user/$p/test-12] Message [net.artsy.atomic.AtomicEventStore$QueryEvents$] from Actor[akka://default/system/testActor-1#-1378593046] to Actor[akka://default/user/$p/test-12#1823397508] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[info] - must regenerate dead log actor that had two events, with state intact *** FAILED ***
[info]   java.lang.AssertionError: assertion failed: expected: list of one event but got unexpected message Result(false,TestEvent2(test-4),List(Timestamped(TestEvent1(test-4),2016-03-03T01:26:04.651-05:00)),Some(Timeout))
[info]   at scala.Predef$.assert(Predef.scala:165)
[info]   at akka.testkit.TestKitBase$class.expectMsgPF(TestKit.scala:369)
[info]   at net.artsy.atomic.AtomicEventStoreSpec.expectMsgPF(AtomicEventStoreSpec.scala:15)
[info]   at net.artsy.atomic.AtomicEventStoreSpec$$anonfun$3$$anonfun$apply$mcV$sp$19$$anonfun$apply$mcV$sp$20.apply$mcV$sp(AtomicEventStoreSpec.scala:431)
[info]   at net.artsy.atomic.AtomicEventStoreSpec$$anonfun$3$$anonfun$apply$mcV$sp$19$$anonfun$apply$mcV$sp$20.apply(AtomicEventStoreSpec.scala:395)
[info]   at net.artsy.atomic.AtomicEventStoreSpec$$anonfun$3$$anonfun$apply$mcV$sp$19$$anonfun$apply$mcV$sp$20.apply(AtomicEventStoreSpec.scala:395)
[info]   at akka.testkit.TestKitBase$class.within(TestKit.scala:308)
[info]   at net.artsy.atomic.AtomicEventStoreSpec.within(AtomicEventStoreSpec.scala:15)
[info]   at akka.testkit.TestKitBase$class.within(TestKit.scala:322)
[info]   at net.artsy.atomic.AtomicEventStoreSpec.within(AtomicEventStoreSpec.scala:15)
[info]   ...
[INFO] [03/03/2016 01:26:07.679] [default-akka.actor.default-dispatcher-7] [akka://default/user/$i] Message [akka.persistence.fsm.PersistentFSM$TimeoutMarker] from Actor[akka://default/user/$i#-1299734467] to Actor[akka://default/user/$i#-1299734467] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
dnvriend commented 8 years ago

Thanks!