MySQL源码调试(二)多线程调试

MySQL源码调试(二)多线程调试

MySQL是一个多线程的服务端程序，所以必须了解一下，多线程调试的技巧，方便去了解MySQL内部运行原理以及问题排查。

gdb 线程操作命令集合

• info thread 列出当前调试程序的所有线程

(gdb) info thread
  Id   Target Id         Frame
* 1    Thread 0x7effc3f7d740 (LWP 10623) "mysqld" 0x00007effc29a574d in poll () at ../sysdeps/unix/syscall-template.S:84
  2    Thread 0x7effbadf1700 (LWP 10624) "mysqld" (running)
  3    Thread 0x7effa8a55700 (LWP 10625) "mysqld" (running)
  4    Thread 0x7effa8254700 (LWP 10626) "mysqld" (running)
  5    Thread 0x7effa7a53700 (LWP 10627) "mysqld" (running)
  6    Thread 0x7effa7252700 (LWP 10628) "mysqld" (running)
  7    Thread 0x7effa6a51700 (LWP 10629) "mysqld" (running)
  8    Thread 0x7effa6250700 (LWP 10630) "mysqld" (running)
  9    Thread 0x7effa5a4f700 (LWP 10631) "mysqld" (running)
  10   Thread 0x7effa524e700 (LWP 10632) "mysqld" (running)
  11   Thread 0x7effa4a4d700 (LWP 10633) "mysqld" (running)
  12   Thread 0x7eff9ffff700 (LWP 10634) "mysqld" (running)
  13   Thread 0x7eff9f7fe700 (LWP 10635) "mysqld" (running)
  14   Thread 0x7eff9effd700 (LWP 10636) "mysqld" (running)
  15   Thread 0x7eff9e7fc700 (LWP 10637) "mysqld" (running)
  16   Thread 0x7eff9dffb700 (LWP 10638) "mysqld" (running)
  17   Thread 0x7eff9d7fa700 (LWP 10639) "mysqld" (running)
  18   Thread 0x7eff9cff9700 (LWP 10640) "mysqld" (running)
  19   Thread 0x7eff97fff700 (LWP 10641) "mysqld" (running)
  20   Thread 0x7eff977fe700 (LWP 10642) "mysqld" (running)
  21   Thread 0x7eff96ffd700 (LWP 10643) "mysqld" (running)

• thread apply all bt 列出所有线程的堆栈信息

(gdb) thread apply all bt

Thread 51 (Thread 0x7eff16ff5700 (LWP 10675)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000001984105 in native_cond_wait (cond=0x2d75ac0 <COND_compress_gtid_table>, mutex=0x2d75a68 <LOCK_compress_gtid_table+40>) at /dbdata/mysql-server/include/thr_cond.h:140
#2  0x000000000198426b in safe_cond_wait (cond=0x2d75ac0 <COND_compress_gtid_table>, mp=0x2d75a40 <LOCK_compress_gtid_table>, file=0x223acb8 "/dbdata/mysql-server/sql/rpl_gtid_persist.cc", line=852) at /dbdata/mysql-server/mysys/thr_cond.c:48
#3  0x000000000189a2fb in my_cond_wait (cond=0x2d75ac0 <COND_compress_gtid_table>, mp=0x2d75a40 <LOCK_compress_gtid_table>, file=0x223acb8 "/dbdata/mysql-server/sql/rpl_gtid_persist.cc", line=852) at /dbdata/mysql-server/include/thr_cond.h:193
#4  0x000000000189a66d in inline_mysql_cond_wait (that=0x2d75ac0 <COND_compress_gtid_table>, mutex=0x2d75a40 <LOCK_compress_gtid_table>, src_file=0x223acb8 "/dbdata/mysql-server/sql/rpl_gtid_persist.cc", src_line=852) at /dbdata/mysql-server/include/mysql/psi/mysql_thread.h:1184
#5  0x000000000189d49e in compress_gtid_table (p_thd=0x56dd380) at /dbdata/mysql-server/sql/rpl_gtid_persist.cc:852
#6  0x0000000001a15b5d in pfs_spawn_thread (arg=0x571ba90) at /dbdata/mysql-server/storage/perfschema/pfs.cc:2188
#7  0x00007effc351c6ba in start_thread (arg=0x7eff16ff5700) at pthread_create.c:333
#8  0x00007effc29b141d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 50 (Thread 0x7effa90c8700 (LWP 10674)):
#0  do_sigwait (sig=0x7effa90c7e28, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:64
#1  __sigwait (set=<optimized out>, sig=0x7effa90c7e28) at ../sysdeps/unix/sysv/linux/sigwait.c:96
#2  0x0000000000f139e7 in signal_hand (arg=0x0) at /dbdata/mysql-server/sql/mysqld.cc:2103
#3  0x0000000001a15b5d in pfs_spawn_thread (arg=0x571ba90) at /dbdata/mysql-server/storage/perfschema/pfs.cc:2188
#4  0x00007effc351c6ba in start_thread (arg=0x7effa90c8700) at pthread_create.c:333
#5  0x00007effc29b141d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 49 (Thread 0x7eff177f6700 (LWP 10673)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000001ba587a in os_event::wait (this=0x4c5ccd8) at /dbdata/mysql-server/storage/innobase/os/os0event.cc:165
#2  0x0000000001ba5238 in os_event::wait_low (this=0x4c5ccd8, reset_sig_count=1) at /dbdata/mysql-server/storage/innobase/os/os0event.cc:335
#3  0x0000000001ba563c in os_event_wait_low (event=0x4c5ccd8, reset_sig_count=0) at /dbdata/mysql-server/storage/innobase/os/os0event.cc:534
#4  0x0000000001d83737 in buf_resize_thread (arg=0x0) at /dbdata/mysql-server/storage/innobase/buf/buf0buf.cc:3016
#5  0x00007effc351c6ba in start_thread (arg=0x7eff177f6700) at pthread_create.c:333
#6  0x00007effc29b141d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 48 (Thread 0x7eff17ff7700 (LWP 10672)):

• thread thread_no 线程切换

(gdb) thread 50
[Switching to thread 50 (Thread 0x7effa90c8700 (LWP 10674))]

• bt 查看当前线程的堆栈信息

(gdb) bt
#0  do_sigwait (sig=0x7effa90c7e28, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:64
#1  __sigwait (set=<optimized out>, sig=0x7effa90c7e28) at ../sysdeps/unix/sysv/linux/sigwait.c:96
#2  0x0000000000f139e7 in signal_hand (arg=0x0) at /dbdata/mysql-server/sql/mysqld.cc:2103
#3  0x0000000001a15b5d in pfs_spawn_thread (arg=0x571ba90) at /dbdata/mysql-server/storage/perfschema/pfs.cc:2188
#4  0x00007effc351c6ba in start_thread (arg=0x7effa90c8700) at pthread_create.c:333
#5  0x00007effc29b141d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb)

• bt 把断点打到某个线程上

no-stop模式

默认情况下，某一个线程触发断点后，其他所有的线程都会暂停执行，gdb提供了no-stop模式，可以让某个线程触发断点后，其他线程可以不受影响的执行，这种方式在调试多线层程序时非常实用。下面来举个例子

一条查询的哪些阶段会阻塞flush tables操作

通过profile命令，可以看到一条简单的查询大概会经历如下几个阶段

mysql> select * from ashe limit 1;
+----+------+
| id | name |
+----+------+
|  1 | aaa  |
+----+------+
1 row in set (0.01 sec)

mysql> show profiles;
+----------+------------+----------------------------+
| Query_ID | Duration   | Query                      |
+----------+------------+----------------------------+
|        1 | 0.01046650 | select * from ashe limit 1 |
+----------+------------+----------------------------+
1 row in set, 1 warning (0.00 sec)

mysql> show profile for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.006838 |
| checking permissions | 0.000147 |
| Opening tables       | 0.000170 |
| init                 | 0.000807 |
| System lock          | 0.000249 |
| optimizing           | 0.000074 |
| statistics           | 0.000146 |
| preparing            | 0.000097 |
| executing            | 0.000016 |
| Sending data         | 0.001674 |
| end                  | 0.000015 |
| query end            | 0.000115 |
| closing tables       | 0.000025 |
| freeing items        | 0.000070 |
| cleaning up          | 0.000024 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)

假设我们不知道查询过程中的加锁逻辑，现在要去分析这些阶段中，哪些是阻塞flush tables操作的，这个时候就可以用到no-stop模式了。

可以在gdb的配置文件中开启no-stop模式，如下：
编辑~/.gdbinit,增加如下内容

set target-async 1
set pagination off
set non-stop on

好了，可以调试了

• gdb attch 到线程中

ashe@ubuntu:~$ sudo gdb -p 10623
GNU gdb (Ubuntu 7.11.1-0ubuntu1~16.5) 7.11.1
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 10623
[New LWP 10624]
[New LWP 10625]
[New LWP 10626]

• 设置全局断点 THD::enter_stage

(gdb) b THD::enter_stage
Breakpoint 1 at 0x15b32ea: file /dbdata/mysql-server/sql/sql_class.cc, line 731.
(gdb) 

• client做一条查询操作，确定线程id

(gdb) c
Continuing.

Thread 53 "mysqld" hit Breakpoint 1, THD::enter_stage (this=0x7eff7c000d80, new_stage=0x2ccb9a0 <stage_starting>, old_stage=0x0, calling_func=0x219a460 <net_after_header_psi(st_net*, void*, unsigned long, char)::__func__> "net_after_header_psi", calling_file=0x2199ce8 "/dbdata/mysql-server/sql/conn_handler/socket_connection.cc", calling_line=103) at /dbdata/mysql-server/sql/sql_class.cc:731
731   DBUG_PRINT("THD::enter_stage",

• 重设断点到线程

(gdb) b THD::enter_stage thread 53
Breakpoint 2 at 0x15b32ea: file /dbdata/mysql-server/sql/sql_class.cc, line 731.

• 线程切换

(gdb) thread 53

• 另开数据库链接，执行flush tables操作。

此时flush tables不会触发断点，只会被线程1阻塞，而线程1每经历一个阶段，都会触发断点。

结束语

如上只是举个例子，还有大量的场景可以用到这种方法。
欢迎加入MySQL内核交流QQ群 860945825