search

lagom / lagom-java-chirper-example

Deprecated: use https://github.com/lagom/lagom-java-sbt-chirper-example or https://github.com/lagom/lagom-java-maven-chirper-example
Apache License 2.0
45 stars 62 forks source link

Errors logged during runAll shutdown #34

Closed huntc closed 6 years ago

huntc commented 8 years ago

Kafka didn't take kindly to being shutdown upon terminating with runAll:

[info] Stopping Kafka...
[error] i.n.u.c.D.rejectedExecution - Failed to submit a listener notification task. Event loop shut down?
java.util.concurrent.RejectedExecutionException: event executor terminated
    at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:800)
    at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:345)
    at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:338)
    at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:743)
    at io.netty.util.concurrent.DefaultPromise.safeExecute(DefaultPromise.java:767)
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:435)
    at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:120)
    at io.netty.channel.DefaultChannelPromise.setFailure(DefaultChannelPromise.java:87)
    at io.netty.channel.AbstractChannelHandlerContext.safeExecute(AbstractChannelHandlerContext.java:1005)
    at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:614)
[error] i.n.u.c.D.rejectedExecution - Failed to submit a listener notification task. Event loop shut down?
java.util.concurrent.RejectedExecutionException: event executor terminated
    at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:800)
    at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:345)
    at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:338)
    at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:743)
    at io.netty.util.concurrent.DefaultPromise.safeExecute(DefaultPromise.java:767)
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:435)
    at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:120)
    at io.netty.channel.DefaultChannelPromise.setFailure(DefaultChannelPromise.java:87)
    at io.netty.channel.AbstractChannelHandlerContext.safeExecute(AbstractChannelHandlerContext.java:1005)
    at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:614)
[error] i.n.u.c.D.rejectedExecution - Failed to submit a listener notification task. Event loop shut down?
java.util.concurrent.RejectedExecutionException: event executor terminated
    at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:800)
    at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:345)
    at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:338)
    at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:743)
    at io.netty.util.concurrent.DefaultPromise.safeExecute(DefaultPromise.java:767)
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:435)
    at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:120)
    at io.netty.channel.DefaultChannelPromise.setFailure(DefaultChannelPromise.java:87)
    at io.netty.channel.AbstractChannelHandlerContext.safeExecute(AbstractChannelHandlerContext.java:1005)
    at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:614)
[info] Kafka is stopped.
TimMoore commented 8 years ago

These messages aren't related to Kafka specifically... they just happen to be concurrently logged. I'll update the issue title accordingly.

TimMoore commented 8 years ago

To reproduce this, you need to create a chirp sometime before shutting down. Just starting runAll and immediately stopping won't do it.

jewelsjacobs commented 7 years ago

This actually happens in the HelloWorld example as well (no chirp needed 🐤 ).

jewelsjacobs commented 7 years ago

When I enabled Kafka it no longer occurs and I am able to hot reload (just other issues):

[info] Loading global plugins from /Users/juliajacobs/.sbt/0.13/plugins
[info] Loading project definition from /Users/juliajacobs/IdeaProjects/activator-lagom-java-chirper-master/project
[info] Set current project to activator-lagom-java-chirper-master (in build file:/Users/juliajacobs/IdeaProjects/activator-lagom-java-chirper-master/)
> runAll
[info] Starting Kafka
[info] Starting Cassandra
.SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
................
[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] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: ServiceLocator is not bound
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: ServiceLocator is not bound
[warn] c.l.l.i.p.c.ServiceLocatorSessionProvider - Could not find Cassandra contact points, due to: ServiceLocator is not bound
[warn] a.p.c.j.CassandraJournal - Failed to connect to Cassandra and initialize. It will be retried on demand. Caused by: ServiceLocator is not bound
[info] Service activity-stream-impl listening for HTTP on 0:0:0:0:0:0:0:0:51855
[info] Service friend-impl listening for HTTP on 0:0:0:0:0:0:0:0:60399
[info] Service chirp-impl listening for HTTP on 0:0:0:0:0:0:0:0:54485
[info] Service front-end listening for HTTP on 0:0:0:0:0:0:0:0:57143
[info] Service load-test-impl listening for HTTP on 0:0:0:0:0:0:0:0:51796
[info] (Services started, press enter to stop and go back to the console...)
[error] activityservice - Exception in PathCallId{pathPattern='/api/activity/:userId/live'}
akka.pattern.CircuitBreaker$$anon$1: Circuit Breaker Timed out.
[info] Compiling 1 Java source to /Users/juliajacobs/IdeaProjects/activator-lagom-java-chirper-master/chirp-impl/target/scala-2.11/classes...

--- (RELOAD) ---

[error] a.a.OneForOneStrategy - Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-10-1-unknown-operation#-246790301]] terminated abruptly
akka.stream.AbruptTerminationException: Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-10-1-unknown-operation#-246790301]] terminated abruptly
[error] a.a.OneForOneStrategy - Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-11-1-unknown-operation#-1045189735]] terminated abruptly
akka.stream.AbruptTerminationException: Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-11-1-unknown-operation#-1045189735]] terminated abruptly
[error] a.a.OneForOneStrategy - Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-9-1-unknown-operation#-1878967675]] terminated abruptly
akka.stream.AbruptTerminationException: Processor actor [Actor[akka://chirp-impl-application/user/StreamSupervisor-1/flow-9-1-unknown-operation#-1878967675]] terminated abruptly
TimMoore commented 7 years ago

@jewelsjacobs it's most likely coincidental that enabling Kafka made the errors go away. This app doesn't make use of Kafka at all. The "errors" noted originally in this issue happen because of timing inconsistencies during shutdown, but they are harmless.

Were you having problems hot reloading before enabling Kafka? If you can share the details in Gitter or on the mailing list, we can help figure out what the problem was.

The errors you're seeing now are also harmless. The nature of distributed microservices is that partial failure is "normal" and Lagom is designed to be able to recover. When different components of the system are starting asynchronously, and two of them need to communicate, one won't be able to know whether the other is available without trying to talk to it. If that fails, it handles the failure and tries again later. We don't want to suppress the errors entirely (after all, maybe it will just keep failing forever) so they are logged, but it's admittedly alarming to see these errors without explanation when just getting started. We will try to make these more comprehensible in the future.

TimMoore commented 6 years ago

This was resolved by updating to Lagom 1.4.