It feels that a Lagom service is not "always" able to re-connect to the cassandra DB. This can happen if the Lagom service is started before the cassandra DB. Tested the behaviour in a ConductR context. More info how to reproduce can be found below.
I am currently not sure if this is a general Lagom issue or if maybe the chirper example has things wrongly implemented. Interesting to note is that during my test the chirp-impl
service couldn't connect to cassandra. The friend-impl
service on the other hand could successfully re-connect to cassandra. Both services have been started before the cassandra bundle. More info can be found below in the Logs section.
How to reproduce
Tested the behaviour with chirper on ConductR 1.1.3:
cd activator-lagom-java-chirper
sbt
sandbox run 1.1.3 --feature logging
bundle:dist
conduct load <chirp-impl-bundle>
conduct load <activity-stream-impl-bundle>
conduct load <friend-impl-bundle>
project front-end
configuration:dist
conduct load <front-end-impl-bundle> <front-end-impl-configuration>
project /
cassandra-configuration:dist
conduct load cassandra <cassandra-configuration>
conduct run --no-wait activity
conduct run --no-wait friend
conduct run --no-wait chirp
conduct run front
conduct run cassandra
It is important to start the cassandra bundle at last.
When using chirper in the browser, it is possible to sign up a user. But it is not possible to post chirps.
Use then conduct logs <bundle>
to display the logging for a bundle.
Logs
chirp-impl
The following stack trace shows that the chirp service periodically tries to re-connect to the cassandra DB, usually 5 times before logging an error. At 13:11:39 you can see that it tries it the fourth time. Afterwards no error is thrown. Maybe the re-connecting algorithm is broken here?
> conduct logs -n 100 chirp
TIME HOST LOG
13:11:36 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:36 860d8dbb3847 [error] s.c.c.i.ChirpServiceImpl - Failed to create chirp table, due to: No contact points for [cas_native]
com.lightbend.lagom.internal.persistence.cassandra.NoContactPointsException: No contact points for [cas_native]
13:11:37 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:38 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:39 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:39 860d8dbb3847 [warn] a.p.c.j.CassandraJournal - Failed to connect to Cassandra and initialize. It will be retried on demand. Caused by: No contact points for [cas_native]
13:15:38 860d8dbb3847 [error] chirpservice - Exception in PathCallId{pathPattern='/api/chirps/live'}
java.util.concurrent.ExecutionException: com.datastax.driver.core.exceptions.InvalidQueryException: unconfigured table chirp
at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:476) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:435) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.get(AbstractFuture.java:79) ~[com.google.guava.guava-19.0.jar:na]
at com.lightbend.lagom.internal.persistence.cassandra.CassandraSessionImpl$ListenableFutureConverter$$anon$1$$anonfun$run$1.apply(CassandraSessionImpl.scala:62) ~[com.lightbend.lagom.lagom-javadsl-persistence_2.11-1.0.0-SNAPSHOT.jar:1.0.0-SNAPSHOT]
at scala.util.Try$.apply(Try.scala:192) ~[org.scala-lang.scala-library-2.11.7.jar:na]
at com.lightbend.lagom.internal.persistence.cassandra.CassandraSessionImpl$ListenableFutureConverter$$anon$1.run(CassandraSessionImpl.scala:62) ~[com.lightbend.lagom.lagom-javadsl-persistence_2.11-1.0.0-SNAPSHOT.jar:1.0.0-SNAPSHOT]
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39) ~[com.typesafe.akka.akka-actor_2.11-2.4.2.jar:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_66-internal]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_66-internal]
at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_66-internal]
Caused by: com.datastax.driver.core.exceptions.InvalidQueryException: unconfigured table chirp
at com.datastax.driver.core.Responses$Error.asException(Responses.java:136) ~[com.datastax.cassandra.cassandra-driver-core-3.0.0.jar:na]
at com.datastax.driver.core.SessionManager$4.apply(SessionManager.java:220) ~[com.datastax.cassandra.cassandra-driver-core-3.0.0.jar:na]
at com.datastax.driver.core.SessionManager$4.apply(SessionManager.java:196) ~[com.datastax.cassandra.cassandra-driver-core-3.0.0.jar:na]
at com.google.common.util.concurrent.Futures$AsyncChainingFuture.doTransform(Futures.java:1442) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.Futures$AsyncChainingFuture.doTransform(Futures.java:1433) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.Futures$AbstractChainingFuture.run(Futures.java:1408) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:456) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:817) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:753) ~[com.google.guava.guava-19.0.jar:na]
at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:613) ~[com.google.guava.guava-19.0.jar:na]
activity-impl
Stacktrace for completion..
> conduct logs -n 100 activity
TIME HOST LOG
13:15:38 860d8dbb3847 [error] activityservice - Exception in PathCallId{pathPattern='/api/activity/:userId/live'}
com.lightbend.lagom.javadsl.api.transport.TransportException:
at com.lightbend.lagom.javadsl.api.transport.TransportException.fromCodeAndMessage(TransportException.java:49) ~[com.lightbend.lagom.lagom-javadsl-api_2.11-1.0.0-SNAPSHOT.jar:1.0.0-SNAPSHOT]
at com.lightbend.lagom.javadsl.jackson.JacksonExceptionSerializer.deserialize(JacksonExceptionSerializer.java:83) ~[com.lightbend.lagom.lagom-javadsl-jackson_2.11-1.0.0-SNAPSHOT.jar:1.0.0-SNAPSHOT]
at com.lightbend.lagom.internal.client.WebSocketSupervisor.channelRead(WebSocketClient.scala:243) ~[com.lightbend.lagom.lagom-javadsl-client_2.11-1.0.0-SNAPSHOT.jar:1.0.0-SNAPSHOT]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:307) ~[io.netty.netty-transport-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:293) ~[io.netty.netty-transport-4.0.34.Final.jar:4.0.34.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:276) ~[io.netty.netty-codec-4.0.34.Final.jar:4.0.34.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:263) ~[io.netty.netty-codec-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:307) ~[io.netty.netty-transport-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:293) ~[io.netty.netty-transport-4.0.34.Final.jar:4.0.34.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:840) ~[io.netty.netty-transport-4.0.34.Final.jar:4.0.34.Final]
friend-impl
Here it seems that the cassandra re-connection was successful. In fact, I was able to sign up new users which I believe is only possible if the DB is available and a connection has been established.
> conduct logs -n 100 friend
TIME HOST LOG
13:11:27 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:27 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:27 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
13:11:27 860d8dbb3847 [error] a.a.OneForOneStrategy - com.lightbend.lagom.internal.persistence.cassandra.NoContactPointsException: No contact points for [cas_native]
java.util.concurrent.CompletionException: com.lightbend.lagom.internal.persistence.cassandra.NoContactPointsException: No contact points for [cas_native]
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[na:1.8.0_66-internal]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[na:1.8.0_66-internal]
at java.util.concurrent.CompletableFuture.uniCompose(CompletableFuture.java:943) ~[na:1.8.0_66-internal]
at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:926) ~[na:1.8.0_66-internal]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[na:1.8.0_66-internal]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[na:1.8.0_66-internal]
at scala.concurrent.java8.FuturesConvertersImpl$CF.apply(FutureConvertersImpl.scala:21) ~[org.scala-lang.modules.scala-java8-compat_2.11-0.7.0.jar:na]
at scala.concurrent.java8.FuturesConvertersImpl$CF.apply(FutureConvertersImpl.scala:18) ~[org.scala-lang.modules.scala-java8-compat_2.11-0.7.0.jar:na]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32) ~[org.scala-lang.scala-library-2.11.7.jar:na]
at scala.concurrent.BatchingExecutor$Batch$$anonfun$run$1.processBatch$1(BatchingExecutor.scala:63) ~[org.scala-lang.scala-library-2.11.7.jar:na]
Caused by: com.lightbend.lagom.internal.persistence.cassandra.NoContactPointsException: No contact points for [cas_native]
13:11:27 860d8dbb3847 [warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: No contact points for [cas_native]
...
...
...
13:12:13 860d8dbb3847 [warn] a.c.s.ShardRegion - Trying to register to coordinator at [Some(ActorSelection[Anchor(akka://friend-impl-1/), Path(/system/sharding/FriendEntityCoordinator/singleton/coordinator)])], but no acknowledgement. Total [3] buffered messages.
13:12:15 860d8dbb3847 [warn] a.c.s.ShardRegion - Trying to register to coordinator at [Some(ActorSelection[Anchor(akka://friend-impl-1/), Path(/system/sharding/FriendEntityCoordinator/singleton/coordinator)])], but no acknowledgement. Total [4] buffered messages.
13:12:15 860d8dbb3847 [warn] a.c.s.ShardRegion - Retry request for shard [16] homes from coordinator at [Actor[akka://friend-impl-1/system/sharding/FriendEntityCoordinator/singleton/coordinator#1449747217]]. [4] buffered messages.
13:12:15 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:23 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:35 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:36 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:37 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:37 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:38 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created
13:13:50 860d8dbb3847 [error] friendservice - Exception in RestCallId{method=POST, pathPattern='/api/users'}
com.lightbend.lagom.javadsl.persistence.PersistentEntity$InvalidCommandException: User qq is already created