HTTP/2 stream initialization fails on incoming preface of max concurrent stream = 1 #8692

angn · 2018-12-28T04:59:14Z

Expected behavior

No error.

Actual behavior

IllegalStateException is fired.

Steps to reproduce

This error happens with hosts that sends a preface with max concurrent stream = 1, which was api.development.push.apple.com in my case.
Digging the code, I found frameStreamToInitialize is not null opposed to the assertion at https://github.com/netty/netty/blob/netty-4.1.29.Final/codec-http2/src/main/java/io/netty/handler/codec/http2/Http2FrameCodec.java#L363

Stacktrace:

 WARN 2018-12-28T13:47:55,732 [nioEventLoopGroup-2-1] DefaultChannelPipeline - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.lang.IllegalStateException: Stream object required for identifier: 131
	at io.netty.handler.codec.http2.Http2FrameCodec$FrameListener.requireStream(Http2FrameCodec.java:578) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2FrameCodec$FrameListener.onHeadersRead(Http2FrameCodec.java:541) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2FrameCodec$FrameListener.onHeadersRead(Http2FrameCodec.java:534) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:317) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:265) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2InboundFrameLogger$1.onHeadersRead(Http2InboundFrameLogger.java:56) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader$2.processFragment(DefaultHttp2FrameReader.java:483) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readHeadersFrame(DefaultHttp2FrameReader.java:491) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:254) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2InboundFrameLogger.readFrame(Http2InboundFrameLogger.java:41) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:118) ~[netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:390) [netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:450) [netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:489) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.http2.Http2MultiplexCodec.channelRead(Http2MultiplexCodec.java:400) [netty-codec-http2-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1429) [netty-handler-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.ssl.SslHandler.decodeNonJdkCompatible(SslHandler.java:1211) [netty-handler-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1245) [netty-handler-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:489) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [netty-codec-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:628) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:528) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:482) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:442) [netty-transport-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884) [netty-common-4.1.29.Final.jar:4.1.29.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.29.Final.jar:4.1.29.Final]
	at java.lang.Thread.run(Thread.java:834) [?:?]

Minimal yet complete reproducer code (or URL to code)

import io.netty.bootstrap.Bootstrap;
import io.netty.buffer.Unpooled;
import io.netty.channel.Channel;
import io.netty.channel.ChannelFutureListener;
import io.netty.channel.ChannelInitializer;
import io.netty.channel.nio.NioEventLoopGroup;
import io.netty.channel.socket.nio.NioSocketChannel;
import io.netty.handler.codec.http.HttpMethod;
import io.netty.handler.codec.http2.*;
import io.netty.handler.logging.LogLevel;
import io.netty.handler.ssl.*;
import io.netty.util.concurrent.FutureListener;

import javax.net.ssl.SSLException;
import java.util.concurrent.CountDownLatch;

final class TestCase {
    public static void main(String[] args) throws InterruptedException, SSLException {
        ApplicationProtocolConfig apConfig = new ApplicationProtocolConfig(
                ApplicationProtocolConfig.Protocol.ALPN,
                ApplicationProtocolConfig.SelectorFailureBehavior.NO_ADVERTISE,
                ApplicationProtocolConfig.SelectedListenerFailureBehavior.ACCEPT,
                ApplicationProtocolNames.HTTP_2);

        SslContext sslContext = SslContextBuilder.forClient()
                .ciphers(Http2SecurityUtil.CIPHERS, SupportedCipherSuiteFilter.INSTANCE)
                .applicationProtocolConfig(apConfig)
                .build();

        NioEventLoopGroup group = new NioEventLoopGroup(1);

        try {
            Channel channel = new Bootstrap()
                    .group(group)
                    .channel(NioSocketChannel.class)
                    .handler(new ChannelInitializer<>() {
                        @Override
                        protected void initChannel(Channel ch) {
                            Http2MultiplexCodecBuilder builder = Http2MultiplexCodecBuilder.forClient(new ChannelInitializer<>() {
                                @Override
                                protected void initChannel(Channel ch) {
                                }
                            });

                            Http2MultiplexCodec codec = builder
                                    .encoderEnforceMaxConcurrentStreams(true)
                                    .frameLogger(new Http2FrameLogger(LogLevel.INFO))
                                    .build();

                            ch.pipeline().addLast(sslContext.newHandler(ch.alloc()), codec);
                        }
                    })
                    .connect("api.development.push.apple.com", 443)
                    .sync()
                    .channel();

            channel.pipeline().get(SslHandler.class).handshakeFuture().sync();

            int attempts = 100;

            CountDownLatch latch = new CountDownLatch(attempts);

            for (int i = 0; i < attempts; i++) {
                Http2StreamChannelBootstrap bs = new Http2StreamChannelBootstrap(channel).handler(new ChannelInitializer<>() {
                    @Override
                    protected void initChannel(Channel ch) {
                    }
                });

                bs.open().addListener((FutureListener<Http2StreamChannel>) future -> {
                    if (future.isSuccess()) {
                        Http2StreamChannel ch = future.getNow();
                        Http2Headers headers = new DefaultHttp2Headers().method(HttpMethod.GET.asciiName()).path("/");
                        ch.write(new DefaultHttp2HeadersFrame(headers), ch.voidPromise());
                        ch.writeAndFlush(new DefaultHttp2DataFrame(Unpooled.EMPTY_BUFFER, true), ch.voidPromise());
                        ch.closeFuture().addListener((ChannelFutureListener) f -> latch.countDown());
                    } else {
                        future.cause().printStackTrace();
                        latch.countDown();
                    }
                });
            }

            latch.await();

            channel.close();
            channel.closeFuture().sync();
        } finally {
            group.shutdownGracefully().sync();
        }
    }
}

Netty version

4.1.29

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

openjdk version "11" 2018-09-25
OpenJDK Runtime Environment 18.9 (build 11+28)
OpenJDK 64-Bit Server VM 18.9 (build 11+28, mixed mode)

and 11.0.1

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

Darwin localhost 18.2.0 Darwin Kernel Version 18.2.0: Fri Oct  5 19:41:49 PDT 2018; root:xnu-4903.221.2~2/RELEASE_X86_64 x86_64

and some linux machines.

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

normanmaurer · 2018-12-28T13:39:03Z

@angn thanks for reporting. I have a fix here... Just working on a unit test now.

Motivation: In Http2FrameCodec we made the incorrect assumption that we can only have 1 buffered outboundstream as maximum. This is not correct and we need to account for multiple buffered streams. Modifications: - Use a map to allow buffer multiple streams - Add unit test. Result: Fixes #8692.

normanmaurer · 2018-12-28T14:21:10Z

@angn PTAL #8694

Motivation: In Http2FrameCodec we made the incorrect assumption that we can only have 1 buffered outboundstream as maximum. This is not correct and we need to account for multiple buffered streams. Modifications: - Use a map to allow buffer multiple streams - Add unit test. Result: Fixes #8692.

…nnection that received a GOAWAY. Motivation: In netty#8692, `Http2FrameCodec` was updated to keep track of all "being initialized" streams, allocating memory before initialization begins, and releasing memory after initialization completes successfully. In some instances where stream initialization fails (e.g. because this connection has received a GOAWAY frame), this memory is never released. Modifications: This change updates the `Http2FrameCodec` to use a separate promise for monitoring the success of sending HTTP2 headers. When sending of headers fails, we now make sure to release memory allocated for stream initialization. Result: After this change, failures in writing HTTP2 Headers (e.g. because this connection has received a GOAWAY frame) will no longer leak memory.

…nnection that received a GOAWAY. (#9674) Motivation: In #8692, `Http2FrameCodec` was updated to keep track of all "being initialized" streams, allocating memory before initialization begins, and releasing memory after initialization completes successfully. In some instances where stream initialization fails (e.g. because this connection has received a GOAWAY frame), this memory is never released. Modifications: This change updates the `Http2FrameCodec` to use a separate promise for monitoring the success of sending HTTP2 headers. When sending of headers fails, we now make sure to release memory allocated for stream initialization. Result: After this change, failures in writing HTTP2 Headers (e.g. because this connection has received a GOAWAY frame) will no longer leak memory.

normanmaurer added this to the 4.1.33.Final milestone Dec 28, 2018

normanmaurer self-assigned this Dec 28, 2018

normanmaurer added the defect label Dec 28, 2018

normanmaurer mentioned this issue Dec 28, 2018

Correctly buffer multiple outbound streams if needed. #8694

Merged

normanmaurer closed this as completed in #8694 Jan 14, 2019

TristanPerry mentioned this issue Aug 22, 2019

Example HTTP/2 client uses extra bogus request #9482

Closed

millems mentioned this issue Oct 15, 2019

HTTP/2: Prevent memory leak when trying to create new streams on a connection that received a GOAWAY. #9674

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HTTP/2 stream initialization fails on incoming preface of max concurrent stream = 1 #8692

HTTP/2 stream initialization fails on incoming preface of max concurrent stream = 1 #8692

angn commented Dec 28, 2018 •

edited

normanmaurer commented Dec 28, 2018

normanmaurer commented Dec 28, 2018

HTTP/2 stream initialization fails on incoming preface of max concurrent stream = 1 #8692

HTTP/2 stream initialization fails on incoming preface of max concurrent stream = 1 #8692

Comments

angn commented Dec 28, 2018 • edited

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 Dec 28, 2018

normanmaurer commented Dec 28, 2018

angn commented Dec 28, 2018 •

edited

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

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