不吐不快,一次意外宕机事故,让我对阿里云 polardb 充满了疑惑

2022-05-30 23:07:34 +08:00
 rekulas

描述下上周本小组经历的一次 polardb 数据库宕机事故,为了尽可能公正已经尽量屏蔽个人主观思想。

polardb是阿里云目前主推的商业数据库之一,完全兼容 mysql 且具有极好的性能,官方宣传比 mysql 快几倍(我们使用中也感觉是要快些至于倍率没测试过),在市场上知名度很高。

背景: 我们从 2020 年开始使用 polardb ,一直以来表现良好。

团队有内网业务+外网业务,因此内外网均有数据库部署,内网是自建 mysql8 ,外网是 polardb 基础版本 2 核 8G*2 节点,基础年费大约 6k 再加一些额外费用大概 7-9k/年。

事故描述

24 日 11 点突然收到 polardb 数据库异常告警邮件,随后同事告诉我进行了数据库导出导致数据库似乎无法访问了,我立即开始处理。 ps: 其实在 16 号我们也经历过一次事故,同事在早上执行了一个 alter table 命令,随后发现所有数据库均无法访问,我发工单联系后才找到重启按钮进行重启随后恢复,也理解这次事故毕竟高峰期执行 DDL 类操作本身就有一定风险,但我心中仍然埋下了一些不满:我们内网数据库即使高峰期执行 alter 操作也最多影响关联的几张表,不至于影响整个服务器(所以当时我怀疑数据库隔离没做好)。问题解决之后提醒过同事尽量避免白天执行表结构操作。

而这次同事通过 navicat 拉取几张表时,突然中断异常并导致数据库卡死,很多服务访问极其缓慢,查看 cpu 发现一直 100%不降,我立即登录 navicat 查询 processlist ,但是没有发现任何异常,这时候我心里还比较轻松,毕竟 polardb 重启一次还是比较快的,所以果断点了重启以为马上就恢复了。

然而随后发生的事情让我陷入了迷茫,重启之后只正常了 10 秒左右 2 个节点瞬间又拉到 100%,我再次检查 processlist 和事务表,仍然没有发现异常进程或 sql ,就有点慌了,立即电话阿里云客服以为这样可以快速得到技术支持,然而浪费了几分钟时间客服让我提工单会有专人处理,虽然我已经严重声明发生了重大事故。。。

没办法我只能发起工单,过程并不愉快,因为我描述了发生重大问题请立即协助,阿里云仍然半小时后才发来一个:已收到您的问题,我当时就有点发火了,言辞激烈请对方立即安排专人帮忙协助查询异常原因,但对方仍然不紧不慢的回复,一会说慢日志导致一会说 io 访问量太大导致。

我这时也对阿里云协助失去了信心,只能采用最后一个办法-临时升级配置,为什么一开始不升级,因为我不敢赌:阿里云升级和开通新服务时间不稳定,有时候几分钟完成有时候要半个小时,在部分服务还能勉强使用的情况下贸然升级有可能导致更严重的问题。

幸运的是这次事故运气比较好,10 分钟左右就完成了,随后我也发现 cpu 开始回复正常,所有数据库也恢复正常。

后续: 我本想让阿里云下来再继续协助调查为什么 cpu 异常,但是工单客服一直像机器人一般回复,我也失去了兴趣,只是今年打算 polar 到期之后迁移倒 ecs 上,毕竟 ecs 还是比较稳定,之前看重 polardb 主要就是看中稳定性,但是如果稳定性得不到保障那还不如放到自建,我们自建数据库也连续 4 年未发生过重大异常,还是挺稳定的,唯一要担心的就是热备份问题。

附件截图: 阿里的回复
https://wx2.sinaimg.cn/mw2000/786620bcly1h2qtesa7akj21e01jkdog.jpg
cpu 、innodb 缓冲请求、IO 吞吐量
https://wx4.sinaimg.cn/mw2000/786620bcly1h2qtes0jrlj20xc0xctby.jpg
iops 、扫描行数、tps
https://wx1.sinaimg.cn/mw2000/786620bcly1h2qtes4zdij20xc0xcn0w.jpg

事故分析: 事故结束后我仔细查看了日志报表,首先确认了客服说的 io 和慢日志都不是事故主因,从报表中可以看到 io 和 iops 都不高,不可能卡死整个实例(也检查过带宽也很低),异常的数据有 innodb 缓冲请求和扫描行数,因为同事导出的总数据量才大概 2-3 百万级别,这个扫描量显得极其可疑,我在事故后也重新复制了一台新实例模拟事故场景,都没有发现 cpu 、io 、scan 有不正常波动,因此我有点怀疑 polardb 本身 bug 导致或者实例所在机器有缺陷导致。

其实整个事故我最不爽的并非事故本身,而是阿里云的处理态度,在发生严重事故了没有协助客户积极处理,第一个回复花了半个小时,之后的回复也在水,我感受不到对方有一丝急迫的心情,事故完成后也不愿去调查事故原因只会顾左言他,这才是我决定放弃 polardb 的主因。如果他们愿意认真调查下,在事故持续的大半个小时里进入实例服务器检查异常,我也绝对会积极配合跟他们一起找出问题来,然而并没有。

疑惑点 其实第一次的 alter 事故我还是有些疑惑的,因为一个访问量并不大的表更新卡住了整个实例的所有数据库,这正常吗?我们有几台自建数据库也只有 2-4 核但是执行 ddl 操作也最多卡住部分表而已。

第二个疑惑点就是 navicat 导出怎么可能导致 cpu 资源耗尽,我们事后认真检查了确认 navicat 导出只有 select 和 show 命令,正常来说这是比较安全的,而且我们随后测试对 cpu 和 io 的影响都非常小,不大可能是导出本身导致的问题

1820 次点击
所在节点    数据库
31 条回复
sss495088732
2022-05-31 15:56:51 +08:00
@encro 上云还是得用主流的解决方案,少用他们的新产品...
TiDB 是永远的神
orczhou
2022-05-31 20:30:16 +08:00
从性能趋势图来看,缓冲池的请求达到 200~300 万,是非常大的;另外,CPU 到 100%;扫描数据行数也有时候超过 150 万行 /秒,基本上是有比较慢的 SQL 或者批量大操作在持续执行。 找到这样的 query ,并优化之,是解决问题的根本原因。

真実はいつもひとつ! 国内云数据库在诊断上普遍做得不太好,等待事件,Top SQL 如果有的话,应该很快可以破案。

本人前阿里云员工,对 PolarDB 还比较了解,现在已经无任何利益相关了。
rekulas
2022-05-31 22:14:07 +08:00
@orczhou 见我写的案例和上面回复,并无任何异常 sql 或慢日志,如果那么简单我早就找到原因了,而且故障时间跟导出数据时间完全吻合,大概率是导出导致的问题并非问题 sql
orczhou
2022-06-01 09:50:00 +08:00
11 点 10 分~12 点 10 分之间,持续了一个小时的内存池每秒读取超 200 万,行扫描 /每秒超 100 万,说明是有“操作”在执行的;“重启之后只正常了 10 秒左右 2 个节点瞬间又拉到 100%”说明这个“操作”并没有重启而停止,而且从性能指标来看,这个“操作”应该持续了 1 个小时
rekulas
2022-06-01 23:00:16 +08:00
@orczhou 我再次检查了慢日志,有发现异常如图
https://imgur.com/a/20iOBZz
确实发现了异常所在,慢日志大幅增加而且有几条扫描行数很多完全有可能导致 1 小时的异常扫描。

但是如果事情这么简单就好了,如下图这是我们平时其他时段搞活动的慢日志记录
https://imgur.com/BH82HF8
可以看到差异巨大,也就是慢日志增加是果而不是因,而且这里还有个无法解释的 bug:我们在 1 小时内的那个大扫描行 sql 请求远远低于慢日志中的数量,我对比了两者的 QPS 、MPS 都在一个水平上,没有理由 24 号的扫描行数差异如此巨大-我对比了 1 小时的总扫描行数,大概在 10 倍差距左右
orczhou
2022-06-02 14:11:25 +08:00
目前,从看到信息来判断,是无法得出什么结论的,只能做一些猜测,再去验证。
通常的,对于 MySQL 数据库,在系统异常的时候,MySQL 慢查询数量的经常都会增长,如上所说,经常都是果不是因,因为 MySQL 并不记录这条 SQL 是为什么慢,是排队还是锁,还是执行时间长。另外,因可能也隐藏在这个大量的慢 SQL 中,只是通常比较难以排查。

目前的信息,还比较难看出是哪里的问题。可以考虑从应用的角度也去排查,看看出现了哪些不应该出现的 query ,或者以前执行次数很少的 query ,现在变多了。如果整体应用系统波动都不大,那可能就是 PolarDB 或者阿里云有什么不稳定的地方
czz19891012
2022-06-02 16:26:29 +08:00
阿里云这边的工程师, 因为实例已经销毁了不好确认, 其实我们内部有一个叫扁鹊的系统, 这里 cpu 已经 100% 了, 我们通过这个系统可以看到当时的 cpu perf 信息, 就可以确定原因在哪里了...
rekulas
2022-06-06 10:11:43 +08:00
@czz19891012 实例其实一直在跑着的还没销毁 pc-2vcj6a9ih099bjpgm
czz19891012
2022-06-09 00:39:51 +08:00
嗯.. 我搞错了 你这个是成都可用区, 不是公有云可用区. 我查错了, 确实还在
我们这里监控只有最近 7 天的数据, 我看最近这 7 天是正常的..
我看监控里面 cpu 已经跑了 100% 了, 这个其实在 DDL 的时候 2c 的实例跑 100% 很正常的, 因为后台还有物理复制, 统计信息更新, IO 等等一系列的线程的..
后续有问题你可以知乎或者微信钉我
czz19891012
2022-06-09 01:22:17 +08:00
@czz19891012 @rekulas 又看了一下, 在慢日志里面看到你这边有很多在 5.24 日 11 点左右的慢查询, 这些慢查询都扫描 100w+ 的行, 这些 sql 你可以关注一下
rekulas
2022-06-09 09:58:49 +08:00
@czz19891012 ok
不过正常情况下我们 cpu 一直低于 20%,扫描多的 sql 一直都在,但从不会进入慢日志级别,直到我们上次导出数据的时候。。。而且也不涉及到 ddl ,其实最好调查的时机是故障时直接登录服务器查看异常进程和 sql ,可惜那时候联系不上技术只有漫不经心的工单在回复

这是一个专为移动设备优化的页面(即为了让你能够在 Google 搜索结果里秒开这个页面),如果你希望参与 V2EX 社区的讨论,你可以继续到 V2EX 上打开本讨论主题的完整版本。

https://www.v2ex.com/t/856320

V2EX 是创意工作者们的社区,是一个分享自己正在做的有趣事物、交流想法,可以遇见新朋友甚至新机会的地方。

V2EX is a community of developers, designers and creative people.

© 2021 V2EX