Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Dataproc: RejectedExecutionException: event executor terminated #5810

Closed
xCASx opened this issue Jul 23, 2019 · 7 comments
Closed

Dataproc: RejectedExecutionException: event executor terminated #5810

xCASx opened this issue Jul 23, 2019 · 7 comments
Assignees
@chingor13
Labels
external This issue is blocked on a bug with the actual product. priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns.

Comments

@xCASx
Copy link

xCASx commented Jul 23, 2019

Thanks for stopping by to let us know something could be better!

PLEASE READ: If you have a support contract with Google, please create an issue in the support console instead of filing on GitHub. This will ensure a timely response.

Please run down the following list and make sure you've tried the usual "quick fixes":

If you are still having issues, please be sure to include as much information as possible:

Environment details

  1. Specify the API at the beginning of the title (for example, "BigQuery: ...")
    General, Core, and Other are also allowed as types
  2. OS type and version: Linux
  3. Java version:
    openjdk version "1.8.0_222"
    OpenJDK Runtime Environment (Zulu 8.40.0.25-CA-linux64) (build 1.8.0_222-b10)
    OpenJDK 64-Bit Server VM (Zulu 8.40.0.25-CA-linux64) (build 25.222-b10, mixed mode)
  4. google-cloud-java version(s): 0.99.0-alpha

Steps to reproduce

  1. Not clear, intermittent bug.

Code example

    public ClusterControllerClient client(String region) throws IOException {
        return ClusterControllerClient.create(ClusterControllerSettings.newBuilder().setEndpoint(String.format("%s-dataproc.googleapis.com:443", region)).build());
    }
        List<Cluster> result = new ArrayList<>();
        for (String region : regions) {
            try (ClusterControllerClient clusterControllerClient = this.clusterRepository.client(region)) {
                for (com.google.cloud.dataproc.v1beta2.Cluster cluster : this.clusterRepository.list(clusterControllerClient, projectId, region)) {
                    if (filter.apply(cluster)) {
                        result.add(transformer.apply(cluster, region));
                    }
                }
            }
        }

Stack trace

...
2019-07-22 19:21:14.449 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.io.netty.handler.ssl.SslHandler  : [id: 0x4a080b0a, [SANITIZED]] HANDSHAKEN: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256
2019-07-22 19:21:14.449 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
2019-07-22 19:21:14.449 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
2019-07-22 19:21:14.455 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=16384}
2019-07-22 19:21:14.455 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND SETTINGS: ack=true
2019-07-22 19:21:14.456 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
2019-07-22 19:21:14.463 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND SETTINGS: ack=true
2019-07-22 19:21:14.566 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: dataproc.googleapis.com:443, :path: /google.cloud.dataproc.v1beta2.ClusterController/ListClusters, :method: POST, :scheme: https, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.21.0, x-goog-api-client: gl-java/1.8.0_222 gapic/0.99.0-alpha gax/1.47.1 grpc/1.21.0, grpc-accept-encoding: gzip, authorization: Bearer [SANITIZED], grpc-timeout: 9767438u] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
2019-07-22 19:21:14.567 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=51 bytes=000000002e0a1e626967646174612d696e676573742d6576616c756174652d6576656e7473220c6575726f70652d7765737434
2019-07-22 19:21:14.669 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-disposition: attachment, content-type: application/grpc, date: Mon, 22 Jul 2019 18:21:14 GMT] padding=0 endStream=false
2019-07-22 19:21:14.670 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=7651 bytes=00000042e50ac64f0a1e626967646174612d696e676573742d6576616c756174652d6576656e7473122c626967646174612d34313430623337372d343730302d...
2019-07-22 19:21:14.675 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=8192 bytes=485245414453120131126d0a23737061726b3a737061726b2e686973746f72792e66732e6c6f674469726563746f7279124667733a2f2f626f6f6b696e672d68...
2019-07-22 19:21:14.675 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=1287 bytes=7465722d6e616d65122c626967646174612d66326438356534652d343866632d343537352d623162322d34316664373863333830353742420a1a676f6f672d64...
2019-07-22 19:21:14.675 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, content-disposition: attachment] padding=0 endStream=true
2019-07-22 19:21:14.676 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] INBOUND PING: ack=false bytes=0
2019-07-22 19:21:14.676 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND PING: ack=true bytes=0
2019-07-22 19:21:15.076 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x4a080b0a, [SANITIZED]] OUTBOUND GO_AWAY: lastStreamId=0 errorCode=0 length=0 bytes=
2019-07-22 19:21:16.078 request_id:0 DEBUG 1 --- [worker-ELG-16-1] i.g.n.s.io.netty.buffer.PoolThreadCache  : Freed 23 thread-local buffer(s) from thread: grpc-default-worker-ELG-16-1
2019-07-22 19:37:45.877 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.io.netty.handler.ssl.SslHandler  : [id: 0x1b568745, [SANITIZED]] HANDSHAKEN: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256
2019-07-22 19:37:45.878 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
2019-07-22 19:37:45.878 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
2019-07-22 19:37:45.884 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=16384}
2019-07-22 19:37:45.884 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND SETTINGS: ack=true
2019-07-22 19:37:45.884 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
2019-07-22 19:37:45.890 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND SETTINGS: ack=true
2019-07-22 19:37:45.968 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: dataproc.googleapis.com:443, :path: /google.cloud.dataproc.v1beta2.ClusterController/ListClusters, :method: POST, :scheme: https, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.21.0, x-goog-api-client: gl-java/1.8.0_222 gapic/0.99.0-alpha gax/1.47.1 grpc/1.21.0, grpc-accept-encoding: gzip, authorization: Bearer [SANITIZED], grpc-timeout: 9861260u] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
2019-07-22 19:37:45.969 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=51 bytes=000000002e0a1e626967646174612d696e676573742d6576616c756174652d6576656e7473220c6575726f70652d7765737434
2019-07-22 19:37:46.071 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-disposition: attachment, content-type: application/grpc, date: Mon, 22 Jul 2019 18:37:46 GMT] padding=0 endStream=false
2019-07-22 19:37:46.072 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=7651 bytes=00000042e50ac64f0a1e626967646174612d696e676573742d6576616c756174652d6576656e7473122c626967646174612d34313430623337372d343730302d...
2019-07-22 19:37:46.076 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=8192 bytes=485245414453120131126d0a23737061726b3a737061726b2e686973746f72792e66732e6c6f674469726563746f7279124667733a2f2f626f6f6b696e672d68...
2019-07-22 19:37:46.077 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND DATA: streamId=3 padding=0 endStream=false length=1287 bytes=7465722d6e616d65122c626967646174612d66326438356534652d343866632d343537352d623162322d34316664373863333830353742420a1a676f6f672d64...
2019-07-22 19:37:46.077 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, content-disposition: attachment] padding=0 endStream=true
2019-07-22 19:37:46.077 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] INBOUND PING: ack=false bytes=0
2019-07-22 19:37:46.077 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND PING: ack=true bytes=0
2019-07-22 19:37:46.579 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x1b568745, [SANITIZED]] OUTBOUND GO_AWAY: lastStreamId=0 errorCode=0 length=0 bytes=
2019-07-22 19:37:46.612 request_id:0 DEBUG 1 --- [      Finalizer] i.g.n.s.io.netty.buffer.PoolThreadCache  : Freed 1 thread-local buffer(s) from thread: Finalizer
2019-07-22 19:37:46.613 request_id:0 DEBUG 1 --- [      Finalizer] i.g.n.s.io.netty.buffer.PoolThreadCache  : Freed 1 thread-local buffer(s) from thread: Finalizer
2019-07-22 19:37:47.580 request_id:0 DEBUG 1 --- [worker-ELG-17-1] i.g.n.s.io.netty.buffer.PoolThreadCache  : Freed 23 thread-local buffer(s) from thread: grpc-default-worker-ELG-17-1
Jul 22, 2019 7:37:47 PM io.grpc.internal.LogExceptionRunnable run
SEVERE: Exception while executing runnable io.grpc.internal.SharedResourceHolder$2@73cfe40e
io.grpc.netty.shaded.io.netty.channel.ChannelException: eventfd_write() failed: Bad file descriptor
at io.grpc.netty.shaded.io.netty.channel.epoll.Native.eventFdWrite(Native Method)
at io.grpc.netty.shaded.io.netty.channel.epoll.EpollEventLoop.wakeup(EpollEventLoop.java:167)
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.shutdownGracefully(SingleThreadEventExecutor.java:603)
at io.grpc.netty.shaded.io.netty.util.concurrent.MultithreadEventExecutorGroup.shutdownGracefully(MultithreadEventExecutorGroup.java:163)
at io.grpc.netty.shaded.io.grpc.netty.Utils$DefaultEventLoopGroupResource.close(Utils.java:346)
at io.grpc.netty.shaded.io.grpc.netty.Utils$DefaultEventLoopGroupResource.close(Utils.java:318)
at io.grpc.internal.SharedResourceHolder$2.run(SharedResourceHolder.java:145)
at io.grpc.internal.LogExceptionRunnable.run(LogExceptionRunnable.java:43)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

2019-07-22 20:01:09.282 request_id:d6301fe5-d546-48ec-be9e-54a26a310fc0 ERROR 1 --- [nio-8080-exec-7] [SANITIZED].c.HandleExceptionComponent     : unexpected error

java.util.concurrent.RejectedExecutionException: event executor terminated
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:845) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:328) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:321) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:756) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.AbstractScheduledEventExecutor.schedule(AbstractScheduledEventExecutor.java:232) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.AbstractScheduledEventExecutor.schedule(AbstractScheduledEventExecutor.java:155) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.AbstractEventExecutorGroup.schedule(AbstractEventExecutorGroup.java:50) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.netty.shaded.io.netty.util.concurrent.AbstractEventExecutorGroup.schedule(AbstractEventExecutorGroup.java:32) ~[grpc-netty-shaded-1.21.0.jar!/:1.21.0]
at io.grpc.internal.ClientCallImpl.startDeadlineTimer(ClientCallImpl.java:357) ~[grpc-core-1.21.0.jar!/:1.21.0]
at io.grpc.internal.ClientCallImpl.startInternal(ClientCallImpl.java:299) ~[grpc-core-1.21.0.jar!/:1.21.0]
at io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:188) ~[grpc-core-1.21.0.jar!/:1.21.0]
at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1.start(CensusTracingModule.java:394) ~[grpc-core-1.21.0.jar!/:1.21.0]
at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1.start(CensusStatsModule.java:695) ~[grpc-core-1.21.0.jar!/:1.21.0]
at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:32) ~[grpc-api-1.21.0.jar!/:1.21.0]
at com.google.api.gax.grpc.GrpcHeaderInterceptor$1.start(GrpcHeaderInterceptor.java:94) ~[gax-grpc-1.47.1.jar!/:1.47.1]
at io.grpc.stub.ClientCalls.startCall(ClientCalls.java:310) ~[grpc-stub-1.21.0.jar!/:1.21.0]
at io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:282) ~[grpc-stub-1.21.0.jar!/:1.21.0]
at io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:191) ~[grpc-stub-1.21.0.jar!/:1.21.0]
at com.google.api.gax.grpc.GrpcDirectCallable.futureCall(GrpcDirectCallable.java:58) ~[gax-grpc-1.47.1.jar!/:1.47.1]
at com.google.api.gax.grpc.GrpcExceptionCallable.futureCall(GrpcExceptionCallable.java:64) ~[gax-grpc-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.AttemptCallable.call(AttemptCallable.java:86) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.RetryingCallable.futureCall(RetryingCallable.java:63) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.RetryingCallable.futureCall(RetryingCallable.java:41) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.PagedCallable.futureCall(PagedCallable.java:62) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.UnaryCallable$1.futureCall(UnaryCallable.java:126) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.UnaryCallable.futureCall(UnaryCallable.java:87) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.api.gax.rpc.UnaryCallable.call(UnaryCallable.java:112) ~[gax-1.47.1.jar!/:1.47.1]
at com.google.cloud.dataproc.v1beta2.ClusterControllerClient.listClusters(ClusterControllerClient.java:761) ~[google-cloud-dataproc-0.99.0-alpha.jar!/:na]
at com.google.cloud.dataproc.v1beta2.ClusterControllerClient.listClusters(ClusterControllerClient.java:687) ~[google-cloud-dataproc-0.99.0-alpha.jar!/:na]
at com.[SANITIZED].repository.ClusterRepository.list(ClusterRepository.java:19) ~[classes!/:na]
at com.[SANITIZED].repository.ClusterRepository$$FastClassBySpringCGLIB$$3c550a4a.invoke(<generated>) ~[classes!/:na]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) ~[spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139) ~[spring-tx-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at com.[SANITIZED].repository.ClusterRepository$$EnhancerBySpringCGLIB$$f8750e10.list(<generated>) ~[classes!/:na]
at com.[SANITIZED].service.google.GoogleClusterService.listClusters(GoogleClusterService.java:381) ~[classes!/:na]
at com.[SANITIZED].service.google.GoogleClusterService.listClusters(GoogleClusterService.java:139) ~[classes!/:na]
at sun.reflect.GeneratedMethodAccessor105.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:206) ~[spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at com.sun.proxy.$Proxy103.listClusters(Unknown Source) ~[na:na]
at com.[SANITIZED].controller.HadoopClusterController.getOrCreateCluster(HadoopClusterController.java:364) ~[classes!/:na]
at com.[SANITIZED].controller.HadoopClusterController.postCluster(HadoopClusterController.java:209) ~[classes!/:na]
at com.[SANITIZED].controller.HadoopClusterController$$FastClassBySpringCGLIB$$c79d02c9.invoke(<generated>) ~[classes!/:na]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) ~[spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.validation.beanvalidation.MethodValidationInterceptor.invoke(MethodValidationInterceptor.java:119) ~[spring-context-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88) ~[spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at com.[SANITIZED].component.HandleExceptionComponent.handle(HandleExceptionComponent.java:25) ~[classes!/:na]
at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) [spring-aop-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at com.[SANITIZED].controller.HadoopClusterController$$EnhancerBySpringCGLIB$$e22ab08f.postCluster(<generated>) [classes!/:na]
at sun.reflect.GeneratedMethodAccessor103.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:892) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1039) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1005) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:908) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:660) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:882) [spring-webmvc-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) [tomcat-embed-websocket-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at com.[SANITIZED].configuration.RequestIdMdcFilter.doFilter(RequestIdMdcFilter.java:24) [classes!/:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.1.7.RELEASE.jar!/:5.1.7.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:200) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:836) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1747) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_222]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.19.jar!/:9.0.19]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_222]
Suppressed: com.google.api.gax.rpc.AsyncTaskException: Asynchronous task failed
 at com.google.api.gax.rpc.ApiExceptions.callAndTranslateApiException(ApiExceptions.java:57) ~[gax-1.47.1.jar!/:1.47.1]
 ... 97 common frames omitted

2019-07-22 20:01:09.294 request_id:0 DEBUG 1 --- [worker-ELG-17-2] i.g.n.s.io.netty.handler.ssl.SslHandler  : [id: 0x0d97074d, [SANITIZED]] HANDSHAKEN: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256
2019-07-22 20:01:09.294 request_id:0 DEBUG 1 --- [worker-ELG-17-2] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x0d97074d, [SANITIZED]] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
2019-07-22 20:01:09.294 request_id:0 DEBUG 1 --- [worker-ELG-17-2] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x0d97074d, [SANITIZED]] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
2019-07-22 20:01:09.301 request_id:0 DEBUG 1 --- [worker-ELG-17-2] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x0d97074d, [SANITIZED]] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=16384}
2019-07-22 20:01:09.301 request_id:0 DEBUG 1 --- [worker-ELG-17-2] i.g.n.s.i.grpc.netty.NettyClientHandler  : [id: 0x0d97074d, [SANITIZED]] OUTBOUND SETTINGS: ack=true
Jul 22, 2019 8:01:09 PM io.grpc.internal.ManagedChannelImpl$1 uncaughtException
SEVERE: [Channel<81>: (dataproc.googleapis.com:443)] Uncaught exception in the SynchronizationContext. Panic!
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@668be555 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@5d6f9cd2[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326)
at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533)
at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:622)
at io.grpc.internal.DelayedClientTransport.reprocess(DelayedClientTransport.java:297)
at io.grpc.internal.ManagedChannelImpl.updateSubchannelPicker(ManagedChannelImpl.java:790)
at io.grpc.internal.ManagedChannelImpl.access$5200(ManagedChannelImpl.java:102)
at io.grpc.internal.ManagedChannelImpl$LbHelperImpl$1UpdateBalancingState.run(ManagedChannelImpl.java:1149)
at io.grpc.SynchronizationContext.drain(SynchronizationContext.java:88)
at io.grpc.internal.InternalSubchannel$TransportListener.transportReady(InternalSubchannel.java:579)
at io.grpc.netty.shaded.io.grpc.netty.ClientTransportLifecycleManager.notifyReady(ClientTransportLifecycleManager.java:43)
at io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler$FrameListener.onSettingsRead(NettyClientHandler.java:783)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:419)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:637)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onSettingsRead(Http2InboundFrameLogger.java:93)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:542)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2InboundFrameLogger.readFrame(Http2InboundFrameLogger.java:41)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:118)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:390)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:254)
at io.grpc.netty.shaded.io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:450)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:502)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:441)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
at io.grpc.netty.shaded.io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1476)
at io.grpc.netty.shaded.io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1225)
at io.grpc.netty.shaded.io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1272)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:502)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:441)
at io.grpc.netty.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
at io.grpc.netty.shaded.io.netty.handler.proxy.ProxyHandler.channelRead(ProxyHandler.java:255)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
at io.grpc.netty.shaded.io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438)
at io.grpc.netty.shaded.io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:255)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
at io.grpc.netty.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1408)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.grpc.netty.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.grpc.netty.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:930)
at io.grpc.netty.shaded.io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:796)
at io.grpc.netty.shaded.io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:427)
at io.grpc.netty.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:328)
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905)
at io.grpc.netty.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
...

External references such as API reference guides used

Any additional information below

After migration to SDK v.0.99.0-alpha from v.0.79.0-alpha we are observing an intermittent bug. After some time, from a few hours to a few days, io.grpc.netty.shaded.io.netty.channel.ChannelException: eventfd_write() failed: Bad file descriptor exception happening and all subsequent requests fail with java.util.concurrent.RejectedExecutionException: event executor terminated making the whole application instance effectively useless. The stack traces are repetitive (probably due to internal retry logic). We also took a thread dump from one of unhealthy instances: https://pastebin.com/ugx5GiXP
We didn't see anything similar in case of v.0.79.0-alpha for about half a year it was used.

We do not use any tricky configuration for client instantiation. The code snippets above is literally how we do it in our application. The pattern is actually borrowed from this javadoc.

After a talk with @ejona86, it seems like the source of the issue may be prematurely closed ScheduledExecutorService, but this requires further investigation.

P.S. a bit orthogonal question about best practices of using clients. According to this comment clients are thread safe. We didn't saw this reference during initial implementation and simply stick to example from javadocs. Now we spin up a new instance ClusterControllerClient on every request and dispose it right after (using try-with-resources). Is this approach justified in any way, or it is better to share client for different requests and reuse it as long as possible?
@ejona86
Copy link

ejona86 commented Jul 23, 2019

The RejectedExecutionException thrown during DelayedClientTransport.reprocess looked like it was caused by the executor (provided by managedChannelBuilder.executor()) being shut down before the channel was terminated. I poked around a bit and found a reference-counted executor but couldn't find the callers of the ExecutorFactory. But that part looked like a google-cloud-java bug.

@xCASx, sorry, I had missed/forgotten about the eventfd_write. That seems likely to be netty/netty#9362 , but we've not actually seen any reports of that failure by users so I'd expect it to be very rare. I would have expected that to be gracefully-recovered... but looking at the code it does seem it could hang future RPCs because there is a lack of try-finally for instances.remove(). That is a gRPC bug. Gotta go to a meeting. I'll open a bug for it on grpc-java.

@ejona86 ejona86 mentioned this issue Jul 23, 2019
Closed
@chingor13 chingor13 added priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns. labels Jul 24, 2019
@arand-mms
Copy link

Maybe it's not so rare as you think. We run into exactly the same problem. However, we are using the google pubsub-library, but it uses the same infrastructure below, I guess.

@xCASx
Copy link
Author

xCASx commented Aug 8, 2019

The gRPC bug was fixed just a moment ago: grpc/grpc-java#6002
Should be released in v1.23

@ejona86
Copy link

ejona86 commented Aug 8, 2019

Note that the gRPC fix does not fix the underlying problem. But it will allow the client to function after this happens, instead of hanging.

This was referenced Aug 14, 2019
Merged
Closed
Merged
Closed
This was referenced Aug 23, 2019
Closed
Closed
Closed
Closed
@dependabot-preview dependabot-preview bot mentioned this issue Aug 30, 2019
Merged
@chingor13
Copy link
Contributor

So here's what's happening here. When a ClientContext is created in gax-java, the Executor and TransportChannel are added to a list of BackgroundResource instances which are scheduled to close. When the background resources are attempted to be closed, it uses BackgroundResourceAggregation to close multiple background resources and does so in the order they were added to the initial list. Thus we attempt to close the Executor before closing the TransportChannel. Closing calls shutdown() on the executor which does not block. If we need to ensure that the channel is shutdown before we close the executor, we need to call awaitTermination on the TransportChannel before trying to shutdown the executor.

This is a gax-java bug.

@chingor13 chingor13 mentioned this issue Sep 4, 2019
Closed
@chingor13 chingor13 added the external This issue is blocked on a bug with the actual product. label Sep 4, 2019
@ejona86
Copy link

ejona86 commented Dec 17, 2019 •
edited

@chingor13, should this be closed as googleapis/gax-java#787 is merged?

@ndarilek
Copy link

I wonder if I'm hitting this issue or a similar one? Using GRPC-java 1.26.0, though I tried downgrading to 1.25.0 since that seems to match other dependency versions in gradlew dependencies but I get the same result. I'll include the stacktrace below.

I'm attempting to use com.google.cloud:google-cloud-texttospeech:0.117.1-beta in a GRPC server. The server has worked well so far, but now I have a server method attempting to use a GRPC client, at which point things start breaking.

One interesting bit I'm noticing in contrast with the above stacktraces is the line:

threads = 0, queued tasks = 0, completed tasks = 5]

Specifically, completed tasks = 5. Seems to be 0 in earlier stacktraces. So some work is getting done it seems, but not enough.

The stacktrace:

java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@7a4245f2 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@6f910552[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 5]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326)
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533)
	at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:622)
	at io.grpc.internal.SerializingExecutor.schedule(SerializingExecutor.java:93)
	at io.grpc.internal.SerializingExecutor.execute(SerializingExecutor.java:86)
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closedInternal(ClientCallImpl.java:707)
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closed(ClientCallImpl.java:657)
	at io.grpc.internal.FailingClientStream.start(FailingClientStream.java:54)
	at io.grpc.internal.ClientCallImpl.startInternal(ClientCallImpl.java:290)
	at io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:190)
	at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1.start(CensusTracingModule.java:394)
	at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1.start(CensusStatsModule.java:695)
	at io.grpc.ForwardingClientCall.start(ForwardingClientCall.java:32)
	at com.google.api.gax.grpc.GrpcHeaderInterceptor$1.start(GrpcHeaderInterceptor.java:94)
	at io.grpc.stub.ClientCalls.startCall(ClientCalls.java:315)
	at io.grpc.stub.ClientCalls.asyncUnaryRequestCall(ClientCalls.java:287)
	at io.grpc.stub.ClientCalls.futureUnaryCall(ClientCalls.java:196)
	at com.google.api.gax.grpc.GrpcDirectCallable.futureCall(GrpcDirectCallable.java:58)
	at com.google.api.gax.grpc.GrpcExceptionCallable.futureCall(GrpcExceptionCallable.java:64)
	at com.google.api.gax.rpc.UnaryCallable$1.futureCall(UnaryCallable.java:126)
	at com.google.api.gax.tracing.TracedUnaryCallable.futureCall(TracedUnaryCallable.java:75)
	at com.google.api.gax.rpc.UnaryCallable$1.futureCall(UnaryCallable.java:126)
	at com.google.api.gax.rpc.UnaryCallable.futureCall(UnaryCallable.java:87)
	at com.google.api.gax.rpc.UnaryCallable.call(UnaryCallable.java:112)
	at com.google.cloud.texttospeech.v1.TextToSpeechClient.synthesizeSpeech(TextToSpeechClient.java:270)
	at com.google.cloud.texttospeech.v1.TextToSpeechClient.synthesizeSpeech(TextToSpeechClient.java:243)
	at io.scribe.converter.tts.TTSConverter.convert(tts.kt:257)
	at io.scribe.converter.ConverterImpl.createMp3IfNeeded(converter.kt:204)
	at io.scribe.converter.ConverterImpl.convert(converter.kt:255)
	at io.scribe.converter.ConverterGrpc$MethodHandlers.invoke(ConverterGrpc.java:279)
	at io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:172)
	at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:331)
	at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:817)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

@ejona86 ejona86 mentioned this issue Mar 26, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@chingor13 chingor13

Labels
external This issue is blocked on a bug with the actual product. priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@ndarilek @chingor13 @xCASx @ejona86 @arand-mms