search

lagom / online-auction-scala

Other
200 stars 128 forks source link

a.a.OneForOneStrategy - Ask timed out #9

Open bcabs opened 7 years ago

bcabs commented 7 years ago

When running the example locally, I get the following error:

[error] a.a.OneForOneStrategy - Ask timed out on [Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singletonProxy#1865177863]] after [20000 ms]. Sender[null] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$".
akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singletonProxy#1865177863]] after [20000 ms]. Sender[null] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$".
    at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:604) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:126) ~[akka-actor_2.11-2.4.16.jar:na]
    at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:601) ~[scala-library-2.11.8.jar:na]
    at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109) ~[scala-library-2.11.8.jar:na]
    at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:599) ~[scala-library-2.11.8.jar:na]
    at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(LightArrayRevolverScheduler.scala:329) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.executeBucket$1(LightArrayRevolverScheduler.scala:280) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:284) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:236) ~[akka-actor_2.11-2.4.16.jar:na]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_102]

Found someone having a similar symptom here but cannot extrapolate this to my own issue. Using sbt 0.13.11.

Thanks for your attention.

TimMoore commented 7 years ago

@bcabs what did it print before that?

bcabs commented 7 years ago

@TimMoore Unfortunately, I havn't been able to reproduce that error, but did manage to produce the following:

netstat is not showing anything running on 9200 

> runAll
[info] Starting Kafka
[info] Starting Cassandra
.......................
[info] Cassandra server running at 127.0.0.1:4000
[info] Service locator is running at http://localhost:8000
[info] Service gateway is running at http://localhost:9000
[info] Service webGateway listening for HTTP on 0:0:0:0:0:0:0:0:60496
[info] Service userImpl listening for HTTP on 0:0:0:0:0:0:0:0:56181
[info] Service searchImpl listening for HTTP on 0:0:0:0:0:0:0:0:55320
[info] Service biddingImpl listening for HTTP on 0:0:0:0:0:0:0:0:58427
[info] Service itemImpl listening for HTTP on 0:0:0:0:0:0:0:0:53203
[info] (Services started, press enter to stop and go back to the console...)
[error] a.a.OneForOneStrategy - Connection refused: /127.0.0.1:9200
java.net.ConnectException: Connection refused: /127.0.0.1:9200
    at org.asynchttpclient.netty.channel.NettyConnectListener.onFailure(NettyConnectListener.java:160) ~[async-http-client-2.0.11.jar:na]
    at org.asynchttpclient.netty.request.NettyChannelConnector$1.onFailure(NettyChannelConnector.java:103) ~[async-http-client-2.0.11.jar:na]
    at org.asynchttpclient.netty.SimpleChannelFutureListener.operationComplete(SimpleChannelFutureListener.java:28) ~[async-http-client-2.0.11.jar:na]
    at org.asynchttpclient.netty.SimpleChannelFutureListener.operationComplete(SimpleChannelFutureListener.java:20) ~[async-http-client-2.0.11.jar:na]
    at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:514) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:507) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:486) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:427) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:129) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:278) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /127.0.0.1:9200
    at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[na:1.8.0_102]
    at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) ~[na:1.8.0_102]
    at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:257) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:291) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:628) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:552) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:466) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438) ~[netty-transport-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:140) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144) ~[netty-common-4.0.41.Final.jar:4.0.41.Final]
bcabs commented 7 years ago

caught it! 

> runAll
[info] Starting Kafka
[info] Starting Cassandra
.....................
[info] Cassandra server running at 127.0.0.1:4000
[info] Service locator is running at http://localhost:8000
[info] Service gateway is running at http://localhost:9000
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[error] a.a.OneForOneStrategy - Ask timed out on [Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#132137402]] after [20000 ms]. Sender[Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#132137402]] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$".
akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#132137402]] after [20000 ms]. Sender[Actor[akka://biddingImpl-application/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#132137402]] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$".
    at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:604) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:126) ~[akka-actor_2.11-2.4.16.jar:na]
    at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:601) ~[scala-library-2.11.8.jar:na]
    at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109) ~[scala-library-2.11.8.jar:na]
    at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:599) ~[scala-library-2.11.8.jar:na]
    at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(LightArrayRevolverScheduler.scala:329) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.executeBucket$1(LightArrayRevolverScheduler.scala:280) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:284) ~[akka-actor_2.11-2.4.16.jar:na]
    at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:236) ~[akka-actor_2.11-2.4.16.jar:na]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_102]
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[warn] a.k.KafkaConsumerActor - Consumer interrupted with WakeupException after timeout. Message: null. Current value of akka.kafka.consumer.wakeup-timeout is 3000 milliseconds
[info] Service webGateway listening for HTTP on 0:0:0:0:0:0:0:0:60496
[info] Service userImpl listening for HTTP on 0:0:0:0:0:0:0:0:56181
[info] Service searchImpl listening for HTTP on 0:0:0:0:0:0:0:0:55320
[info] Service biddingImpl listening for HTTP on 0:0:0:0:0:0:0:0:58427
[info] Service itemImpl listening for HTTP on 0:0:0:0:0:0:0:0:53203
[info] (Services started, press enter to stop and go back to the console

I've noticed that the akka.kafka.consumer.wakeup-timeout messages appear whenever trying to runAll twice within the same sbt invocation - hence this might have to do with not sufficiently tearing down the previous instantiation.

t1anchen commented 6 years ago

same issue +1

scalaVersion 2.12.4 sbtVersion 0.13.6 lagom 1.4.0

ignasi35 commented 6 years ago

Connection refused: /127.0.0.1:9200 is unrelated. It just indicates that ElasticSearch can't be contacted. ElasticSearch is not managed by sbt and is meant to be started manually.

TimMoore commented 6 years ago

Does the application actually work when you see this @au9ustine? Can you add your console output to the issue?

Suspect that the ask timeout could be caused by under-powered machines that can't start everything fast enough, but I would also expect this to automatically retry and correct itself eventually.

berk-can commented 6 years ago

This issue seems relatively old but I could reproduce error,

akka.actor.OneForOneStrategy [sourceThread=device-shadow-svc-akka.actor.default-dispatcher-18, akkaTimestamp=08:46:31.463UTC, akkaSource=akka://device-shadow-svc/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare, sourceActorSystem=device-shadow-svc] - Ask timed out on [Actor[akka://device-shadow-svc/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#-1385226940]] after [20000 ms]. Sender[Actor[akka://device-shadow-svc/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#-1385226940]] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$". akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://device-shadow-svc/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#-1385226940]] after [20000 ms]. Sender[Actor[akka://device-shadow-svc/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare#-1385226940]] sent message of type "com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor$Execute$". at akka.pattern.PromiseActorRef$.$anonfun$defaultOnTimeout$1(AskSupport.scala:596) at akka.pattern.PromiseActorRef$.$anonfun$apply$1(AskSupport.scala:606) at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:205) at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:866) at scala.concurrent.BatchingExecutor.execute(BatchingExecutor.scala:109) at scala.concurrent.BatchingExecutor.execute$(BatchingExecutor.scala:103) at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:864) at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(LightArrayRevolverScheduler.scala:328) at akka.actor.LightArrayRevolverScheduler$$anon$4.executeBucket$1(LightArrayRevolverScheduler.scala:279) at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:283) at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:235) at java.lang.Thread.run(Thread.java:748) 2018-06-28T08:46:34.693Z [info] com.lightbend.lagom.internal.persistence.cluster.ClusterStartupTaskActor [sourceThread=device-shadow-svc-akka.actor.default-dispatcher-17, akkaTimestamp=08:46:34.693UTC, akkaSource=akka.tcp://device-shadow-svc@10.233.120.243:10001/user/cassandraOffsetStorePrepare-singleton/singleton/cassandraOffsetStorePrepare, sourceActorSystem=device-shadow-svc] - Executing cluster start task cassandraOffsetStorePrepare.

Is there anything new about the issue so far?

Somuncu commented 6 years ago

[ERROR] a.a.OneForOneStrategy - Ask timed out on I have this error. Have any idea to fix it for my error ?