grpc / grpc

The C based gRPC (C++, Python, Ruby, Objective-C, PHP, C#)
https://grpc.io
Apache License 2.0
41.73k stars 10.51k forks source link

gRPC "StatusRuntimeException: UNKNOWN" and underlying netty throws NullPointerException #28762

Closed WPCode closed 2 years ago

WPCode commented 2 years ago

What version of gRPC and what language are you using?

gRPC version: 1.37.0, we are using Java. The underlying netty version should be 4.1.52.

What operating system (Linux, Windows,...) and version?

Linux, inside a container inside kubernetes pod

bash-4.4$ cat /etc/os-release
NAME="Red Hat Enterprise Linux"
VERSION="8.5 (Ootpa)"

What runtime / compiler are you using (e.g. python version or version of gcc)

Java version

What did you do?

We don't know how to reproduce this issue, but it starts showing up in several production servers. The gRPC calls one component make to other components using those BlockingStub will fail, and we see the NullPointerException below every time. If we restart the component (pod), it starts working again. Usually it work fine for some time (maybe several days or weeks?), then starts failing. Once it starts failing, it will fail forever. And we don't know how long it will take to fail again.

What did you expect to see?

gRPC calls work fine.

What did you see instead?

io.grpc.StatusRuntimeException: UNKNOWN
 at io.grpc.StatusRuntimeException.<init>(StatusRuntimeException.java:58)
 at io.grpc.StatusRuntimeException.<init>(StatusRuntimeException.java:50)
 at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:262)
 at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:243)
 at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:156)
 ...
 at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
 at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
 at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
 at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:61)
 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
 at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
 at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
 ...
 at jdk.internal.reflect.GeneratedMethodAccessor510.invoke(Unknown Source)
 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.base/java.lang.reflect.Method.invoke(Unknown Source)
 at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
 at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
 at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
 at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
 at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
 at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
 at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1063)
 at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
 at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
 at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
 at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
 at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791)
 at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
 at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
 at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:121)
 at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:115)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
 at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:105)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:147)
 at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:125)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103)
 at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
 at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
 at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:110)
 at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:80)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55)
 at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
 at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
 at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:211)
 at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183)
 at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
 at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
 at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
 at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
 at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
 at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
 at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
 at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
 at org.eclipse.jetty.server.Server.handle(Server.java:516)
 at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
 at org.eclipse.jetty.server.HttpChannel$$Lambda$996/0x00000000740745d0.dispatch(Unknown Source)
 at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
 at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
 at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:279)
 at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
 at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
 at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
 at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
 at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
 at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
 at java.base/java.lang.Thread.run(Unknown Source)
Caused byjava.lang.NullPointerException
 at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:339)
 at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:321)
 at io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onHeadersRead(Http2InboundFrameLogger.java:56)
 at io.netty.handler.codec.http2.DefaultHttp2FrameReader$2.processFragment(DefaultHttp2FrameReader.java:483)
 at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readHeadersFrame(DefaultHttp2FrameReader.java:491)
 at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:254)
 at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
 at io.netty.handler.codec.http2.Http2InboundFrameLogger.readFrame(Http2InboundFrameLogger.java:41)
 at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:174)
 at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:378)
 at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:438)
 at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)
 at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
 at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
 at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
 at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
 at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
 at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
 at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
 at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
 ... 1 more

Anything else we should know about your project / environment?

We tried to look at DefaultHttp2ConnectionDecoder.java, line 339, it's weird this line will throw NPE, since connection is used before and java final, how could it throw NPE?

            boolean isInformational = !connection.isServer() &&
                    HttpStatusClass.valueOf(headers.status()) == INFORMATIONAL;
dapengzhang0 commented 2 years ago

@donnadionne This is duplicated to https://github.com/grpc/grpc-java/issues/8880 which is being triage there. Please close the issue here. Thanks.

macche80 commented 2 years ago

I am having the same issue actually (I was about to open an issue on this, when I saw that @WPCode already opened one).

I have a similar feedback:

This is the stack trace on the server side (which doesn't seem to have any problem), in case gives you any clue: io.grpc.netty.NettyServerHandler onStreamError WARNING: Stream Error io.netty.handler.codec.http2.Http2Exception$StreamException: Stream closed before write could take place at io.netty.handler.codec.http2.Http2Exception.streamError(Http2Exception.java:167) at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$FlowState.cancel(DefaultHttp2RemoteFlowController.java:481) at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$1.onStreamClosed(DefaultHttp2RemoteFlowController.java:105) at io.netty.handler.codec.http2.DefaultHttp2Connection.notifyClosed(DefaultHttp2Connection.java:356) at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.removeFromActiveStreams(DefaultHttp2Connection.java:1000) at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.deactivate(DefaultHttp2Connection.java:956) at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultStream.close(DefaultHttp2Connection.java:512) at io.netty.handler.codec.http2.DefaultHttp2Connection.close(DefaultHttp2Connection.java:152) at io.netty.handler.codec.http2.Http2ConnectionHandler$BaseDecoder.channelInactive(Http2ConnectionHandler.java:209) at io.netty.handler.codec.http2.Http2ConnectionHandler.channelInactive(Http2ConnectionHandler.java:417) at io.grpc.netty.NettyServerHandler.channelInactive(NettyServerHandler.java:617) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:819) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Unknown Source)

Code wise, I was also looking at DefaultHttp2ConnectionDecoder.java, line 339 and I didn't notice anything obvious, except connection being null, but then, as you said, it should not even be possible, because it's final, and it was used few lines above. BUT I think what is happening is this: boolean isInformational = !connection.isServer() && ... connection.isServer() is returning null, and !null is throwing NPE. EDIT: actually scratch that, because isServer is returning a primitive boolean, not Boolean, so no NPE from unboxing.

We are also using grpc 1.37.0 and netty 4.1.52.Final

WPCode commented 2 years ago

Closing as duplicate of https://github.com/grpc/grpc-java/issues/8880