【下】.netcore下的PostgreSQL异常排查

这是我参与11月更文挑战的第5天,活动详情查看:2021最后一次更文挑战」。

书接上回...

5.幽灵再现

由于测试环境未能真正的和线上环境保持一致,因此运维又开了一台AWS的云数据库(postgresql)环境,分配了域名供测试调用。

为了谨慎起见,再交付产品组前,我使用多线程进行了测试,并未发现问题,变交给了产品组。

而产品组在使用后,发现问题依然存在。

这该死的BUG,像幽灵一样,怎么搞?

感觉陷于了死循环里。

6.静心分析问题

从头来过,不抛弃,不放弃!

为了解决该问题,我查阅了云服务的数据库日志,终于找到了有用的线索。

数据库日志 
2021-11-10 05:28:03 UTC:218.76.52.112(26828):xxx@test:[26849]:LOG:  could not receive data from client: Connection reset by peer
2021-11-10 05:28:16 UTC:218.76.52.112(26346):xxx@postgres:[24160]:LOG:  could not receive data from client: Connection reset by peer
2021-11-10 05:28:16 UTC:218.76.52.112(26504):xxx@test:[25374]:LOG:  could not receive data from client: Connection reset by peer
2021-11-10 05:28:16 UTC:218.76.52.112(26361):xxx@test:[24280]:LOG:  could not receive data from client: Connection reset by peer
复制代码

重要的线索来了,Connection reset by peer,连接被重置! 被谁重置了?

7 连接被重置

TCP连接被重置的情景如下:

  1. 如果一端的Socket被关闭(或主动关闭,或因为异常退出而 引起的关闭),另一端仍发送数据,发送的第一个数据包引发该异常(Connect reset by peer)。

Socket默认连接60秒,60秒之内没有进行心跳交互,即读写数据,就会自动关闭连接。

  1. 如果一端退出,但退出时并未关闭该连接,另一端如果在从连接中读数据则抛出该异常(Connection reset)。

简单的说就是在连接断开后的读和写操作引起的。

情景出现的常见原因:

  • 服务器的并发连接数超过了其承载量,服务器会将其中一些连接关闭;

如果知道实际连接服务器的并发客户数没有超过服务器的承载量,则有可能是中了病毒或者木马,引起网络流量异常。

  • 客户关掉了连接,而服务器还在给客户端发送数据;
  • 防火墙的问题

如果网络连接通过防火墙,而防火墙一般都会有超时的机制,在网络连接长时间不传输数据时,会关闭这个TCP的会话。

关闭后再读写,就会导致异常。 如果关闭防火墙,解决了问题,需要重新配置防火墙,或者自己编写程序实现TCP的长连接。

实现TCP的长连接,需要自己定义心跳协议,每隔一段时间,发送一次心跳协议,双方维持连接。

8 .解决问题

是的,我本地测试AWS服务就没有问题,而测试环境连接AWS服务器就会频繁发生问题,我们之间最大的不同就是网络硬件通道不一样。

那可以断定数据库的连接被缓存在连接池内,而当再次取出来用时,这个连接可能早被网络某个代理/防火墙/路由器等关闭,因此就出现了异常。

不得不说,连接字符串参数很重要,再次阅读文档,即可找到:
Npgsql .net 版本的PostgreSQL数据库连接字符串及参数

  1. 设置 ConnectionLifetime 设置最大生命周期,防止过长时间重用,设置为60s
  2. 设置 Keepalive 心跳,防止被回收。设置为30s

我把这2项配置强有力的推给了产品组。经过半个小时后,产品组反馈,问题得到了解决!

9. 阅读源码,找找根

我们找到 ConnectorPool类,查看其代码,发现其从池子中获取空闲链接时,会检查是否断开状态。

bool CheckIdleConnector([NotNullWhen(true)] NpgsqlConnector? connector)
        {
            if (connector is null)
                return false;

            // Only decrement when the connector has a value.
            Interlocked.Decrement(ref _idleCount);

            // An connector could be broken because of a keepalive that occurred while it was
            // idling in the pool
            // TODO: Consider removing the pool from the keepalive code. The following branch is simply irrelevant
            // if keepalive isn't turned on.
            if (connector.IsBroken)
            {
                CloseConnector(connector);
                return false;
            }

            if (_connectionLifetime != TimeSpan.Zero && DateTime.UtcNow > connector.OpenTimestamp + _connectionLifetime)
            {
                Log.Debug("Connection has exceeded its maximum lifetime and will be closed.", connector.Id);
                CloseConnector(connector);
                return false;
            }

            return true;
        }
复制代码

当然,注释也表明了,如果设置了KeepAlive参数,那么断开检查是有效的,如果没有设置那么该参数是无效的。是啊,没有心跳,它应该也无法检查链接是否断开吧!

从代码中也能看出来,如果设置了链接的生命周期,那么超时的链接也会被销毁而不是返回给客户端。

继续查看NpgsqlConnector的实现代码,发现了心跳检查的奥妙。

_keepAliveTimer = new Timer(PerformKeepAlive, null, Timeout.Infinite, Timeout.Infinite);
复制代码

原来是利用定时器进行检查,那么也就是说如果设置了KeepAlive,那么每个链接多占用了1个线程。

心跳检查的核心代码如下:

Log.Trace("Performing keepalive", Id);
 AttemptPostgresCancellation = false;
   var timeout = InternalCommandTimeout;
   WriteBuffer.Timeout = TimeSpan.FromSeconds(timeout);
   UserTimeout = timeout;
   WriteSync(async: false);
   Flush();
   SkipUntil(BackendMessageCode.ReadyForQuery);
   Log.Trace("Performed keepalive", Id);
复制代码

一个简单的写 SYNC 就搞定了心跳保持和检查。

从上述代码来看,我们的推断是又道理的,如果没有心跳检查,那么放在链接池的链接的确状态是未知的,如果被其他网关断开了,那么再次访问,异常必然会被抛出。

嗯,好开心!

10. 小结

本次故障排查,总跨度有2周时间,共分析2次故障,每次大约占用2-3天时间,确实不易啊,各位看到的给点支持!

👓都看到这了,还在乎点个赞吗?

👓都点赞了,还在乎一个收藏吗?

👓都收藏了,还在乎一个评论吗?