Debugging MySQL/MariaDB (3): GDB Debugging
この記事は次の2つの記事の続編である。2つの記事を基礎とし、GDB を用いた MySQL/MariaDB のデバッグについて解説する。なお、(1) で述べた通り、MySQL 8.0.24 および MariaDB 10.5.9 を前提として説明する。
以下では、(1) の記事の方法で MySQL/MariaDB がデバッグビルドしている前提で解説を行う。
Debugging with GDB
筆者が MySQL/MariaDB を GDB でデバッグするときのやり方を具体例を通して説明する。ただし、説明には MySQL 8.0.24 を使うものとする。
例えば、(1) の記事で作成した example.test の実行をデバッグしたいとしよう。
# mysql-test/suite/innodb/t/example.test CREATE TABLE t1 (a INT); INSERT INTO t1 VALUES (1); SELECT * FROM t1; DROP TABLE t1; --error ER_BAD_TABLE_ERROR DROP TABLE t;
「よい」ブレークポイントが打てるケース
ブレークポイントをどこに打てばよいかわかっており、そのブレークポイントが頻繁にヒットしないものならば、mysql-test-run.pl に --manual-gdb オプションを与えて実行するのがよい。
cd bld/mysql-test/ ./mysql-test-run.pl innodb.example --manual-gdb
すると、次のような文言が出力される。
To start gdb for mysqld.1, type in another window: gdb -cd /home/vagrant/repo/mysql-8.0.24/mysql-test -x /home/vagrant/repo/mysql-8.0.24/bld/mysql-test/var/tmp/gdbinit.mysqld.1 /home/vagrant/repo/mysql-8.0.24/bld/runtime_output_directory/mysqld
このコマンドを別のウィンドウで実行すると、MySQL 8.0.24 では main() 関数で停止した状態になる。適当にブレークポイントを設定し continue するとテストケースが実行される。
※ MariaDB 10.5.9 では、プログラムの実行開始前 (run されていない状態) で停止するようだ。
GNU gdb (Ubuntu 9.2-0ubuntu1~20.04) 9.2
Copyright (C) 2020 Free Software Foundation, Inc.
...
Reading symbols from /home/vagrant/repo/mysql-8.0.24/bld/runtime_output_directory/mysqld...
Breakpoint 1 at 0x32c4ea9: file /home/vagrant/repo/mysql-8.0.24/sql/main.cc, line 25.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Breakpoint 1, main (argc=0, argv=0x7fffffffe8e0) at /home/vagrant/repo/mysql-8.0.24/sql/main.cc:25
25 int main(int argc, char **argv) { return mysqld_main(argc, argv); }
(gdb)
「よい」ブレークポイントを打てないケース
どこにブレークポイントを打てばいいかわからない場合や、わかっているがブレークポイントが頻繁にヒットしすぎる部類のものの場合、--manual-gdb は使いづらい。何故なら、MySQL の初期化プロセスや興味のないクエリも GDB デバッグの対象となってしまうからである。
このようなケースでは、筆者ならば mysql-test-run.pl に --start-and-exits オプションを渡して起動し、手でクエリを投入しながら、デバッグしたい箇所に到達したら GDB をアタッチする。実際にやってみよう。
まず、MySQL server を innodb.example の設定で起動する。
> cd bld/mysql-test/
> ./mysql-test-run.pl innodb.example --start-and-exit
...
==============================================================================
TEST NAME RESULT TIME (ms) COMMENT
------------------------------------------------------------------------------
worker[1] - 'localhost:13000' was not free
worker[1] - 'localhost:13020' was not free
worker[1] - 'localhost:13020' was not free
worker[1]
Started [mysqld.1 - pid: 2222438, winpid: 2222438]
worker[1] Using config include/default_my.cnf
worker[1] Port and socket path for server(s):
worker[1] mysqld.1 13030 /home/vagrant/repo/mysql-8.0.24/bld/mysql-test/var/tmp/mysqld.1.sock
worker[1] Server(s) started, not waiting for them to finish
ビルドした MySQL client で MySQL server に接続し、SELECT の直前までクエリを投入する。
../bin/mysql -u root -S /home/vagrant/repo/mysql-8.0.24/bld/mysql-test/var/tmp/mysqld.1.sock
mysql> USE test; Database changed mysql> CREATE TABLE t1 (a INT); Query OK, 0 rows affected (0.04 sec) mysql> INSERT INTO t1 VALUES (1); Query OK, 1 row affected (0.01 sec)
別ウィンドウで GDB を MySQL にアタッチする。PID は mysql-test-run.pl の出力にあるものを使えばよい。
sudo gdb -p 2222438
これでいい感じに GDB デバッグできる状態になったはずだ。 ブレークポイントを置くべき場所はわかっているがヒットしすぎるというケースはこれで解決だ。
一方、問題の箇所が特定できていないケースでは、GDB をお伴にコードの中を嗅ぎ回ることになる。そのような作業をしなくてはならない場合、代表的な関数を知っているとそこにブレークポイントを置けて便利である。
何が代表的な関数なのかわからなければ、書籍 "Expert MySQL" を読むとよい（古い本なので最新のコードとは乖離があることに注意）。例えば、InnoDB のテーブルスキャンであれば、mysql_execute_command(), ha_innobase::rnd_init(), ha_innobase::rnd_next() 等に打つのがよいのではないだろうか。
雰囲気を味わうために ha_innobase::rnd_next() ブレークポイントを置きバックトレースを見てみよう。
(gdb) b ha_innobase::rnd_next Breakpoint 2 at 0x56204df892b8: file /home/vagrant/repo/mysql-8.0.24/storage/innobase/handler/ha_innodb.cc, line 10469. (gdb) c Continuing. ...
MySQL client のウィンドウに戻り、SELECT を実行する。
mysql> SELECT * FROM t1;
すると GDB のウィンドウがブレークポイントで止まっているはずなので、バックトレースを出力させる。
...
Thread 38 "mysqld" hit Breakpoint 2, ha_innobase::rnd_next (this=0x7f978cabf3a8, buf=0x7f978c1b01c0 "\001\001\001\001")
at /home/vagrant/repo/mysql-8.0.24/storage/innobase/handler/ha_innodb.cc:10469
10469 {
(gdb) bt
#0 ha_innobase::rnd_next (this=0x7f978cabf3a8, buf=0x7f978c1b01c0 "\001\001\001\001") at /home/vagrant/repo/mysql-8.0.24/storage/innobase/handler/ha_innodb.cc:10469
#1 0x000056204ca37a62 in handler::ha_rnd_next (this=0x7f978cabddf8, buf=0x7f978cb48698 "\377") at /home/vagrant/repo/mysql-8.0.24/sql/handler.cc:2985
#2 0x000056204c50a251 in TableScanIterator::Read (this=0x7f978cac2f40) at /home/vagrant/repo/mysql-8.0.24/sql/records.cc:361
#3 0x000056204c7b5a51 in Query_expression::ExecuteIteratorQuery (this=0x7f978cb46698, thd=0x7f978c000f00) at /home/vagrant/repo/mysql-8.0.24/sql/sql_union.cc:1230
#4 0x000056204c7b5dda in Query_expression::execute (this=0x7f978cb46698, thd=0x7f978c000f00) at /home/vagrant/repo/mysql-8.0.24/sql/sql_union.cc:1283
#5 0x000056204c6fe340 in Sql_cmd_dml::execute_inner (this=0x7f978cac21d8, thd=0x7f978c000f00) at /home/vagrant/repo/mysql-8.0.24/sql/sql_select.cc:791
#6 0x000056204c6fd7fe in Sql_cmd_dml::execute (this=0x7f978cac21d8, thd=0x7f978c000f00) at /home/vagrant/repo/mysql-8.0.24/sql/sql_select.cc:575
#7 0x000056204c679446 in mysql_execute_command (thd=0x7f978c000f00, first_level=true) at /home/vagrant/repo/mysql-8.0.24/sql/sql_parse.cc:4412
#8 0x000056204c67b467 in dispatch_sql_command (thd=0x7f978c000f00, parser_state=0x7f98342f8b90) at /home/vagrant/repo/mysql-8.0.24/sql/sql_parse.cc:5000
#9 0x000056204c671588 in dispatch_command (thd=0x7f978c000f00, com_data=0x7f98342f9b80, command=COM_QUERY) at /home/vagrant/repo/mysql-8.0.24/sql/sql_parse.cc:1841
#10 0x000056204c66fa2b in do_command (thd=0x7f978c000f00) at /home/vagrant/repo/mysql-8.0.24/sql/sql_parse.cc:1320
#11 0x000056204c86c6b7 in handle_connection (arg=0x562055755770) at /home/vagrant/repo/mysql-8.0.24/sql/conn_handler/connection_handler_per_thread.cc:301
#12 0x000056204e720230 in pfs_spawn_thread (arg=0x562055913a60) at /home/vagrant/repo/mysql-8.0.24/storage/perfschema/pfs.cc:2898
#13 0x00007f9845984609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#14 0x00007f98450c2293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
MySQL 5.7 からずいぶんリファクタリングが進んだなと思わせるバックトレースである。
"Debugging MySQL/MariaDB" をタイトルに冠した記事は、この記事 (3) で一旦終わりとする。将来、新たに書きたいテーマが生まれたら、(4) を書くかもしれない。
