查询ElasticSearch卡住超时

现象

现网业务接口查询的数据源由Mysql改为了ElasticSearch，上线运行一段时间后，发现部分查询请求出现卡很久（几十秒）的情况，且最终也查不出结果。

分析

查看ElasticSearch的日志，有比较多的连接超时日志，如下：

[2023-01-06T06:11:30,415][WARN ][o.e.h.AbstractHttpServerTransport] [ghca-node-1] caught exception while handling client http traffic, closing connection Netty4HttpChannel{localAddress=/192.168.33.26:9092, remoteAddress=/*.*.*.*:4
1838}
java.io.IOException: 连接超时
        at sun.nio.ch.SocketDispatcher.read0(Native Method) ~[?:?]
        at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:47) ~[?:?]
        at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276) ~[?:?]
        at sun.nio.ch.IOUtil.read(IOUtil.java:233) ~[?:?]
        at sun.nio.ch.IOUtil.read(IOUtil.java:223) ~[?:?]
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:417) ~[?:?]
        at org.elasticsearch.transport.CopyBytesSocketChannel.readFromSocketChannel(CopyBytesSocketChannel.java:130) ~[transport-netty4-client-7.13.0.jar:7.13.0]
        at org.elasticsearch.transport.CopyBytesSocketChannel.doReadBytes(CopyBytesSocketChannel.java:115) ~[transport-netty4-client-7.13.0.jar:7.13.0]
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:615) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:578) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.49.Final.jar:4.1.49.Final]
        at java.lang.Thread.run(Thread.java:831) [?:?]
[2023-01-06T06:11:30,415][WARN ][o.e.h.AbstractHttpServerTransport] [ghca-node-1] caught exception while handling client http traffic, closing connection Netty4HttpChannel{localAddress=/192.168.33.26:9092, remoteAddress=/*.*.*.*:4
1840}

 

在接口客户端和ElasticSearch服务端进行抓包，复现卡住的情况。

从抓包结果中看到接口调用ElasticSearch接口时未进行TCP三次握手，判断是复用了之前的连接。但是复用的这条连接可能由于中间网络策略的缘故，实际上已经断掉，故而引起查询不成功。另外卡住时间长，是因为ElasticSearch的客户端有重试机制，会依次轮询所以节点，直到连接到活动节点，因此会耗时较长。

解决

在客户端发送HTTP请求时，明确保活时间 keep-alive=10000。如此，客户端在10秒内可以复用之前建立的连接，在此期间这条TCP连接大概率是不会被网络设备杀掉的。超过10秒以后新的请求则会重新建立TCP连接，避免使用到已经被杀掉的连接，出现卡住的情况。

后续

上述办法虽然解决了查询卡住的问题，但是在ElasticSearch服务端仍然能看到连接超时的日志，这是因为ElasticSearch的客户端不会主动去关闭TCP的Socket，仅仅是不去使用超过10秒的连接。当连接被网络设备杀掉或其他原因导致断掉以后，服务端在一定时间后就会杀掉这个僵死连接，否则netstat就会看到很多网络连接，最终引起故障。