【故障公告】数据库服务器 CPU 近 100% 引发的故障(源于 .NET Core 3.0 的一个 bug)-LMLPHP

非常抱歉,这次故障给您带来麻烦了,请您谅解。

今天早上 10:54 左右,我们所使用的数据库服务(阿里云 RDS 实例 SQL Server 2016 标准版)CPU 突然飙升至 90% 以上,应用日志中出现大量数据库查询超时的错误。

Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
 ---> System.ComponentModel.Win32Exception (258): Unknown error 258

我们收到告警通知并确认问题后,在 11:06 启动了阿里云 RDS 的主备切换, 11:08 完成切换,数据库 CPU 恢复正常。但是关键时候 docker swarm 总是雪上加霜,在数据库恢复正常后,部署博客站点的 docker swarm 集群有一个节点出现异常情况,部分请求会出现 50x 错误,将这个异常节点退出集群并启动新的节点后在 11:15 左右才恢复正常。

通过阿里云 RDS 控制台的 CloudDBA 发现了 CPU 近 100% 期间执行次数异常多的 SQL 语句。

【故障公告】数据库服务器 CPU 近 100% 引发的故障(源于 .NET Core 3.0 的一个 bug)-LMLPHP

SELECT TOP @__p_1 [b].[TagName] AS [Name], [b].[TagID] AS [Id], [b].[UseCount], [b].[BlogId]
FROM [blog_Tag] [b]
WHERE [b].[BlogId] = @__blogId_0
    AND @__blogId_0 IS NOT NULL
    AND [b].[UseCount] > ?
ORDER BY [b].[UseCount] DESC

上面的 SQL 语句是 EF Core 3.0 生成的,其中加粗的  IS NOT NULL  就是 EF Core 3.0 的一个臭名还没昭著的 bug —— 生成 SQL 语句时会生成额外的  IS NOT NULL  查询条件。

谁也没想到(连微软自己也没想到)这个看似无伤大雅的多此一举却存在致命隐患 —— 在某些情况下会让整个数据库服务器 CPU 持续 100% (或者近 100%)。一开始遇到这个问题时,我们也没想到,还因此错怪了阿里云(博文链接),后来在阿里云数据库专家分析了我们遇到的问题后才发现原来罪魁祸首是 EF Core 生成的多余的 "IS NOT NULL" ,它会在某些情况下会造成 SQL Server 缓存了性能极其低下(很耗CPU)的执行计划,然后后续的查询都走这个执行计划,CPU 就会居高不下。这个错误的执行计划有双重杀伤力,一边巨耗数据库 CPU ,一边造成对应的查询无法正常完成从而查询结果不能被缓存到 memcached ,于是针对这个执行计划的查询就越多,雪崩效应就发生了。唯一的解决方法就是清除这个错误的执行计划缓存,主备切换或者重启服务器只是清除执行计划缓存的一种简单粗暴的方法。

在我们开始遇到这个问题,就已经有人在 github 上反馈了这个问题:

但当时没有引起微软的足够重视,在我们知道错怪了阿里云实际是微软的问题之后,我们向微软 .NET 团队反馈了这个问题,这次得到了微软的重视,很快就修复了,但是是通过 .NET Core 3.0 Preview 版发布的,我们在非生产环境下验证了  IS NOT NULL 的确修复了,由于是 Preview 版,再加上 .NET Core 3.1 正式版年底前会发布,所以我们没有在生产环境中更新这个修复,只是将上次出现问题的复杂 SQL 语句改为用 Dapper 调用存储过程。后来阿里云数据库专家进一步对我们的数据库进行分析,连平时数据库 CPU 的毛刺(偶尔跑高的波动)都与  IS NOT NULL  有关。

这就是这次故障的背景,在我们等待 .NET Core 3.1 正式版修复这个 bug 的过程中又被坑了一次,与上次不同的是这次出现问题的 SQL 语句非常简单,而且只有一个 "IS NOT NULL" ,由此可见这个坑的杀伤力。

这个坑足以载入 .NET Core 的史册,另一个让我们记忆犹新的那次也让我们错怪阿里云的 .NET Core 坑是正式版的 .NET Core 中 SqlClient 竟然漏写了 Dispose ,详见 云计算之路-阿里云上:数据库连接数过万的真相,从阿里云RDS到微软.NET Core

11-23 23:40