search

mirromutth / r2dbc-mysql

R2DBC MySQL Implementation
Apache License 2.0
656 stars 100 forks source link

NotSslRecordException #150

Open jddipqd opened 3 years ago

jddipqd commented 3 years ago

Sometimes I'm getting NotSslRecordException in the logs:

2020-11-23 08:00:04.772   WARN 18628 --- [reactor-tcp-epoll-1] d.m.r.mysql.client.ReactorNettyClient    : Connection has been closed by peer
2020-11-23 08:00:04.777  ERROR 18628 --- [reactor-tcp-epoll-1] reactor.core.publisher.Operators         : Operator called default onErrorDropped

dev.miku.r2dbc.mysql.client.MySqlConnectionClosedException: Connection unexpectedly closed
        at dev.miku.r2dbc.mysql.client.ClientExceptions.unexpectedClosed(ClientExceptions.java:32) ~[r2dbc-mysql-0.8.2.RELEASE.jar!/:0.8.2.RELEASE]
        at dev.miku.r2dbc.mysql.client.ReactorNettyClient.handleClose(ReactorNettyClient.java:260) ~[r2dbc-mysql-0.8.2.RELEASE.jar!/:0.8.2.RELEASE]
        at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:257) ~[reactor-core-3.3.10.RELEASE.jar!/:3.3.10.RELEASE]
2020-11-23 08:00:04.778   WARN 18628 --- [reactor-tcp-epoll-1] i.n.c.AbstractChannelHandlerContext      : An exception 'reactor.core.Exceptions$BubblingException: dev.miku.r2dbc.mysql.clien
t.MySqlConnectionClosedException: Connection unexpectedly closed' [enable DEBUG level for full stacktrace] was thrown by a user handler's exceptionCaught() method while handling the followi
ng exception:

io.netty.handler.ssl.NotSslRecordException: not an SSL/TLS record: 16000002ff13042330385330314261642068616e647368616b65
        at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1254) ~[netty-handler-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322) ~[netty-handler-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501) ~[netty-codec-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440) ~[netty-codec-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) ~[netty-codec-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:795) ~[netty-transport-native-epoll-4.1.52.Final-linux-x86_64.jar
!/:4.1.52.Final]
        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:475) ~[netty-transport-native-epoll-4.1.52.Final-linux-x86_64.jar!/:4.1.52.Final]
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378) ~[netty-transport-native-epoll-4.1.52.Final-linux-x86_64.jar!/:4.1.52.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.52.Final.jar!/:4.1.52.Final]
        at java.base/java.lang.Thread.run(Thread.java:832) ~[na:na]

I'm still not able to reliably reproduce it, the same code executing the same SQL sometimes throws it and sometimes not. If you treat 16000002ff13042330385330314261642068616e647368616b65 as hex string it contains the substring #08S01Bad handshake

mirromutth commented 2 years ago

Hi there,

Thanks for your report, apologies for the late reply.

Could you please let me know your MySQL server version, r2dbc-mysql version and JDK version?