onStreamAllocated was not called, but it seems the stream is active Error

[gar...@rave.io]

Hey,

I'm getting this cryptic error message and would like some help figuring out what's causing it. 

We have a GRPC service written in Clojure/Java and after running the service for a while our logs will be filled with these errors. Can someone explain what this error message means? 

grpc version: 1.3.0

22:42:37.609 |- WARN  i.n.u.c.DefaultPromise - An exception was thrown by io.grpc.netty.NettyClientStream$Sink$2.operationComplete()

java.lang.IllegalStateException: onStreamAllocated was not called, but it seems the stream is active

        at com.google.common.base.Preconditions.checkState(Preconditions.java:174)

        at io.grpc.internal.AbstractStream2$TransportState.onSentBytes(AbstractStream2.java:287)

        at io.grpc.netty.NettyClientStream$Sink$2.operationComplete(NettyClientStream.java:172)

        at io.grpc.netty.NettyClientStream$Sink$2.operationComplete(NettyClientStream.java:166)

        at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:507)

        at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:481)

        at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:420)

        at io.netty.util.concurrent.DefaultPromise.setSuccess(DefaultPromise.java:95)

        at io.netty.channel.DefaultChannelPromise.setSuccess(DefaultChannelPromise.java:76)

        at io.netty.channel.DefaultChannelPromise.setSuccess(DefaultChannelPromise.java:71)

        at io.netty.handler.codec.http2.StreamBufferingEncoder$Frame.release(StreamBufferingEncoder.java:309)

        at io.netty.handler.codec.http2.StreamBufferingEncoder$DataFrame.release(StreamBufferingEncoder.java:357)

        at io.netty.handler.codec.http2.StreamBufferingEncoder$PendingStream.close(StreamBufferingEncoder.java:292)

        at io.netty.handler.codec.http2.StreamBufferingEncoder.writeRstStream(StreamBufferingEncoder.java:184)

        at io.grpc.netty.NettyClientHandler.cancelStream(NettyClientHandler.java:470)

        at io.grpc.netty.NettyClientHandler.write(NettyClientHandler.java:244)

        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:739)

        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:731)

        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:817)

        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:724)

        at io.netty.channel.DefaultChannelPipeline.write(DefaultChannelPipeline.java:1022)

        at io.netty.channel.AbstractChannel.write(AbstractChannel.java:291)

        at io.grpc.netty.WriteQueue.flush(WriteQueue.java:127)

        at io.grpc.netty.WriteQueue.access$000(WriteQueue.java:47)

        at io.grpc.netty.WriteQueue$1.run(WriteQueue.java:59)

        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)

        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)

        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:445)

        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)

        at java.lang.Thread.run(Thread.java:745)

Garrett

[Carl Mastrangelo]

+Eric

[Eric Anderson]

This is a bug in gRPC. That exception is checking our internal state and somehow it's gotten confused.

I filed https://github.com/grpc/grpc-java/issues/3007 for tracking