When working on #19197 running against 2.1.10.RELEASE
I noticed...
Netty logs basic handshake failures from the client whereas Jetty/Tomcat/Undertow does not. This results in a noisy log w/ entries that you can really do nothing about. We should match parity w/ the other servers.
Steps to repro:
Run in Netty:
- Download attached demo project and navigate to its directory.
./mvnw -Djavax.net.debug=all spring-boot:run
curl https://localhost:8443/hello
- Notice logs about
unknown_ca
as well as verbose javax.net output
Verbose output produced by -Djavax.net.debug=all
(normally hidden)
reactor-http-nio-2, READ: TLSv1.2 Alert, length = 2
reactor-http-nio-2, RECV TLSv1.2 ALERT: fatal, unknown_ca
reactor-http-nio-2, fatal: engine already closed. Rethrowing javax.net.ssl.SSLException: Received fatal alert: unknown_ca
reactor-http-nio-2, fatal: engine already closed. Rethrowing javax.net.ssl.SSLException: Received fatal alert: unknown_ca
reactor-http-nio-2, called closeOutbound()
reactor-http-nio-2, closeOutboundInternal()
reactor-http-nio-2, SEND TLSv1.2 ALERT: warning, description = close_notify
reactor-http-nio-2, WRITE: TLSv1.2 Alert, length = 2
Noisy application logs also generated by Netty (not generated by Jetty below)
io.netty.handler.codec.DecoderException: javax.net.ssl.SSLException: Received fatal alert: unknown_ca
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:473) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:406) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:373) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:356) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.ssl.SslHandler.channelInactive(SslHandler.java:1078) ~[netty-handler-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1417) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:913) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:819) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510) [netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518) [netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050) [netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.43.Final.jar:4.1.43.Final]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_102]
Caused by: javax.net.ssl.SSLException: Received fatal alert: unknown_ca
at sun.security.ssl.Alerts.getSSLException(Alerts.java:208) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1666) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1634) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.recvAlert(SSLEngineImpl.java:1800) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1083) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:907) ~[na:1.8.0_102]
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) ~[na:1.8.0_102]
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) ~[na:1.8.0_102]
at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:280) ~[netty-handler-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1332) ~[netty-handler-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1227) ~[netty-handler-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1274) ~[netty-handler-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:503) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:442) ~[netty-codec-4.1.43.Final.jar:4.1.43.Final]
... 19 common frames omitted
reactor-http-nio-2, called closeOutbound()
reactor-http-nio-2, closeOutboundInternal()
Run in Jetty
- Rename
pom.xml.jetty
topom.xml
./mvnw -Djavax.net.debug=all spring-boot:run
curl https://localhost:8443/hello
- Notice NO logs about
unknown_ca
but verbose javax.net output
Verbose output produced by `-Djavax.net.debug=all (normally hidden)
qtp1099953472-30, READ: TLSv1.2 Alert, length = 2
qtp1099953472-30, RECV TLSv1.2 ALERT: fatal, unknown_ca
qtp1099953472-30, fatal: engine already closed. Rethrowing javax.net.ssl.SSLException: Received fatal alert: unknown_ca
qtp1099953472-30, fatal: engine already closed. Rethrowing javax.net.ssl.SSLException: Received fatal alert: unknown_ca
qtp1099953472-30, called closeOutbound()
qtp1099953472-30, closeOutboundInternal()
qtp1099953472-30, SEND TLSv1.2 ALERT: warning, description = close_notify
qtp1099953472-30, WRITE: TLSv1.2 Alert, length = 2
No application logs produced by Jetty (unlike Netty above).
NOTE: You can perform the same test w/ Undertow or Tomcat by modifying the pom at step 1) above and edit spring-boot-starter-jetty
-> spring-boot-starter-[undertow|tomcat]
NOTE: Netty issue discussing one instance of this.
Comment From: wilkinsona
I think this will have to be addressed in Reactor Netty as it's logging the failure at ERROR
level:
2020-07-30 11:07:45.126 ERROR 79170 --- [ctor-http-nio-2] reactor.netty.tcp.TcpServer : [id: 0x338c30c8, L:0.0.0.0/0.0.0.0:8443 ! R:/0:0:0:0:0:0:0:1:51123] onUncaughtException(SimpleConnection{channel=[id: 0x338c30c8, L:0.0.0.0/0.0.0.0:8443 ! R:/0:0:0:0:0:0:0:1:51123]})
io.netty.handler.codec.DecoderException: javax.net.ssl.SSLException: Received fatal alert: unknown_ca
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:471) ~[netty-codec-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) ~[netty-codec-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_252]
Caused by: javax.net.ssl.SSLException: Received fatal alert: unknown_ca
at sun.security.ssl.Alerts.getSSLException(Alerts.java:214) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1667) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1635) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.recvAlert(SSLEngineImpl.java:1801) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1090) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:913) ~[na:1.8.0_252]
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:783) ~[na:1.8.0_252]
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:626) ~[na:1.8.0_252]
at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:282) ~[netty-handler-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1380) ~[netty-handler-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1275) ~[netty-handler-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322) ~[netty-handler-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501) ~[netty-codec-4.1.51.Final.jar:4.1.51.Final]
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440) ~[netty-codec-4.1.51.Final.jar:4.1.51.Final]
... 17 common frames omitted
I've opened https://github.com/reactor/reactor-netty/issues/1235.