Every incoming request fails with unexpected message type: DefaultHttpRequest

[mathieufortin01]

Description

A first request provokes a "An existing connection was forcibly closed by the remote host" error. Every further requests fail with "unexpected message type: DefaultHttpRequest". Only workaround found is to reboot the gateway. See details below.

Setup

• Spring Gateway 2.0.0.BUILD-SNAPSHOT
• Spring Boot 2.0.1
• reactor-netty-0.7.6.RELEASE
• netty 4.1.23.Final

Details

I can't reproduce, and I dont know what kind of request provokes the first error (!). What I know is that the gateway is deployed on an AWS instance opened to the world (meaning it receives a lot of malicious requests) and that a single route is configured, catching all incoming requests.

What I also know is that the first error received is always :

2018-04-13 15:21:10.216 ERROR 6084 --- [reactor-http-nio-2] r.ipc.netty.channel.ChannelOperations    : [HttpServer] Error processing connection. Requesting close the channel

java.io.IOException: An existing connection was forcibly closed by the remote host
	at sun.nio.ch.SocketDispatcher.read0(Native Method) ~[na:1.8.0_152]
	at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43) ~[na:1.8.0_152]
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) ~[na:1.8.0_152]
	at sun.nio.ch.IOUtil.read(IOUtil.java:192) ~[na:1.8.0_152]
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) ~[na:1.8.0_152]
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) ~[netty-buffer-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1108) ~[netty-buffer-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:345) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) [netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) [netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) [netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) [netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) [netty-common-4.1.23.Final.jar!/:4.1.23.Final]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_152]

2018-04-13 15:21:10.218 ERROR 6084 --- [reactor-http-nio-2] r.i.n.channel.CloseableContextHandler    : Handler failure while no child channelOperation was present

And then EVERY incoming requests fail with:

2018-04-13 15:21:51.362 ERROR 6084 --- [reactor-http-nio-1] .a.w.r.e.DefaultErrorWebExceptionHandler : Failed to handle request [GET https://***.***.com/]

io.netty.handler.codec.EncoderException: java.lang.IllegalStateException: unexpected message type: DefaultHttpRequest
	at io.netty.handler.codec.MessageToMessageEncoder.write(MessageToMessageEncoder.java:106) ~[netty-codec-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.CombinedChannelDuplexHandler.write(CombinedChannelDuplexHandler.java:348) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:738) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:730) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:816) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:723) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at reactor.ipc.netty.channel.ChannelOperationsHandler.doWrite(ChannelOperationsHandler.java:291) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.ipc.netty.channel.ChannelOperationsHandler.drain(ChannelOperationsHandler.java:465) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.ipc.netty.channel.ChannelOperationsHandler.flush(ChannelOperationsHandler.java:191) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:802) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:831) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1071) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:300) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at reactor.ipc.netty.http.HttpOperations.lambda$then$0(HttpOperations.java:135) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.ipc.netty.FutureMono.lambda$deferFuture$0(FutureMono.java:68) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.ipc.netty.FutureMono$DeferredFutureMono.subscribe(FutureMono.java:134) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.core.publisher.Mono.subscribe(Mono.java:3080) ~[reactor-core-3.1.6.RELEASE.jar!/:3.1.6.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:167) ~[reactor-core-3.1.6.RELEASE.jar!/:3.1.6.RELEASE]
	at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:56) ~[reactor-core-3.1.6.RELEASE.jar!/:3.1.6.RELEASE]
	at reactor.core.publisher.Mono.subscribe(Mono.java:3080) ~[reactor-core-3.1.6.RELEASE.jar!/:3.1.6.RELEASE]
	at reactor.ipc.netty.NettyOutbound.subscribe(NettyOutbound.java:356) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.core.publisher.MonoSource.subscribe(MonoSource.java:51) ~[reactor-core-3.1.6.RELEASE.jar!/:3.1.6.RELEASE]
	at reactor.ipc.netty.channel.ChannelOperations.applyHandler(ChannelOperations.java:381) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at reactor.ipc.netty.http.client.HttpClientOperations.onHandlerStart(HttpClientOperations.java:501) ~[reactor-netty-0.7.6.RELEASE.jar!/:0.7.6.RELEASE]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) ~[netty-common-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) ~[netty-common-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:463) ~[netty-transport-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) ~[netty-common-4.1.23.Final.jar!/:4.1.23.Final]
	at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_152]
Caused by: java.lang.IllegalStateException: unexpected message type: DefaultHttpRequest
	at io.netty.handler.codec.http.HttpObjectEncoder.encode(HttpObjectEncoder.java:86) ~[netty-codec-http-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.handler.codec.http.HttpClientCodec$Encoder.encode(HttpClientCodec.java:167) ~[netty-codec-http-4.1.23.Final.jar!/:4.1.23.Final]
	at io.netty.handler.codec.MessageToMessageEncoder.write(MessageToMessageEncoder.java:88) ~[netty-codec-4.1.23.Final.jar!/:4.1.23.Final]
	... 31 common frames omitted

I added a predicate to filter out all the unexpected requests, accepting only the legitimate ones, and the service stays up without any problem. Without this filtering, I experienced the service dropping out every 10 to 120 minutes.

I know this is not a lot of information, but this is the pattern I identified.

[cah-andrew-fitzgerald]

related to (or duplicate of) #228

[spencergibb]

I don't think this is an issue anymore.

If you can you provide a complete, minimal, verifiable sample that reproduces the problem using boot 2.1.2 and Greenwich.RELEASE, then I'll reopen. It should be available as a GitHub (or similar) project or attached to this issue as a zip file.

[wk1102]

请问一下各路大神,造成这种错误的情况有哪些?