【故障公告】数据库服务器 CPU 近 100% 引发的故障(源于 .NET Core 3.0 的一个 bug)
非常抱歉,这次故障给您带来麻烦了,请您谅解。
今天早上 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 语句。
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 上反馈了这个问题:
Yeah this needs to be fixed asap. We just deployed code that uses 3.0 and had to immediately revert to 2.2 because simple queries blew up our SQL Azure CPU usage. Went from under 50% to 100% and stayed there until we rolled back.
但当时没有引起微软的足够重视,在我们知道错怪了阿里云实际是微软的问题之后,我们向微软 .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。
- 云计算之路-阿里云上:14:20-14:55博客后台2台服务器都CPU 100%引发的故障
- 一个存在三年的内核 bug 引发大量的容器系统出现网络故障
- 一个存在三年的内核 bug 引发大量的容器系统出现网络故障
- 一个诡异BUG引发的血案(线程死锁造成的CPU利用率逐渐增高)
- [故障公告] 13-52-14-03,访问量突增,博客web服务器CPU 100%
- [故障公告] 13-52-14-03,访问量突增,博客web服务器CPU 100%
- Java nio的一个严重BUG,导致cpu 100%
- 使用dotnet-dump 查找 .net core 3.0 占用CPU 100%的原因解析
- [故障公告]14:40-15:00博客站点web服务器雪崩似的CPU 100%
- 云计算之路-阿里云上:启用Windows虚拟内存引发的CPU 100%故障
- Oracle触发bug(cursor: mutex S),造成数据库服务器CPU接近100%
- MySQL 5.6的一个bug引发的故障
- [故障公告] 13:52-14:03,访问量突增,博客web服务器CPU 100%
- Java nio的一个严重BUG,导致cpu 100%
- 【故障公告】再次出现数据库 CPU 居高不下的问题以及找到了最可能的原因
- WSS 3.0 的一个Bug
- 一次cpu占用100%的故障解决
- 云计算之路-阿里云上: RDS实例CPU跑满引发的故障
- ubuntu fwupd占用一个cpu100%解决办法