作者:Fander(芬达)
转移:芬达数据库学习笔记
今天中午,公司的业务系统 mysql crash 了,重启 mysqld 业务恢复后。业务同事来找我,说需要分析 mysqld crash 的原因。
MySQL 的 err.log 如下:
2022-06-22T12:37:36.675314Z170605886[Note]Abortedconnection170605886todb:''user:'fander'host:'192.168.199.1'(Gotanerrorreadingcommunic ationpackets) 12:37:55UTC-mysqldgotsignal11; Thiscouldbebecauseyouhitabug.Itisalsopossiblethatthisbinary oroneofthelibrariesitwaslinkedagainstiscorrupt,improperlybuilt, ormisconfigured.Thiserrorcanalsobecausedbymalfunctioninghardware. Attemptingtocollectsomeinformationthatcouldhelpdiagnosetheproblem. Asthisisacrashandsomethingisdefinitelywrong,theinformation collectionprocessmightfail. key_buffer_size=402653184 read_buffer_size=2097152 max_used_connections=6001 max_threads=6000 thread_count=253 connection_count=251 Itispossiblethatmysqldcoulduseupto key_buffer_size (read_buffer_size sort_buffer_size)*max_threads=61913278Kbytesofmemory Hopethat'sok;ifnot,decreasesomevariablesintheequation. Threadpointer:0x7f6c8a416140 Attemptingbacktrace.Youcanusethefollowinginformationtofindout wheremysqlddied.Ifyouseenomessagesafterthis,somethingwent terriblywrong... stack_bottom=7f74bd2cee70thread_stack0x30000 mysqld(my_print_stacktrace 0x3b)[0xf1102b] mysqld(handle_fatal_signal 0x461)[0x7c3861] /lib64/libpthread.so.0( 0xf130)[0x7f77081bf130] mysqld(_Z16digest_add_tokenP16sql_digest_statejP7YYSTYPE 0x81)[0xca9bd1] mysqld(_ZN16Lex_input_stream16add_digest_tokenEjP7YYSTYPE 0x1d)[0xcb8b5d] mysqld(_Z8MYSQLlexP7YYSTYPEP7YYLTYPEP3THD 0x130)[0xcbb1a0] mysqld(_Z10MYSQLparseP3THD 0x9dc)[0xdaf85c] mysqld(_Z9parse_sqlP3THDP12Parser_stateP19Object_creation_ctx 0x123)[0xce2c73] mysqld(_Z11mysql_parseP3THDP12Parser_state 0x1cd)[0xce319d] mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command 0xa7a)[0xce3e7a] mysqld(_Z10do_commandP3THD 0x19f)[0xce58bf] mysqld(handle_connection 0x288)[0xda5438] mysqld(pfs_spawn_thread 0x1b4)[0x12861a4] /lib64/libpthread.so.0( 0x7df3)[0x7f77081b7df3] /lib64/libc.so.6(clone 0x6d)[0x7f7706c753dd] Tryingtogetsomevariables. ...
说实话,分析这个东西有点难。
是OOM kill吗?
最常见的 crash 其实是 OOM kill,那么这次是 OOM kill 吗?不是!因为 err.log 里写明了"mysqld got signal 11",而 OOM kill,其实是"signal 9",也就是 kill -9,这种情况 MySQL 没有办法保留堆栈信息无法保留。
是服务器扛不住造成的吗?
从堆栈信息中"connection_count=251" 和 内存使用总值不是,从监控的角度来看,监控值与历史没有太大区别。
那就是bug咯?
我觉得很有可能让业务回顾一下最近有没有做过什么变化,crash 我以前做过什么特别的操作吗?我一边分析一下 bug 去了。
如何分析bug?
先来看看堆栈

我们得到了崩溃的位置 0xca9bd1.如何找到相对的代码位置?找到测试机,获取相应版本的安装包。我们的版本是 5.7.18.下载两个包,一个是二进制安装包,一个是源码包。
解压二进制安装包后,使用 gdb 打开 mysqld,大概方法是
gdb${二进制包二进制包}/bin/mysqld
在 0xca9bd1 如果位置打断,可能会有以下信息:
(gdb)b*0xca9bd1 Breakpoint1at0xca9bd1:file${源码路径}/sql/sql_digest.cc,line:379 (gdb)
我们可以看到,gdb 打印出崩溃位置的文件名和行号,剩下的可以交给开发工程师,根据崩溃堆栈进行问题调查。
以上步骤参考爱可生开源社区黄炎专栏《MySQL第25个问题在一问一实验中:MySQL 崩溃了,打印了一些堆栈信息,怎么读?有兴趣直接关注他们的微信官方账号,看原文。我不需要做文字搬运工。
让我谈谈我是怎么做到的?
因为我没有分析源码的能力,其实我也没用 gdb 定位到哪个文件,我用 notepad 定位!首先,我已经知道崩溃点在这个位置
mysqld(_Z16digest_add_tokenP16sql_digest_statejP7YYSTYPE 0x81)[0xca9bd1]
用 c filt 解析就是
[root@fander~]#c filt_Z16digest_add_tokenP16sql_digest_statejP7YYSTYPE digest_add_token(sql_digest_state*,unsignedint,YYSTYPE*)
我们能发现 digest_add_token 是函数,然后我用 notepad 遍历搜索源文件,如下图:
最后只发现两个源码文件涉及这部分,能定位到具体的行。那么我就"双击"直接跳转到定位的地方。
看源码函数的注释,还有结合 baidu (实际不是用 baidu,用什么大家也懂)搜索这个函数干嘛的。
源码在 sql 目录,能大概知道是 sql 相关的问题。
当然了,我只是从源码能有个大概了解。然后:
1. 我以 "digest_add_token" 为关键字 baidu 搜索
发现了什么?
淘宝内核月报有源码分析过 digest_add_token,这兄弟大概率有 bug 啊
Percona 官方发现过 digest_add_token 相关 bug,并且在 percona server 5.7.18 版本修复了。尤其是 percona 这个分析,根本和我们遇到的场景一模一样,无论版本号还有错误日志。
腾讯 TXSQL 修复过 digest_add_token 相关 bug,说这个函数会导致 overflow 我从 baidu 没有搜到 mysql 官方的相关 bug,于是我直接去 mysql 的 bug report 网站直接搜索了
2. 我以 "digest_add_token" 为关键字,在 bugs.mysql.com 搜索。
很遗憾,我完全搜不到。
当时心想,不厚道啊。。难道 MySQL 的分支兄弟们修复完 bug,没有提交给官方?
3. 我以 "digest_add_token" 为关键字,在 github 开源官方仓库搜索
这次我找到了,这个 bug 的描述很我在 percona 网站看的描述是一样的。
官方的修复方法比 percona 晚了 5 个月,但修复的方法是一模一样。
实际上是官方不厚道哈。。别人修的 bug,复制粘贴后说自己修复。
从 bug 的编号看,他是一个内部 bug,"Bug#26021187",这种长编号的就是内部发现的 bug,在 bug report 网站是搜索不到的,这也是他的 bug 标题虽然有"digest_add_token"关键字,我也搜索不到的原因。但这里又有个短 bug,我的理解是,有可能有外部有人发现和提交过这个 bug (这也正常,percona 早 5 个月就修复了,所以发现那就是更早的事了。),但官方一直很"狗",如果他们内部也发现了,他们会把外部的 bug 编号关闭,说和内部 bug 编号重复,导致我们外部人无法查到这个 bug。
如图,我以外部 bug 编号 86209 搜索也搜索不到。
看这个报错,Oracle 是把这个外部 bug 关闭和隐藏了。如果 bug 编号不存在应该下面这个报错。
现在我们知道 oracle 修复了这个 bug 了,那么他是哪个版本修复呢?
还是 github 上的那个页面,这里能看到最早在 5.7.21 修复了,然后我们去 release note 里可以再次确认。 https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-21.htmlSome statements could cause a buffer overflow in the digest code. Thanks to Laurynas Biveinis and Roel van de Paar for the patch. (Bug #26021187)
Bug 是如此描述: 某些语句可能会导致摘要代码中的缓冲区溢出。
Bug 确实和 sql 有关,我们故障时涉及的具体哪个 sql 我仍然不知道,因为官方很"狗",不给我看具体 Bug 的描述。
无论如何,我找到了 mysqld crash 的原因,希望大家从我的文章学到知识。
Enjoy MySQL!
《深入浅出MGR》视频课程
戳此小程序即可直达B站
MySQL索引统计信息为什么不更新
索引下推如何进行数据过滤
案例分析:磁盘I/O %util特别高
Linux环境监控工具汇总
MySQL Test Run 测试框架介绍
MySQL主从复制之半同步(semi-sync replication)
创建MySQL function的限制
MySQL复制主从实例表DDL不一致导致失败案例
想看更多技术好文,点个吧!