`QuicException: STREAM_RESET` in `exceptionCaught()`

Question

`QuicException: STREAM_RESET` in `exceptionCaught()`

abezhovets opened this issue 3 years ago · 6 comments

If the client sends RESET_STREAM, then the STREAM_RESET will reach exceptionCaught() as a QuicException.
Is this an error or valid behavior? Is it correct that STREAM_RESET reaches the custom logic handler?

Code to reproduce:

ResetStreamTest

package io.netty.incubator.codec.http3;

import io.netty.bootstrap.Bootstrap;
import io.netty.channel.*;
import io.netty.channel.socket.nio.NioDatagramChannel;
import io.netty.handler.logging.ByteBufFormat;
import io.netty.handler.logging.LogLevel;
import io.netty.handler.logging.LoggingHandler;
import io.netty.handler.ssl.util.InsecureTrustManagerFactory;
import io.netty.incubator.codec.quic.QuicChannel;
import io.netty.incubator.codec.quic.QuicSslContext;
import io.netty.incubator.codec.quic.QuicSslContextBuilder;
import io.netty.incubator.codec.quic.QuicStreamChannel;
import io.netty.util.NetUtil;
import lombok.extern.log4j.Log4j2;
import org.junit.Test;

import java.net.InetSocketAddress;
import java.util.concurrent.TimeUnit;

@Log4j2
public class ResetStreamTest extends BaseTest {

    @Test
    public void testUpload() throws Exception {

        QuicSslContext context = QuicSslContextBuilder.forClient()
                .trustManager(InsecureTrustManagerFactory.INSTANCE)
                .applicationProtocols(Http3.supportedApplicationProtocols()).build();
        ChannelHandler codec = Http3.newQuicClientCodecBuilder()
                .sslContext(context)
                .initialMaxStreamsBidirectional(100)
                .maxIdleTimeout(5000, TimeUnit.MILLISECONDS)
                .initialMaxData(10000000)
                .initialMaxStreamDataBidirectionalLocal(1000000)
                .build();

        Channel channel = new Bootstrap()
                .group(GROUP)
                .channel(NioDatagramChannel.class)
                .option(ChannelOption.SO_REUSEADDR, true)
                .handler(codec)
                .bind(new InetSocketAddress(0))
                .sync().channel();

        QuicChannel quicChannel = QuicChannel.newBootstrap(channel)
                .option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 10_000)
                .remoteAddress(new InetSocketAddress(NetUtil.LOCALHOST4, PORT))
                .handler(new ChannelInitializer<>() {
                    @Override
                    protected void initChannel(Channel ch) {
                        ch.pipeline().addLast(new Http3ClientConnectionHandler());
                    }
                })
                .connect()
                .sync().get();

        QuicStreamChannel streamChannel = Http3.newRequestStream(quicChannel, new ChannelInitializer<>() {
            @Override
            protected void initChannel(Channel ch) {
                ch.pipeline()
                        .addLast(new LoggingHandler(LogLevel.DEBUG, ByteBufFormat.SIMPLE))
                        .addLast(new Http3RequestStreamInboundHandler() {

                            @Override
                            protected void channelRead(ChannelHandlerContext ctx, Http3HeadersFrame frame, boolean isLast) throws Exception {
                                log.info("channelRead {}, {}", frame, isLast);
                            }

                            @Override
                            protected void channelRead(ChannelHandlerContext ctx, Http3DataFrame frame, boolean isLast) throws Exception {
                                log.info("channelRead {}, {}", frame, isLast);
                            }
                        });
            }
        }).sync().getNow();

        streamChannel.shutdownOutput(Http3ErrorCode.H3_INTERNAL_ERROR.code);

        TimeUnit.SECONDS.sleep(1);
    }
}

BaseTest

package io.netty.incubator.codec.http3;

import io.netty.bootstrap.Bootstrap;
import io.netty.channel.Channel;
import io.netty.channel.ChannelHandler;
import io.netty.channel.ChannelHandlerContext;
import io.netty.channel.nio.NioEventLoopGroup;
import io.netty.channel.socket.nio.NioDatagramChannel;
import io.netty.handler.ssl.util.SelfSignedCertificate;
import io.netty.incubator.codec.quic.InsecureQuicTokenHandler;
import io.netty.incubator.codec.quic.QuicSslContext;
import io.netty.incubator.codec.quic.QuicSslContextBuilder;
import org.junit.After;
import org.junit.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.net.InetSocketAddress;
import java.util.concurrent.TimeUnit;

public abstract class BaseTest {

    protected static final int PORT = 9999;
    protected static final NioEventLoopGroup GROUP = new NioEventLoopGroup(1);

    protected final Logger log = LoggerFactory.getLogger(this.getClass());

    @Before
    public void setUp() throws Exception {
        SelfSignedCertificate cert = new SelfSignedCertificate();
        QuicSslContext sslContext = QuicSslContextBuilder.forServer(cert.key(), null, cert.cert())
                .applicationProtocols(Http3.supportedApplicationProtocols()).build();

        ChannelHandler codec = Http3.newQuicServerCodecBuilder()
                .sslContext(sslContext)
                .maxIdleTimeout(5000, TimeUnit.MILLISECONDS)
                .initialMaxData(10000000)
                .initialMaxStreamDataBidirectionalLocal(1000000)
                .initialMaxStreamDataBidirectionalRemote(1000000)
                .initialMaxStreamsBidirectional(100)
                .tokenHandler(InsecureQuicTokenHandler.INSTANCE)
                .handler(new Http3ServerConnectionHandler(new Http3RequestStreamInboundHandler() {

                    @Override
                    protected void channelRead(ChannelHandlerContext ctx, Http3HeadersFrame frame, boolean isLast) throws Exception {
                        log.info("channelRead {}, {}", frame, isLast);
                    }

                    @Override
                    protected void channelRead(ChannelHandlerContext ctx, Http3DataFrame frame, boolean isLast) throws Exception {
                        log.info("channelRead {}, {}", frame, isLast);
                    }
                }))
                .build();

        Bootstrap bs = new Bootstrap();
        Channel serverChannel = bs.group(GROUP)
                .channel(NioDatagramChannel.class)
                .handler(codec)
                .bind(new InetSocketAddress(PORT)).sync().channel();
    }

    @After
    public void cleanUp() {
        GROUP.shutdownGracefully();
    }
}

Stacktrace

[nioEventLoopGroup-2-1] WARN channel.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.
io.netty.incubator.codec.quic.QuicException: STREAM_RESET
	at io.netty.incubator.codec.quic.Quiche.newException(Quiche.java:645) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.Quiche.throwIfError(Quiche.java:669) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicChannel.streamRecv(QuicheQuicChannel.java:765) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicStreamChannel$QuicStreamChannelUnsafe.recv(QuicheQuicStreamChannel.java:860) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicStreamChannel$QuicStreamChannelUnsafe.beginRead(QuicheQuicStreamChannel.java:602) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.read(DefaultChannelPipeline.java:1362) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.read(AbstractChannelHandlerContext.java:671) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.http3.Http3FrameCodec.read(Http3FrameCodec.java:625) ~[netty-incubator-codec-http3-0.0.8.Final.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.read(AbstractChannelHandlerContext.java:671) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.http3.Http3FrameTypeDuplexValidationHandler.read(Http3FrameTypeDuplexValidationHandler.java:85) ~[netty-incubator-codec-http3-0.0.8.Final.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.read(AbstractChannelHandlerContext.java:671) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline.read(DefaultChannelPipeline.java:1004) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline.read(DefaultChannelPipeline.java:46) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.quic.QuicheQuicStreamChannel.read(QuicheQuicStreamChannel.java:287) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicStreamChannel.read(QuicheQuicStreamChannel.java:51) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.readIfIsAutoRead(DefaultChannelPipeline.java:1422) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelActive(DefaultChannelPipeline.java:1400) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:216) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelActive(DefaultChannelPipeline.java:895) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.quic.QuicheQuicStreamChannel$QuicStreamChannelUnsafe.register(QuicheQuicStreamChannel.java:474) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:87) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:81) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.quic.QuicheQuicChannel$1.onUnhandledInboundMessage(QuicheQuicChannel.java:360) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.channel.DefaultChannelPipeline$TailContext.channelRead(DefaultChannelPipeline.java:1296) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.http3.Http3ConnectionHandler.channelRead(Http3ConnectionHandler.java:172) ~[netty-incubator-codec-http3-0.0.8.Final.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.incubator.codec.quic.QuicheQuicChannel$QuicChannelUnsafe.recvStream(QuicheQuicChannel.java:1298) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicChannel$QuicChannelUnsafe.connectionRecv(QuicheQuicChannel.java:1237) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicChannel.recv(QuicheQuicChannel.java:777) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicCodec.lambda$handlerAdded$0(QuicheQuicCodec.java:83) ~[netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicHeaderParser.parse(QuicHeaderParser.java:123) [netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicCodec.handleQuicPacket(QuicheQuicCodec.java:140) [netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.incubator.codec.quic.QuicheQuicCodec.channelRead(QuicheQuicCodec.java:131) [netty-incubator-codec-quic-0.0.17.Final-osx-x86_64.jar:0.0.17.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.nio.AbstractNioMessageChannel$NioMessageUnsafe.read(AbstractNioMessageChannel.java:97) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-all-4.1.67.Final.jar:4.1.67.Final]
	at java.lang.Thread.run(Thread.java:832) [?:?]

Answer 1 · 2021-08-31T01:26:57.000Z

I verified that this exception is benign, i.e. it does not close the underlying connection and you could keep using the connection otherwise. It also looks like the corresponding stream which is reset also correctly receives the channelInactive() callback as expected. So, this does not look like a bug from my end. Also, I do think it is useful to send this exception down the pipeline for the specific stream such that someone may be able to know whether the stream has been reset or not.

Having said the above, there may be an opportunity here to improve the Http3RequestStreamInboundHandler such that by default it does not propagate the exception to the pipeline further and reduce this noisy logs. Do you want to send a PR for this change?

Answer 2 · 2021-09-01T10:41:33.000Z

@NiteshKant
I can try, but I don't understand yet exactly how to handle this error. Should I close the channel or can I ignore it?

Answer 3 · 2021-09-01T18:21:17.000Z

I think we can do something like this:

    @Override
    public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
        if (cause instanceof QuicException) {
            handleQuicException(ctx, (QuicException) cause);
        } else if (cause instanceof Http3Exception) {
            handleHttp3Exception(ctx, (Http3Exception) cause);
        } else {
            ctx.fireExceptionCaught(cause);
        }
    }

and in the default implementation of the handle*Exception methods above just log the error.

Answer 4 · 2021-09-01T18:22:09.000Z

Also if you haven't already, please sign the netty CLA: https://docs.google.com/spreadsheet/viewform?formkey=dHBjc1YzdWhsZERUQnhlSklsbG1KT1E6MQ

ref: https://netty.io/community.html

Answer 5 · 2021-09-06T09:45:26.000Z

@NiteshKant
I signed the netty CLA.
When will I have the rights to push or am I doing something wrong? 403 error right now.

Answer 6 · 2021-09-07T18:28:13.000Z

When will I have the rights to push

CLA does not control the rights to push to this repo. We only make changes to any netty repo through pull requests. Typically, you will fork the repo and then create a pull request.