目录
1、debug package介绍
当你执行一条SQL,想快速跟踪 MySQL在做什么时,可以使用 DBUG 包。通过跟踪文件,我们可以更好地对 mysqld 进行调试跟踪及源码阅读。
The MySQL server and most MySQL clients are compiled with the DBUG package originally created by Fred Fish. When you have configured MySQL for debugging, this package makes it possible to get a trace file of what the program is doing.
官网介绍:MySQL :: MySQL 8.0 Reference Manual :: 5.9.4 The DBUG Package
2、源码安装MYSQL DEBUG版本
官方指导文档:MySQL :: MySQL 8.0 Reference Manual :: 2.9 Installing MySQL from Source
OS版本:CentOS Linux release 8.0.1905
mysql源码下载: MySQL :: Download MySQL Community Server (Archived Versions)
解压:unzip mysql-server-8.0.zip
检查make版本: make --version
GNU Make 4.2.1
检查gcc版本:gcc --version
gcc (GCC) 8.5.0 20210514 (Red Hat 8.5.0-4)
安装cmake: yum install cmake
安装g++: yum install gcc-c++
ncurses library安装:yum install ncurses
perl 安装:yum install perl -y
SSL library安装:
wget https://www.openssl.org/source/openssl-3.0.5.tar.gz
tar xvf openssl-3.0.5.tar.gz
cd openssl-3.0.5
./Configure
make
make test
make install
Boost C++ libraries安装:
wget https://boostorg.jfrog.io/artifactory/main/release/1.77.0/source/boost_1_77_0.tar.bz2
tar xvf boost_1_77_0.tar.bz2
./bootstrap.sh
./b2
./b2 install
ls /usr/local/include | grep boost
vi /etc/profile.d/boost.sh
#!/bin/sh
BOOST_ROOT=/data/boost_1_77_0
BOOST_INCLUDE=/usr/local/include/boost
BOOST_LIB=/usr/local/lib
export BOOST_INCLUDE BOOST_LIB BOOST_ROOT
chmod +x /etc/profile.d/boost.sh
source /etc/profile.d/boost.sh
MYSQL DEBUG版编译、安装、启动:
cd mysql-VERSION
mkdir bld
cd bld
cmake .. -DBUILD_CONFIG=mysql_release -DWITH_DEBUG=1
失败,提示安装
yum install gcc-toolset-11-gcc gcc-toolset-11-gcc-c++ gcc-toolset-11-binutils
yum install ncurses-devel
yum install libtirpc-devel
wget https://github.com/thkukuk/rpcsvc-proto/releases/download/v1.4/rpcsvc-proto-1.4.tar.gz
tar xf rpcsvc-proto-1.4.tar.gz
cd rpcsvc-proto-1.4
./configure
make
make install
yum install bison
make
make VERBOSE=1
make install
ln -s /usr/local/lib64/libssl.so.3 /usr/lib64/libssl.so.3
ln -s /usr/local/lib64/libcrypto.so.3 /usr/lib64/libcrypto.so.3
bin/mysqld-debug --initialize --user=mysql
bin/mysql_ssl_rsa_setup
cp support-files/mysql.server /etc/init.d/mysql.server
cd /usr/local/mysql/bin
./mysqld_safe &
3、DBUG 包启用说明
对于 mysqld 来讲,可以通过以下两种方式启用 DBUG 包。
- 在 mysqld 启动时,设置 --debug 选项
- 在 mysqld 运行时,修改 debug 参数
show variables like 'debug';
select @@debug;
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| debug | |
+---------------+-------+
3.1 debug设置参考例子
--debug=d:t
--debug=d:f,main,subr1:F:L:t,20
--debug=d,input,output,files:n
--debug=d:t:i:O,\\mysqld.trace
Each field within the value consists of a mandatory flag character, optionally preceded by a +
or -
character, and optionally followed by a comma-separated list of modifiers:
[+|-]flag[,modifier,modifier,...,modifier]
4、DBUG 包标志说明
Flag | Description |
---|---|
| Enable output from DBUG_ In MySQL, common debug macro keywords to enable are |
| Delay after each debugger output line. The argument is the delay, in tenths of seconds, subject to machine capabilities. For example, |
| Limit debugging, tracing, and profiling to the list of named functions. An empty list enables all functions. The appropriate |
| Identify the source file name for each line of debug or trace output. |
| Identify the process with the PID or thread ID for each line of debug or trace output. |
| Identify the source file line number for each line of debug or trace output. |
| Print the current function nesting depth for each line of debug or trace output. |
| Number each line of debug output. |
| Redirect the debugger output stream to the specified file. The default output is |
| Like |
| Limit debugger actions to specified processes. A process must be identified with the |
| Print the current process name for each line of debug or trace output. |
| When pushing a new state, do not inherit the previous state's function nesting level. Useful when the output is to start at the left margin. |
| Do function |
| Enable function call/exit trace lines. May be followed by a list (containing only one modifier) giving a numeric maximum trace level, beyond which no output occurs for either debugging or tracing macros. The default is a compile time option. |
5、使用体验
5.1 MYSQL使用DEBUG
使用 MySQL 客户端连上服务器,设置DEBUG参数,执行SQL。
mysql> set debug = 'd,info:n:N:F:i:L:o,/tmp/mysqld.trace';
Query OK, 0 rows affected (0.00 sec)
mysql> select @debug,@@debug;
+----------------+--------------------------------------+
| @debug | @@debug |
+----------------+--------------------------------------+
| NULL | d,info:F:i:L:n:N:o,/tmp/mysqld.trace |
+----------------+--------------------------------------+
1 row in set (0.00 sec)
mysql> select * from a;
+------+
| id |
+------+
| 1 |
| 2 |
+------+
2 rows in set (0.01 sec)
观察mysqld.trace文件
tail -f mysqld.trace
MYSQL_BIN_LOG::commit: info: query='select @debug,@@debug'
T@309: 428: sql_parse.cc: 2061: 2: dispatch_command: info: query ready
T@309: 429: protocol_classic.cc: 917: 5: net_send_ok: info: affected_rows: 0 id: 0 status: 2 warning_count: 0
T@309: 430: protocol_classic.cc: 976: 5: net_send_ok: info: OK sent, so no more error sending allowed
T@309: 431: protocol_classic.cc: 2825: 2: Protocol_classic::parse_packet: info: param count 0l
T@309: 432: sql_parse.cc: 1345: 1: do_command: info: Command on socket (26) = 3 (Query)
T@309: 433: sql_parse.cc: 1348: 1: do_command: info: packet: ' '; command: 3
T@309: 434: sql_parse.cc: 1623: 2: dispatch_command: info: command: 3
T@309: 435: rpl_gtid_execution.cc: 441: 5: gtid_pre_statement_checks: info: gtid_next->type=0 owned_gtid.{sidno,gno}={0,0}
T@309: 436: binlog.cc: 10556: 6: THD::is_ddl_gtid_compatible: info: is_binlog_open:1 is_binlog_enabled_for_session:1
T@309: 437: binlog.cc: 10589: 6: THD::is_ddl_gtid_compatible: info: is_create_table:0 is_create_temporary_table:0 is_create_table_select:0 is_create_table_atomic:0 is_drop_table:0 is_drop_temporary_table:0 is_in_transaction:0 is_in_sub_statement:0 is_binlog_format_statement:0
T@309: 438: sql_authorization.cc: 2367: 7: check_table_access: info: table: a derived: 0 view: 0
T@309: 439: handler.cc: 3835: 11: void handler::column_bitmaps_signal: info: read_set: 0x7fb434fe3988 write_set: 0x7fb434fe39a0
T@309: 440: table.cc: 5156: 10: Field_iterator_table_ref::set_field_iterator: info: field_it for 'a' is Field_iterator_table
T@309: 441: sql_resolver.cc: 2520: 7: Query_block::prepare: info: setup_ref_array this 0x7fb41402ead0 3 : 0 0 1 1 1 0 0
T@309: 442: sql_base.cc: 9006: 8: setup_fields: info: thd->mark_used_columns: 1
T@309: 443: sql_base.cc: 9148: 8: setup_fields: info: thd->mark_used_columns: 1
T@309: 444: sql_resolver.cc: 1645: 8: Query_block::setup_conds: info: thd->mark_used_columns: 1
T@309: 445: lock.cc: 648: 8: get_lock_data: info: count 1
T@309: 446: lock.cc: 716: 8: get_lock_data: info: sql_lock->table_count 1 sql_lock->lock_count 0
T@309: 447: lock.cc: 335: 7: mysql_lock_tables: info: thd->proc_info System lock
T@309: 448: lock.cc: 384: 8: lock_external: info: count 1
T@309: 449: binlog.cc: 9860: 7: THD::decide_logging_format: info: query: select * from a
T@309: 450: binlog.cc: 9861: 7: THD::decide_logging_format: info: variables.binlog_format: 2
T@309: 451: binlog.cc: 9862: 7: THD::decide_logging_format: info: lex->get_stmt_unsafe_flags(): 0x0
T@309: 452: binlog.cc: 10036: 7: THD::decide_logging_format: info: table: a; ha_table_flags: 0x8ffa8c00638496
T@309: 453: binlog.cc: 10172: 7: THD::decide_logging_format: info: flags_write_all_set: 0xc00000000
T@309: 454: binlog.cc: 10173: 7: THD::decide_logging_format: info: flags_write_some_set: 0x0
T@309: 455: binlog.cc: 10174: 7: THD::decide_logging_format: info: flags_access_some_set: 0x8ffa8c00638496
T@309: 456: binlog.cc: 10176: 7: THD::decide_logging_format: info: multi_write_engine: 0
T@309: 457: binlog.cc: 10177: 7: THD::decide_logging_format: info: multi_access_engine: 0
T@309: 458: binlog.cc: 10660: 8: THD::is_dml_gtid_compatible: info: some_non_transactional_table=0 some_transactional_table=0 trans_has_updated_trans_table=0 non_transactional_tables_are_tmp=0 is_current_stmt_binlog_format_row=1
T@309: 459: binlog.cc: 10394: 7: THD::decide_logging_format: info: decision: logging in ROW format
Info about JOIN
a type: ALL q_keys: 0 refs: 0 key: -1 len: 0
T@309: 460: sql_executor.cc: 585: 10: JOIN::get_end_select_func: info: Using end_send
T@309: 461: protocol_classic.cc: 3084: 8: bool Protocol_classic::start_result_metadata: info: num_cols 1, flags 5
5.2 MYSQLDUMP使用DEBUG
./mysqldump -h127.0.0.1 -uroot -proot --debug='d,query:n:N:F:i:L:o,/tmp/mysqldump.trace' ldc -vvvv
查看/tmp/mysqldump.trace文件,可以很清晰看出MYSQLDUMP的流程。这种办法比GDB MYSQLDUMP或者查看MYSQL GENERAL日志,更智能化。
cat mysqldump.trace
T@1: 1: client.cc: 7898: 2: mysql_real_query: query: Query = '/*!40100 SET @@SQL_MODE='' */'
T@1: 2: client.cc: 7898: 2: mysql_real_query: query: Query = '/*!40103 SET TIME_ZONE='+00:00' */'
T@1: 3: client.cc: 7898: 2: mysql_real_query: query: Query = '/*!80000 SET SESSION information_schema_stats_expiry=0 */'
T@1: 4: client.cc: 7898: 2: mysql_real_query: query: Query = 'SET SESSION NET_READ_TIMEOUT= 86400, SESSION NET_WRITE_TIMEOUT= 86400'
T@1: 5: client.cc: 7898: 1: mysql_real_query: query: Query = 'SHOW VARIABLES LIKE 'gtid\_mode''
T@1: 6: client.cc: 7898: 2: mysql_real_query: query: Query = 'SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE ENGINE = 'ndbcluster' AND FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IN (SELECT DISTINCT LOGFILE_GROUP_NAME FROM INFORMATION_SCHEMA.FILES WHERE ENGINE = 'ndbcluster' AND FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('ldc'))) GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE, TOTAL_EXTENTS, INITIAL_SIZE ORDER BY LOGFILE_GROUP_NAME'
T@1: 7: client.cc: 7898: 2: mysql_real_query: query: Query = 'SELECT DISTINCT TABLESPACE_NAME, FILE_NAME, LOGFILE_GROUP_NAME, EXTENT_SIZE, INITIAL_SIZE, ENGINE FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('ldc')) ORDER BY TABLESPACE_NAME, LOGFILE_GROUP_NAME'
T@1: 8: client.cc: 7898: 3: mysql_real_query: query: Query = 'SHOW VARIABLES LIKE 'ndbinfo\_version''
T@1: 9: client.cc: 7898: 4: mysql_real_query: query: Query = 'show tables'
T@1: 10: client.cc: 7898: 3: mysql_real_query: query: Query = 'LOCK TABLES `a` READ /*!32311 LOCAL */'
T@1: 11: client.cc: 7898: 6: mysql_real_query: query: Query = 'show table status like 'a''
T@1: 12: client.cc: 7898: 5: mysql_real_query: query: Query = 'SET SQL_QUOTE_SHOW_CREATE=1'
T@1: 13: client.cc: 7898: 5: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'binary''
T@1: 14: client.cc: 7898: 5: mysql_real_query: query: Query = 'show create table `a`'
T@1: 15: client.cc: 7898: 5: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'utf8mb4''
T@1: 16: client.cc: 7898: 5: mysql_real_query: query: Query = 'show fields from `a`'
T@1: 17: client.cc: 7898: 5: mysql_real_query: query: Query = 'show fields from `a`'
T@1: 18: client.cc: 7898: 4: mysql_real_query: query: Query = 'SELECT /*!40001 SQL_NO_CACHE */ * FROM `a`'
T@1: 19: client.cc: 7898: 4: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'binary''
T@1: 20: client.cc: 7898: 4: mysql_real_query: query: Query = 'use `ldc`'
T@1: 21: client.cc: 7898: 4: mysql_real_query: query: Query = 'select @@collation_database'
T@1: 22: client.cc: 7898: 4: mysql_real_query: query: Query = 'SHOW TRIGGERS LIKE 'a''
T@1: 23: client.cc: 7898: 4: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'utf8mb4''
T@1: 24: client.cc: 7898: 4: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'binary''
T@1: 25: client.cc: 7898: 4: mysql_real_query: query: Query = 'SELECT COLUMN_NAME, JSON_EXTRACT(HISTOGRAM, '$."number-of-buckets-specified"') FROM information_schema.COLUMN_STATISTICS WHERE SCHEMA_NAME = 'ldc' AND TABLE_NAME = 'a';'
T@1: 26: client.cc: 7898: 4: mysql_real_query: query: Query = 'SET SESSION character_set_results = 'utf8mb4''
T@1: 27: client.cc: 7898: 3: mysql_real_query: query: Query = 'UNLOCK TABLES'
User time 0.00, System time 0.00
Maximum resident set size 11176, Integral resident set size 0
Non-physical pagefaults 561, Physical pagefaults 0, Swaps 0
Blocks in 0 out 0, Messages in 0 out 0, Signals 0
Voluntary context switches 37, Involuntary context switches 0
5.3 MYSQLSLAP使用DEBUG
./mysqlslap -T -h127.0.0.1 -uroot -proot --concurrency=1 --iterations=1 --create-schema=ldc --query="select now()" --debug='d:n:N:F:i:L:t:o,/tmp/mysqlslap.trace' -vvvv
查看mysqlslap.trace文件
cat mysqlslap.trace | grep mysqlslap
T@1: 1: mysqlslap.cc: 2: | <get_one_option
T@1: 2: mysqlslap.cc: 750: 2: | >get_one_option
T@1: 3: mysqlslap.cc: 2: | <get_one_option
T@1: 4: mysqlslap.cc: 750: 2: | >get_one_option
T@1: 5: mysqlslap.cc: 2: | <get_one_option
T@1: 6: mysqlslap.cc: 750: 2: | >get_one_option
T@1: 7: mysqlslap.cc: 2: | <get_one_option
T@1: 8: mysqlslap.cc: 750: 2: | >get_one_option
T@1: 9: mysqlslap.cc: 2: | <get_one_option
T@1: 14: mysqlslap.cc: 1: <get_options
T@1: 399: mysqlslap.cc: 1616: 1: >run_scheduler
T@1: 400: mysqlslap.cc: 1: <run_scheduler