no WINDOW_UPDATE sent due to uncaught error in promise #9663

ti2ger92 · 2019-10-14T18:36:22Z

Expected behavior

Server sends a WINDOW_UPDATE after the window is completed.

Actual behavior

Server throws exceptions from:

netty/codec-http2/src/main/java/io/netty/handler/codec/http2/DefaultHttp2LocalFlowController.java

Line 431 in 4c64c98

throw streamError(stream.id(), INTERNAL_ERROR,

after Delta grows perpetually, never being reset, and throws this exception upstream via a promise to which nothing listening.

Steps to reproduce

Run the test class in this gradle project.

Minimal yet complete reproducer code (or URL to code)

https://gist.github.com/ti2ger92/18c9c4439192d7e88996dbe928e3c300

Netty version

4.1.42

JVM version (e.g. `java -version`)

1.8.0_202, x86_64: "AdoptOpenJDK 8"

OS version (e.g. `uname -a`)

Darwin f01898596f5f.ant.amazon.com 17.7.0 Darwin Kernel Version 17.7.0: Sun Jun 2 20:31:42 PDT 2019; root:xnu-4570.71.46~1/RELEASE_X86_64 x86_64

The text was updated successfully, but these errors were encountered:

normanmaurer · 2019-10-14T21:36:35Z

@carl-mastrangelo @bryce-anderson can you have a look ?

…multiplexed channel Motivation: We may fail to update the flow-controller and in this case need to notify the stream channel and close it. Modifications: Attach a future to the write of the update frame and in case of a failure propagate it to the channel and close it Result: Fixes #9663

normanmaurer · 2019-10-14T23:15:22Z

@ti2ger92 @carl-mastrangelo @bryce-anderson #9664 PTAL

rhernandez35 · 2019-10-14T23:49:20Z

@normanmaurer I do agree that closing the channel is the correct response to this exception. However, the larger issue is that we see this exception thrown many times per connection, even for requests that succeed. It seems like there's something wrong with how the flow control windows tracked in DefaultHttp2LocalFlowController and AbstractHttp2StreamChannel are calculated.

Specifically, AbstractHttp2StreamChannel's flowControlledBytes counter seems to get out sync with DefaultHttp2LocalFlowController's processedWindow, causing it to throw when attempting to flush the window update frame on read. As far as I can tell, our client isn't misbehaving.

normanmaurer · 2019-10-15T00:07:18Z

I will try to investigate but I am not sure when exactly I will have the time yet :(

normanmaurer · 2019-10-15T13:40:00Z

@rhernandez35 @ti2ger92 funny enough my PR did have the side-effect of what seems to be the same issue you reported here:

io.netty.handler.codec.http2.Http2Exception: Attempting to return too many bytes for stream 0
	at io.netty.handler.codec.http2.Http2Exception.connectionError(Http2Exception.java:103)
	at io.netty.handler.codec.http2.Http2Exception.streamError(Http2Exception.java:146)
	at io.netty.handler.codec.http2.DefaultHttp2LocalFlowController$DefaultState.returnProcessedBytes(DefaultHttp2LocalFlowController.java:431)
	at io.netty.handler.codec.http2.DefaultHttp2LocalFlowController$DefaultState.consumeBytes(DefaultHttp2LocalFlowController.java:440)
	at io.netty.handler.codec.http2.DefaultHttp2LocalFlowController.consumeBytes(DefaultHttp2LocalFlowController.java:189)
	at io.netty.handler.codec.http2.Http2FrameCodec.consumeBytes(Http2FrameCodec.java:364)
	at io.netty.handler.codec.http2.Http2FrameCodec.write(Http2FrameCodec.java:307)
	at io.netty.handler.codec.http2.Http2MultiplexCodec$Http2MultiplexCodecStreamChannel.write0(Http2MultiplexCodec.java:313)
	at io.netty.handler.codec.http2.AbstractHttp2StreamChannel$Http2ChannelUnsafe.updateLocalWindowIfNeeded(AbstractHttp2StreamChannel.java:837)
	at io.netty.handler.codec.http2.AbstractHttp2StreamChannel$Http2ChannelUnsafe.beginRead(AbstractHttp2StreamChannel.java:777)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.read(DefaultChannelPipeline.java:1374)
	at io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:685)
	at io.netty.channel.AbstractChannelHandlerContext.read(AbstractChannelHandlerContext.java:670)
	at io.netty.handler.codec.http2.Http2MultiplexTest$24.channelRead(Http2MultiplexTest.java:1138)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931)
	at io.netty.handler.codec.http2.AbstractHttp2StreamChannel$Http2ChannelUnsafe.doRead0(AbstractHttp2StreamChannel.java:872)
	at io.netty.handler.codec.http2.AbstractHttp2StreamChannel.fireChildRead(AbstractHttp2StreamChannel.java:550)
	at io.netty.handler.codec.http2.Http2MultiplexCodec.onHttp2Frame(Http2MultiplexCodec.java:142)
	at io.netty.handler.codec.http2.Http2FrameCodec$FrameListener.onDataRead(Http2FrameCodec.java:576)
	at io.netty.handler.codec.http2.Http2FrameListenerDecorator.onDataRead(Http2FrameListenerDecorator.java:36)
	at io.netty.handler.codec.http2.Http2EmptyDataFrameListener.onDataRead(Http2EmptyDataFrameListener.java:49)
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onDataRead(DefaultHttp2ConnectionDecoder.java:292)
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readDataFrame(DefaultHttp2FrameReader.java:422)
	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.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:174)
	at io.netty.handler.codec.http2.DecoratingHttp2ConnectionDecoder.decodeFrame(DecoratingHttp2ConnectionDecoder.java:63)
	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:505)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:444)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:283)
	at io.netty.handler.codec.http2.Http2MultiplexCodec.channelRead(Http2MultiplexCodec.java:267)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931)
	at io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:343)
	at io.netty.handler.codec.http2.Http2FrameInboundWriter$WriteInboundChannelHandlerContext.writeAndFlush(Http2FrameInboundWriter.java:301)
	at io.netty.handler.codec.http2.Http2FrameInboundWriter$WriteInboundChannelHandlerContext.write(Http2FrameInboundWriter.java:295)
	at io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writeData(DefaultHttp2FrameWriter.java:179)
	at io.netty.handler.codec.http2.Http2FrameInboundWriter.writeInboundData(Http2FrameInboundWriter.java:54)
	at io.netty.handler.codec.http2.Http2MultiplexTest.useReadWithoutAutoReadBuffered(Http2MultiplexTest.java:1149)
	at io.netty.handler.codec.http2.Http2MultiplexTest.useReadWithoutAutoReadInRead(Http2MultiplexTest.java:1098)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)

Does this sound right ?

Will dig into it :)

ti2ger92 · 2019-10-15T19:09:18Z

That looks about right to me, yes. I appreciate that.

normanmaurer · 2019-10-16T21:57:54Z

@ti2ger92 can you check #9664 again ? I think it should fix your problem.

rschmitt · 2019-10-16T23:14:50Z

@normanmaurer Speaking for @ti2ger92, commit d42aa46 from the window_update_failure branch appears to fix our integration tests.

normanmaurer · 2019-10-21T07:27:42Z

@rschmitt can you re-test with the current code of the #9664 PR again ?

rschmitt · 2019-10-21T19:23:45Z

@normanmaurer I've run the tests many times with the current code, everything is working great.

ti2ger92 · 2019-10-21T20:18:42Z

As I commented on the CR its self, my tests also show this solves the problem.

#9664) Motivation: We may fail to update the flow-controller and in this case need to notify the stream channel and close it. Modifications: Attach a future to the write of the update frame and in case of a failure propagate it to the channel and close it Result: Fixes #9663

normanmaurer · 2019-10-22T12:41:36Z

@rschmitt @ti2ger92 thanks a lot... I just merged the change

#9664) Motivation: We may fail to update the flow-controller and in this case need to notify the stream channel and close it. Modifications: Attach a future to the write of the update frame and in case of a failure propagate it to the channel and close it Result: Fixes #9663

normanmaurer mentioned this issue Oct 14, 2019

Correctly propagate failures while update the flow-controller to the … #9664

Merged

normanmaurer closed this as completed in #9664 Oct 22, 2019

normanmaurer added this to the 4.1.43.Final milestone Oct 22, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

no WINDOW_UPDATE sent due to uncaught error in promise #9663

no WINDOW_UPDATE sent due to uncaught error in promise #9663

ti2ger92 commented Oct 14, 2019

normanmaurer commented Oct 14, 2019

normanmaurer commented Oct 14, 2019

rhernandez35 commented Oct 14, 2019 •

edited

Loading

normanmaurer commented Oct 15, 2019

normanmaurer commented Oct 15, 2019

ti2ger92 commented Oct 15, 2019

normanmaurer commented Oct 16, 2019

rschmitt commented Oct 16, 2019

normanmaurer commented Oct 21, 2019

rschmitt commented Oct 21, 2019

ti2ger92 commented Oct 21, 2019

normanmaurer commented Oct 22, 2019

no WINDOW_UPDATE sent due to uncaught error in promise #9663

no WINDOW_UPDATE sent due to uncaught error in promise #9663

Comments

ti2ger92 commented Oct 14, 2019

Expected behavior

Actual behavior

Steps to reproduce

Minimal yet complete reproducer code (or URL to code)

Netty version

JVM version (e.g. java -version)

OS version (e.g. uname -a)

normanmaurer commented Oct 14, 2019

normanmaurer commented Oct 14, 2019

rhernandez35 commented Oct 14, 2019 • edited Loading

normanmaurer commented Oct 15, 2019

normanmaurer commented Oct 15, 2019

ti2ger92 commented Oct 15, 2019

normanmaurer commented Oct 16, 2019

rschmitt commented Oct 16, 2019

normanmaurer commented Oct 21, 2019

rschmitt commented Oct 21, 2019

ti2ger92 commented Oct 21, 2019

normanmaurer commented Oct 22, 2019

JVM version (e.g. `java -version`)

OS version (e.g. `uname -a`)

rhernandez35 commented Oct 14, 2019 •

edited

Loading