[问题描述]
我们生产环境有一组集群的多台 MySQL 服务器(MySQL 5.6.21), 不定期的会 crash, 但 error log 中只记录了重启信息, 未记录 crash 时的堆栈:
- mysqld_safe Number of processes running now: 0
- mysqld_safe mysqld restarted
接下来首先排查系统日志 / var/log/message 文件, crash 时没有其他异常信息, 也不是 OOM 导致的.
[排查思路]
由于日志中未记录有价值的信息. 为定位 crash 的原因, 首先开启 MySQL core dump 的功能.
下面是开启 core dump 的步骤:
1, 在 my.cnf 文件中增加 2 个配置项
- [mysqld]
- core_file
- [mysqld_safe]
- core-file-size=unlimited
2, 修改系统参数, 配置 suid_dumpable
echo 1>/proc/sys/fs/suid_dumpable
3, 重启 MySQL 服务, 配置生效
[问题分析]
开启 core dump 后, 服务器再次 crash 时生成了 core file.
用 gdb 分析生成的 core file, 可以看到 crash 时的堆栈信息如下:
从函数 table_esms_by_digest::delete_all_rows 可以看出触发 crash 的是 truncate table events_statements_summary_by_digest 操作.
我们内部有个 DML 的分析工具, 用来统计数据库每分钟增删改查的访问量. 该工具的数据源是 events_statements_summary_by_digest 表, 采集程序会每一分钟采集一次这张表的数据, 采集完成后执行 truncate 操作.
暂停这组集群上 DML 采集程序后 MySQL 没有再发生 crash.
进一步分析多个 core file, 发现最终函数的调用都发生在_lf_pinbox_real_free 函数上.
结合现场环境, 有两处地方值得分析:
1, 内存的不正常值. 当打印该变量时, 此处变量的地址偏低, 不太正常:
- (gdb) p pins->pinbox
- $2 = (LF_PINBOX *) 0x1367208
2, 红字部分为 pfs 逐条释放 digest 记录的操作, 正在释放某行数据时出现错误:
- void reset_esms_by_digest()
- {
- uint index;
- if (statements_digest_stat_array == NULL)
- return;
- PFS_thread *thread= PFS_thread::get_current_thread();
- if (unlikely(thread == NULL))
- return;
- for (index= 0; index <digest_max; index++)
- {
- statements_digest_stat_array[index].reset_index(thread);
- statements_digest_stat_array[index].reset_data();
- }
- digest_index= 1;
- }
猜测有两种可能导致错误:
1, 高并发下, 对内存访问出现冲突;
2, 某个特殊 SQL 导致, 在处理 hash 时.
在网上搜索类似的问题, 有了进一步的进展, 基本确定了这个问题是 bug 导致
如下 MySQL 的 bug report 中讲述了类似问题
https://bugs.mysql.com/bug.php?>
更详细的环境描述如下连接中
https://bugs.launchpad.net/percona-server/+bug/1351148
查到 5.6.35 上的 bug fix 的修复内容, 和我们碰到的情况非常类似.
对比_lf_pinbox_real_free 的修改, 该部分确实进行很大的调整.
下面是 MySQL 5.6.35 函数_lf_pinbox_real_free 的代码片段:
- static void _lf_pinbox_real_free(LF_PINS pins)
- {
- LF_PINBOX pinbox= pins->pinbox;
- struct st_match_and_save_arg arg = {
- pins, pinbox, pins->purgatory
- };
- pins->purgatory= NULL;
- pins->purgatory_count= 0;
- lf_dynarray_iterate(&pinbox->pinarray,
- (lf_dynarray_func)match_and_save, &arg);
- if (arg.old_purgatory)
- {
- void *last= arg.old_purgatory;
- while (pnext_node(pinbox, last))
- last= pnext_node(pinbox, last);
- pinbox->free_func(arg.old_purgatory, last, pinbox->free_func_arg);
- }
- }
下面是 MySQL 5.6.21 函数的_lf_pinbox_real_free 的代码片段
- static void _lf_pinbox_real_free(LF_PINS pins)
- {
- int npins;
- void list;
- void **addr= NULL;
- void first= NULL, last= NULL;
- LF_PINBOX pinbox= pins->pinbox;
- npins= pinbox->pins_in_array+1;
- if (pins->stack_ends_here != NULL)
- {
- int alloca_size= sizeof(void )LF_PINBOX_PINSnpins;
- if (available_stack_size(&pinbox, *pins->stack_ends_here)> alloca_size)
- {
- struct st_harvester hv;
- addr= (void **) alloca(alloca_size);
- hv.granary= addr;
- hv.npins= npins;
- _lf_dynarray_iterate(&pinbox->pinarray,
- (lf_dynarray_func)harvest_pins, &hv);
- npins= hv.granary-addr;
- if (npins)
- qsort(addr, npins, sizeof(void *), (qsort_cmp)ptr_cmp);
- }
- }
同时观察到出问题的集群有指标异常, QPS 不到 6000,Threads_connected 将近 8000.(对比其他高并发的集群, QPS 在 20000 以上, Threads_connected 也只有 300 左右).
排查应用端的连接方式, 了解到其中一个应用有近百台应用服务器, 可能同时发起请求, 却没有合理的复用连接, 维持大量的连接线程增大了 bug 触发的概率.
Bugs Fixed 的描述如下:
Miscalculation of memory requirements for qsort operations could result in stack overflow errors in situations with a large number of concurrent server connections. (Bug #73979, Bug #19678930, Bug #23224078)
[解决思路]
我们通过分析 crash 时的 core file 文件, 找到 crash 时的触发条件, 暂停 DML 采集程序 (truncate table events_statements_summary_by_digest 操作) 后恢复.
后面了解到这是 MySQL 的一个 bug, 在 MySQL 5.6.35 版本后已修复. 这个 bug 在应用端与数据库建立大量的连接时, 更容易触发.
来源: http://www.linuxidc.com/Linux/2018-12/156000.htm