写点什么

从零开始学习 MySQL 调试跟踪(2)

作者:GreatSQL
  • 2023-04-17
    福建
  • 本文字数:5576 字

    阅读完需:约 18 分钟

  1. 启用 coredump

  2. 制造一个 coredump 场景

  3. 真实故障场景分析跟踪




上一篇文档介绍了如何构建gdb跟踪调试环境,本文介绍如何根据错误日志信息,跟踪定位问题可能的原因,以及如何利用 coredump 文件查找问题线索。

1. 启用 coredump

程序运行过程中可能会异常终止或崩溃,OS 会把程序挂掉时的内存状态记录下来,写入 core 文件,这就叫 coredump,通过 gdb 结合 core 文件可以方便地进行调试。


利用 core 文件中保留的异常堆栈文件,能够帮助研发同学更快定位问题。因此,如果某些故障断断续续会出现,建议阶段性开启 coredump 功能。


想要开启 coredump,需要先修改 OS 层的几个设置:


$ ulimit -c unlimited$ sysctl -w fs.suid_dumpable=2$ echo "core.%p.%e.%s" > /proc/sys/kernel/core_pattern
复制代码


同时,将这些修改持久化到相应文件中(假定 MySQL/GreatSQL 服务进程的属主用户是 mysql):


$ echo "mysql  -  core   unlimited" >> /etc/security/limits.conf$ echo "fs.suid_dumpable=2" >> /etc/sysctl.conf$ echo "kernel.core_pattern=core.%e.%p.%t" >> /etc/sysctl.conf$ sysctl -p
复制代码


接下来,修改 my.cnf 配置文件,增加以下两行内容:


core_fileinnodb_buffer_pool_in_core_file=OFF
复制代码


然后重启 GreatSQL 服务进程,即可生效,查询确认下:


mysql> show global variables like '%core%';+---------------------------------+-------+| Variable_name                   | Value |+---------------------------------+-------+| core_file                       | ON    || innodb_buffer_pool_in_core_file | OFF   |+---------------------------------+-------+
复制代码


这样设置完成后,需要的话会在 datadir 目录下生成 core 文件。

2. 制造一个 coredump 场景

我们可以给 mysqld 进程发送 SIGSEGV(11) 信号,即可模拟出 coredump 的场景,例如:


$ kill -s SIGSEGV `pidof mysqld`
复制代码


这时查看 GreatSQL 错误日志文件,以及 core 文件,就会发现有 coredump:


$ls -la ...-rw-------   1 mysql mysql 1081147392 Feb 20 22:36 core.mysqld-debug.2658134.1676903816...
$ less error.log...14:36:56 UTC - mysqld got signal 11 ;Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Build ID: 1f4232b893100742b7c519df2fa714648c2d76d9Server Version: 8.0.25-16-debug Source distribution
Thread pointer: 0x0Attempting backtrace. You can use the following information to find outwhere mysqld died. If you see no messages after this, something wentterribly wrong...stack_bottom = 0 thread_stack 0x80000/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(my_print_stacktrace(unsigned char const*, unsigned long)+0x43) [0x4b04d26]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(handle_fatal_signal+0x2cb) [0x39a7d22]/lib64/libpthread.so.0(+0x12c20) [0x7fc3e669ac20]/lib64/libc.so.6(__poll+0x51) [0x7fc3e45c4a41]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(Mysqld_socket_listener::listen_for_connection_event()+0x57) [0x3995195]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(Connection_acceptor<Mysqld_socket_listener>::connection_event_loop()+0x30) [0x355a024]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(mysqld_main(int, char**)+0x27d2) [0x354e4a6]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(main+0x20) [0x32de906]/lib64/libc.so.6(__libc_start_main+0xf3) [0x7fc3e44f6493]/usr/local/GreatSQL-8.0.25-16-Linux-glibc2.28-x86_64/bin/mysqld-debug(_start+0x2e) [0x32de82e]Please help us make Percona Server better by reporting anybugs at https://bugs.percona.com/...
复制代码


在一线的同学,如果需要向研发寻求支持或报告故障时,可以先参考这篇文章 MySQL报障之coredump收集处理流程,需要采集其他几个信息:


  • 故障时刻的 error log。

  • 故障产生的 core 文件。

  • 如果有 general log 的话,也采集起来(故障时刻往前约 1 小时或 10 万行日志)。

  • 导致 core 发生涉及到的表 DDL 以及相应的 SQL 语句,有必要的话,可能还要同时提供真实数据(或样例数据)。

3. 真实故障场景分析跟踪

在 GreatSQL 8.0.25-15 版本(上一个版本)中,InnoDB 并行查询功能在特定场景下存在 bug,会导致 crash,相应的日志见下:


mysqld-debug: /opt/greatsql-8.0.25/sql/item.cc:6047: virtual void Item_field::make_field(Send_field*): Assertion `item_name.is_set()' failed.01:59:20 UTC - mysqld got signal 6 ;Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Build ID: 1f4232b893100742b7c519df2fa714648c2d76d9Server Version: 8.0.25-debug Source distribution
Thread pointer: 0x7fb4a9a0b000Attempting backtrace. You can use the following information to find outwhere mysqld died. If you see no messages after this, something wentterribly wrong...stack_bottom = 7fb4f7aa53b0 thread_stack 0x80000/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(my_print_stacktrace(unsigned char const*, unsigned long)+0x43) [0x4b04d26]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(handle_fatal_signal+0x2cb) [0x39a7d22]/lib64/libpthread.so.0(+0x12c20) [0x7fb5146cac20]/lib64/libc.so.6(gsignal+0x10f) [0x7fb51253a37f]/lib64/libc.so.6(abort+0x127) [0x7fb512524db5]/lib64/libc.so.6(+0x21c89) [0x7fb512524c89]/lib64/libc.so.6(+0x2fa76) [0x7fb512532a76] #<--从这里网上,都是错误信息处理逻辑/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Item_field::make_field(Send_field*)+0x9e) [0x3338758] #<--从这里往下,才是真正触发故障的位置,并记住 "0x3338758" 这个指针/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(THD::send_result_metadata(mem_root_deque<Item*> const&, unsigned int)+0x19d) [0x36977ab]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Query_result_send::send_result_set_metadata(THD*, mem_root_deque<Item*> const&, unsigned int)+0x2d) [0x35f3ff9]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Query_expression::ExecuteIteratorQuery(THD*)+0x1f1) [0x38d057b]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Query_expression::execute(THD*)+0xed) [0x38d0d7d]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Sql_cmd_dml::execute_inner(THD*)+0x1c1) [0x381db25]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(Sql_cmd_dml::execute(THD*)+0x5c7) [0x381cfab]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(mysql_execute_command(THD*, bool)+0x565c) [0x37a1a2b]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(dispatch_sql_command(THD*, Parser_state*, bool)+0x769) [0x37a3a1d]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0x1491) [0x3799819]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug(do_command(THD*)+0x51c) [0x3797c48]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug() [0x3991168]/usr/local/GreatSQL-8.0.25-Linux-glibc2.28-x86_64/bin/mysqld-debug() [0x52e4b22]/lib64/libpthread.so.0(+0x817a) [0x7fb5146c017a]/lib64/libc.so.6(clone+0x43) [0x7fb5125ffdc3]
Trying to get some variables.Some pointers may be invalid and cause the dump to abort.Query (7fb4a9a65028): SELECT ... FROM t1 WHERE ... #<-- 这是触发bug的SQL语句Connection ID (thread ID): 8Status: NOT_KILLED
复制代码


按照上面所说的方法,我们采集了所有相关信息,并能在测试环境重现上述故障。


接下来,我们利用 gdb 来定位分析问题原因:


$ gdb path/bin/mysqld-debug path/core.mysqld-debug.2657287.1657270311GNU gdb (GDB) Red Hat Enterprise Linux 9.2-4.el8...Type "apropos word" to search for commands related to "word"...Reading symbols from ./bin/mysqld-debug......[New LWP 2675795][New LWP 2675825][Thread debugging using libthread_db enabled]Using host libthread_db library "/lib64/libthread_db.so.1".--Type <RET> for more, q to quit, c to continue without paging--Core was generated by `./bin/mysqld-debug --defaults-extra-file=./my.cnf'.Program terminated with signal SIGABRT, Aborted.#0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:5656        return (INTERNAL_SYSCALL_ERROR_P (val, err)[Current thread is 1 (Thread 0x7fb4f7aa7700 (LWP 2676055))](gdb)(gdb) b *0x3338758  #<-- 上面记下的指针值,前面加个 "*" 号,在这里打上断点Breakpoint 1 at 0x3338758: file /opt/greatsql-8.0.25/sql/item.cc, line 6048.  #<-- 指向可能触发问题的源码位置(gdb)(gdb) bt  #<-- 打印详细backtrace信息#0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56#1  0x0000000004b04f1d in my_write_core (sig=6) at /opt/greatsql-8.0.25/mysys/stacktrace.cc:409#2  0x00000000039a7f84 in handle_fatal_signal (sig=6) at /opt/greatsql-8.0.25/sql/signal_handler.cc:199#3  <signal handler called>#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50#5  0x00007fb512524db5 in __GI_abort () at abort.c:79#6  0x00007fb512524c89 in __assert_fail_base (fmt=0x7fb51268d698 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x57a1835 "item_name.is_set()",    file=0x57a1400 "/opt/greatsql-8.0.25/sql/item.cc", line=6047, function=<optimized out>) at assert.c:92#7  0x00007fb512532a76 in __GI___assert_fail (assertion=0x57a1835 "item_name.is_set()", file=0x57a1400 "/opt/greatsql-8.0.25/sql/item.cc", line=6047,    function=0x57a3a40 "virtual void Item_field::make_field(Send_field*)") at assert.c:101#8  0x0000000003338758 in Item_field::make_field (this=0x7fb4a9b5bcf8, tmp_field=0x7fb4f7aa2380) at /opt/greatsql-8.0.25/sql/item.cc:6047#9  0x00000000036977ab in THD::send_result_metadata (this=0x7fb4a9a0b000, list=..., flags=5) at /opt/greatsql-8.0.25/sql/sql_class.cc:2824#10 0x00000000035f3ff9 in Query_result_send::send_result_set_metadata (this=0x7fb4a9a0fda0, thd=0x7fb4a9a0b000, list=..., flags=5)    at /opt/greatsql-8.0.25/sql/query_result.cc:76#11 0x00000000038d057b in Query_expression::ExecuteIteratorQuery (this=0x7fb4a9a65178, thd=0x7fb4a9a0b000) at /opt/greatsql-8.0.25/sql/sql_union.cc:1150#12 0x00000000038d0d7d in Query_expression::execute (this=0x7fb4a9a65178, thd=0x7fb4a9a0b000) at /opt/greatsql-8.0.25/sql/sql_union.cc:1321#13 0x000000000381db25 in Sql_cmd_dml::execute_inner (this=0x7fb4a9a0fd68, thd=0x7fb4a9a0b000) at /opt/greatsql-8.0.25/sql/sql_select.cc:814#14 0x000000000381cfab in Sql_cmd_dml::execute (this=0x7fb4a9a0fd68, thd=0x7fb4a9a0b000) at /opt/greatsql-8.0.25/sql/sql_select.cc:585#15 0x00000000037a1a2b in mysql_execute_command (thd=0x7fb4a9a0b000, first_level=true) at /opt/greatsql-8.0.25/sql/sql_parse.cc:4684#16 0x00000000037a3a1d in dispatch_sql_command (thd=0x7fb4a9a0b000, parser_state=0x7fb4f7aa41d0, update_userstat=false)    at /opt/greatsql-8.0.25/sql/sql_parse.cc:5284#17 0x0000000003799819 in dispatch_command (thd=0x7fb4a9a0b000, com_data=0x7fb4f7aa5370, command=COM_QUERY) at /opt/greatsql-8.0.25/sql/sql_parse.cc:1940#18 0x0000000003797c48 in do_command (thd=0x7fb4a9a0b000) at /opt/greatsql-8.0.25/sql/sql_parse.cc:1388#19 0x0000000003991168 in handle_connection (arg=0x7fb4ba094500) at /opt/greatsql-8.0.25/sql/conn_handler/connection_handler_per_thread.cc:307#20 0x00000000052e4b22 in pfs_spawn_thread (arg=0x7fb511e44320) at /opt/greatsql-8.0.25/storage/perfschema/pfs.cc:2899#21 0x00007fb5146c017a in start_thread (arg=<optimized out>) at pthread_create.c:479#22 0x00007fb5125ffdc3 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
复制代码


有了这些信息,研发同学再去跟踪定位问题根源就会方便很多。


本文简单演示了如何利用 core 文件去跟踪定位分析可能导致 crash 的原因,更多有趣实用的方法还有待进一步挖掘,一起探索新世界吧。

用户头像

GreatSQL

关注

GreatSQL社区 2023-01-31 加入

GreatSQL是由万里数据库维护的MySQL分支,专注于提升MGR可靠性及性能,支持InnoDB并行查询特性,是适用于金融级应用的MySQL分支版本。 社区:https://greatsql.cn/ Gitee: https://gitee.com/GreatSQL/GreatSQL

评论

发布
暂无评论
从零开始学习MySQL调试跟踪(2)_GreatSQL_InfoQ写作社区