search

grpc / grpc-java

The Java gRPC implementation. HTTP/2 based RPC
https://grpc.io/docs/languages/java/
Apache License 2.0
11.39k stars 3.83k forks source link

NullPointerException if method is missing leading '/' #4849

Closed drcrallen closed 2 months ago

drcrallen commented 6 years ago

If a go client initiates a grpc.ClientConn.NewStream to a java server, but the method passed into NewStream is lacking the leading '/', then io.netty.handler.codec.http2.DefaultHttp2Connection.DefaultStream will have a null property in io.netty.handler.codec.http2.DefaultHttp2Connection.DefaultStream.PropertyMap, resulting in a null stream in io.grpc.netty.NettyServerHandler#onDataRead and a NullPointerException when stream.inboundDataReceived(data, endOfStream); is called.

On the server side this yields logs like:

Sep 12, 2018 12:16:37 AM io.grpc.netty.NettyServerHandler onDataRead
WARNING: Exception in onDataRead()
java.lang.NullPointerException
    at io.grpc.netty.NettyServerHandler.onDataRead(NettyServerHandler.java:464)
    at io.grpc.netty.NettyServerHandler.access$800(NettyServerHandler.java:98)
    at io.grpc.netty.NettyServerHandler$FrameListener.onDataRead(NettyServerHandler.java:724)
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onDataRead(DefaultHttp2ConnectionDecoder.java:236)
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onDataRead(DefaultHttp2ConnectionDecoder.java:593)
    at io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onDataRead(Http2InboundFrameLogger.java:48)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readDataFrame(DefaultHttp2FrameReader.java:421)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:251)
    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:118)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:390)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:254)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:450)
    at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:489)
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:628)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:563)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:480)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:442)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)

Sep 12, 2018 12:16:37 AM io.grpc.netty.NettyServerHandler onStreamError
WARNING: Stream Error
io.netty.handler.codec.http2.Http2Exception$StreamException: 
    at io.netty.handler.codec.http2.Http2Exception.streamError(Http2Exception.java:149)
    at io.grpc.netty.NettyServerHandler.newStreamException(NettyServerHandler.java:701)
    at io.grpc.netty.NettyServerHandler.onDataRead(NettyServerHandler.java:468)
    at io.grpc.netty.NettyServerHandler.access$800(NettyServerHandler.java:98)
    at io.grpc.netty.NettyServerHandler$FrameListener.onDataRead(NettyServerHandler.java:724)
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onDataRead(DefaultHttp2ConnectionDecoder.java:236)
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onDataRead(DefaultHttp2ConnectionDecoder.java:593)
    at io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onDataRead(Http2InboundFrameLogger.java:48)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readDataFrame(DefaultHttp2FrameReader.java:421)
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:251)
    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:118)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:390)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:254)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:450)
    at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:489)
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:628)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:563)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:480)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:442)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
    at io.grpc.netty.NettyServerHandler.onDataRead(NettyServerHandler.java:464)
    ... 31 more

Sep 12, 2018 12:16:37 AM 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:149)
    at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$FlowState.cancel(DefaultHttp2RemoteFlowController.java:480)
    at io.netty.handler.codec.http2.DefaultHttp2RemoteFlowController$1.onStreamClosed(DefaultHttp2RemoteFlowController.java:104)
    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$DefaultStream.close(DefaultHttp2Connection.java:518)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.closeStream(Http2ConnectionHandler.java:589)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.processRstStreamWriteResult(Http2ConnectionHandler.java:862)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.access$1000(Http2ConnectionHandler.java:66)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$3.operationComplete(Http2ConnectionHandler.java:786)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$3.operationComplete(Http2ConnectionHandler.java:783)
    at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
    at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:485)
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
    at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
    at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48)
    at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:696)
    at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:258)
    at io.netty.channel.ChannelOutboundBuffer.removeBytes(ChannelOutboundBuffer.java:338)
    at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:428)
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:360)
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:901)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1396)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.onError(Http2ConnectionHandler.java:619)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:392)
    at io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:254)
    at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:450)
    at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:489)
    at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:628)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:563)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:480)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:442)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)

and on the client side the request results in

error="rpc error: code = Internal desc = transport: received the unexpected content-type \"text/plain; encoding=utf-8\""

Adding in the leading / on the go client's NewStream call fixes the issue

What version of gRPC are you using?

This is using netty-codec-http2 version 4.1.29.Final with grpc-netty version 1.15.0

What did you expect to see?

A more descriptive error that there was something wrong in the request. Neither the server logs nor the client error message is descriptive. It is possible the text/plain content might be helpful from the client side, but I couldn't find out where the exception for the content type was coming from in order to fix it.

carl-mastrangelo commented 6 years ago

I agree, that could use a better message. I'm not even sure where the plaintext is coming from.

vaikzs commented 5 years ago

@carl-mastrangelo I see this issue now with my application and notice it has been added to the milestone, any thoughts on this?

carl-mastrangelo commented 5 years ago

@vaikzs I'm not sure how this is possible. gRPC always sends HEADERS before data, and we check for a leading slash in NettyServerHandler.onHeadersRead. There must be some other reason why the stream is not in the property map, because the stream would have been closed before ever getting to onDataRead.

vaikzs commented 5 years ago

@carl-mastrangelo Thanks for the response. Not noticing this issue anymore, all we did was follow the https://github.com/grpc/grpc-java to set up the Server instance, only this time with a custom executor and NettyServerBuilder.

vinodhabib commented 3 months ago

After going through the comments/descriptions in the ticket, as per the comments from carl-mastrangelo in the ticket can see a check for path which is missing the leading "/" in onReadHeader() method as below for Headers info in the NettyServerHandler class. As he commented looks like this issue not with missing leading slash as this was caught at the header level check before calling onDataRead() method.

if (path.charAt(0) != '/') { respondWithHttpError(ctx, streamId, 404, Status.Code.UNIMPLEMENTED, String.format("Expected path to start with /: %s", path)); return; }

I also validated/debug this peace of code through JUnit cases (NettyServerHandlerTest.headersWithInvalidPathShouldFail()) and its failing if slash is missing in onReadHeader() method.

Also I can see the comments from vaikzs saying he is not able to see this issue later after following grpc-java setup for server instance.

As per the recent discussion with @kannanjgithub on the latest Analysis, no further action required on this issue.

vinodhabib commented 3 months ago

@kannanjgithub as discussed in the last call are we good to close this ticket?

ejona86 commented 2 months ago

We can close this for a different reason, but I think @vinodhabib's analysis was incomplete. The stack trace wasn't within onHeadersRead(); it was within onDataRead(). The problem was the error handling path as additional frames arrive.

A client could send two frames: HEADERS and DATA. If the processing of the HEADERS fails, the DATA frame will still be arriving; there's a delay after resetting a stream until the remote side learns the stream is reset (and we should even ignore that, as we shouldn't be letting remote machines trigger NPEs).

So let's look back in time at the code throwing a NPE when it was reported: https://github.com/grpc/grpc-java/blob/591a26b1dd5eb0a13c53539da190d6bf8c51bc5b/netty/src/main/java/io/grpc/netty/NettyServerHandler.java#L463-L464

requireHttp2Stream() handles the case where this is an unknown stream. But serverStream() might not find gRPC stream information associated with that HTTP/2 stream and so return null. And looking at the original path handling, it doesn't create any gRPC stream (ditto for many other cases): https://github.com/grpc/grpc-java/blob/591a26b1dd5eb0a13c53539da190d6bf8c51bc5b/netty/src/main/java/io/grpc/netty/NettyServerHandler.java#L386-L390

But looking at the current code, I do think it is fixed. onDataRead() now has: https://github.com/grpc/grpc-java/blob/37d19babffaa91dd3f58f2a9e1c1d774efeb7b98/netty/src/main/java/io/grpc/netty/NettyServerHandler.java#L533-L536

That check was added in https://github.com/grpc/grpc-java/pull/10384 . The other usages of serverStream() also have null checks.