admin管理员组

文章数量:1033940

MySQL源码学习系列（二）

在实际工作中，我们常常会遇到各种各样的数据库问题，比如查询性能低下、数据不一致等。为了更好地诊断和解决这些问题，MySQL 提供了丰富的日志功能，其中 general log 和慢查询日志（slowlog）是两个非常重要的日志类型。

General log 会记录 MySQL 服务器接收到的所有 SQL 语句，就像一个全面的监控摄像头，不放过任何一个数据库操作。而慢查询日志则专注于记录执行时间超过指定阈值的 SQL 语句，帮助我们定位那些 “拖后腿” 的查询，从而进行针对性的优化。理解这两种日志的记录顺序，不仅有助于我们在生产环境中高效地排查问题，也是面试中经常被问到的高频考点。

1. 准备工作

1.1 环境准备

准备一套MySQL8.0.40的源码编译实例，相关编译环境及基本命令可以参考历史文章准备

MySQL8.0.40编译安装

MySQL源码学习系列（一）-- 环境准备及常用命令

1.2 调整参数

开启慢SQL并设置阈值为1s、开启general log

代码语言：javascript代码运行次数：0运行复制
mysql> set global slow_query_log=1;
Query OK, 0 rows affected (0.00 sec)

mysql> set global long_query_time=1;
Query OK, 0 rows affected (0.00 sec)

mysql> set global  general_log=1;
Query OK, 0 rows affected (0.00 sec)

mysql> show global variables like '%slow%';
+-----------------------------+-----------------------------------------------------------------+
| Variable_name               | Value                                                           |
+-----------------------------+-----------------------------------------------------------------+
| log_slow_admin_statements   | OFF                                                             |
| log_slow_extra              | OFF                                                             |
| log_slow_replica_statements | OFF                                                             |
| log_slow_slave_statements   | OFF                                                             |
| slow_launch_time            | 2                                                               |
| slow_query_log              | ON                                                              |
| slow_query_log_file         | /usr/local/mysql-8.0.40/mysql-test/var/mysqld.1/mysqld-slow.log |
+-----------------------------+-----------------------------------------------------------------+
7 rows in set (0.01 sec)

mysql> show global variables like '%long%';
+----------------------------------------------------------+----------+
| Variable_name                                            | Value    |
+----------------------------------------------------------+----------+
| long_query_time                                          | 1.000000 |
| performance_schema_events_stages_history_long_size       | 1000     |
| performance_schema_events_statements_history_long_size   | 1000     |
| performance_schema_events_transactions_history_long_size | 1000     |
| performance_schema_events_waits_history_long_size        | 10000    |
+----------------------------------------------------------+----------+
5 rows in set (0.01 sec)

mysql> show global variables like '%general%';
+------------------+------------------------------------------------------------+
| Variable_name    | Value                                                      |
+------------------+------------------------------------------------------------+
| general_log      | ON                                                         |
| general_log_file | /usr/local/mysql-8.0.40/mysql-test/var/mysqld.1/mysqld.log |
+------------------+------------------------------------------------------------+
2 rows in set (0.02 sec)

mysql>

2. 通过GDB调试确定执行顺序

2.1 选择断点

可以选择几个断点来设置，只是确定三个日志的写入顺序可以选如下断点（其他的也可）

日志类型

源码文件

设置断点

General Log

sql/log

general_log_write

慢查询日志

sql/log

write_slow

SQL语句

sql/sql_parse

mysql_execute_command

2.2 设置断点

启动gdb后设置断点

代码语言：javascript代码运行次数：0运行复制
(gdb) b mysql_execute_command
Breakpoint 1 at 0x5c59b7e80d77: file /usr/local/mysql-8.0.40/sql/sql_parse, line 2946.
(gdb) b general_log_write
Breakpoint 2 at 0x5c59b85400c8: file /usr/local/mysql-8.0.40/sql/log, line 1374.
(gdb) b write_slow
Breakpoint 3 at 0x5c59b853d498: file /usr/local/mysql-8.0.40/sql/log, line 687.
(gdb) info b 
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   0x00005c59b7e80d77 in mysql_execute_command(THD*, bool) at /usr/local/mysql-8.0.40/sql/sql_parse:2946
2       breakpoint     keep y   0x00005c59b85400c8 in Query_logger::general_log_write(THD*, enum_server_command, char const*, unsigned long) at /usr/local/mysql-8.0.40/sql/log:1374
3       breakpoint     keep y   0x00005c59b853d498 in File_query_log::write_slow(THD*, unsigned long long, unsigned long long, char const*, unsigned long, unsigned long long, unsigned long long, bool, char const*, unsigned long) at /usr/local/mysql-8.0.40/sql/log:687
(gdb)

2.3 开始执行SQL调试

在sql里执行一个慢SQL

代码语言：javascript代码运行次数：0运行复制
mysql> select sleep(2);

gdb里命中第一个断点：Query_logger::general_log_write

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.
[Switching to Thread 0x7ba3a4fff640 (LWP 32375)]
Thread 39 "connection" hit Breakpoint 2, Query_logger::general_log_write (this=0x5c59bd33d140 <query_logger>, thd=0x7ba310001200, command=COM_QUERY, query=0x7ba31002fc90 "select sleep(2)", query_length=15) at /usr/local/mysql-8.0.40/sql/log:1374
1374	                                     const char *query, size_t query_length) {
(gdb)

gdb继续命中第二个断点：mysql_execute_command

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.

Thread 39 "connection" hit Breakpoint 1, mysql_execute_command (thd=0x7ba310001200, first_level=true) at /usr/local/mysql-8.0.40/sql/sql_parse:2946
2946	int mysql_execute_command(THD *thd, bool first_level) {
(gdb) p m_query_string
No symbol "m_query_string" in current context.
(gdb) p thd.m_query_string
$1 = {str = 0x7ba31002fc90 "select sleep(2)", length = 15}

再继续，命中第三个断点：File_query_log::write_slow

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.

Thread 39 "connection" hit Breakpoint 3, File_query_log::write_slow (this=0x5c59d9ba18a8, thd=0x7ba310001200, current_utime=1743142862100420, query_start_utime=1743142567761813, user_host=0x7ba3a4ffd5c0 "root[root] @ localhost [127.0.0.1]", query_utime=294338607, lock_utime=0, is_command=false, sql_text=0x7ba31002fc90 "select sleep(2)", sql_text_len=15) at /usr/local/mysql-8.0.40/sql/log:687
687	                                size_t sql_text_len) {
(gdb)

MySQL中也返回了结果

至此，可以验证出MySQL在执行SQL语句时，先写general log、再执行SQL、最后写slowlog。

大致的流程如下

3. 小结

从以上验证结果中可以得出MySQL在执行SQL语句时，先写general log、再执行SQL、最后写slowlog。

不过，还有遗留问题，例如，general log是在sql解析器写入还是解析后写入？ slow log是在事务提交前写入还是提交后写入。继续我们继续探索。

本文参与 腾讯云自媒体同步曝光计划，分享自微信公众号。原始发表：2025-03-28，如有侵权请联系 cloudcommunity@tencent 删除源码学习mysql编译面试日志

MySQL源码学习系列（二）

在实际工作中，我们常常会遇到各种各样的数据库问题，比如查询性能低下、数据不一致等。为了更好地诊断和解决这些问题，MySQL 提供了丰富的日志功能，其中 general log 和慢查询日志（slowlog）是两个非常重要的日志类型。

General log 会记录 MySQL 服务器接收到的所有 SQL 语句，就像一个全面的监控摄像头，不放过任何一个数据库操作。而慢查询日志则专注于记录执行时间超过指定阈值的 SQL 语句，帮助我们定位那些 “拖后腿” 的查询，从而进行针对性的优化。理解这两种日志的记录顺序，不仅有助于我们在生产环境中高效地排查问题，也是面试中经常被问到的高频考点。

1. 准备工作

1.1 环境准备

准备一套MySQL8.0.40的源码编译实例，相关编译环境及基本命令可以参考历史文章准备

MySQL8.0.40编译安装

MySQL源码学习系列（一）-- 环境准备及常用命令

1.2 调整参数

开启慢SQL并设置阈值为1s、开启general log

代码语言：javascript代码运行次数：0运行复制
mysql> set global slow_query_log=1;
Query OK, 0 rows affected (0.00 sec)

mysql> set global long_query_time=1;
Query OK, 0 rows affected (0.00 sec)

mysql> set global  general_log=1;
Query OK, 0 rows affected (0.00 sec)

mysql> show global variables like '%slow%';
+-----------------------------+-----------------------------------------------------------------+
| Variable_name               | Value                                                           |
+-----------------------------+-----------------------------------------------------------------+
| log_slow_admin_statements   | OFF                                                             |
| log_slow_extra              | OFF                                                             |
| log_slow_replica_statements | OFF                                                             |
| log_slow_slave_statements   | OFF                                                             |
| slow_launch_time            | 2                                                               |
| slow_query_log              | ON                                                              |
| slow_query_log_file         | /usr/local/mysql-8.0.40/mysql-test/var/mysqld.1/mysqld-slow.log |
+-----------------------------+-----------------------------------------------------------------+
7 rows in set (0.01 sec)

mysql> show global variables like '%long%';
+----------------------------------------------------------+----------+
| Variable_name                                            | Value    |
+----------------------------------------------------------+----------+
| long_query_time                                          | 1.000000 |
| performance_schema_events_stages_history_long_size       | 1000     |
| performance_schema_events_statements_history_long_size   | 1000     |
| performance_schema_events_transactions_history_long_size | 1000     |
| performance_schema_events_waits_history_long_size        | 10000    |
+----------------------------------------------------------+----------+
5 rows in set (0.01 sec)

mysql> show global variables like '%general%';
+------------------+------------------------------------------------------------+
| Variable_name    | Value                                                      |
+------------------+------------------------------------------------------------+
| general_log      | ON                                                         |
| general_log_file | /usr/local/mysql-8.0.40/mysql-test/var/mysqld.1/mysqld.log |
+------------------+------------------------------------------------------------+
2 rows in set (0.02 sec)

mysql>

2. 通过GDB调试确定执行顺序

2.1 选择断点

可以选择几个断点来设置，只是确定三个日志的写入顺序可以选如下断点（其他的也可）

日志类型

源码文件

设置断点

General Log

sql/log

general_log_write

慢查询日志

sql/log

write_slow

SQL语句

sql/sql_parse

mysql_execute_command

2.2 设置断点

启动gdb后设置断点

代码语言：javascript代码运行次数：0运行复制
(gdb) b mysql_execute_command
Breakpoint 1 at 0x5c59b7e80d77: file /usr/local/mysql-8.0.40/sql/sql_parse, line 2946.
(gdb) b general_log_write
Breakpoint 2 at 0x5c59b85400c8: file /usr/local/mysql-8.0.40/sql/log, line 1374.
(gdb) b write_slow
Breakpoint 3 at 0x5c59b853d498: file /usr/local/mysql-8.0.40/sql/log, line 687.
(gdb) info b 
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   0x00005c59b7e80d77 in mysql_execute_command(THD*, bool) at /usr/local/mysql-8.0.40/sql/sql_parse:2946
2       breakpoint     keep y   0x00005c59b85400c8 in Query_logger::general_log_write(THD*, enum_server_command, char const*, unsigned long) at /usr/local/mysql-8.0.40/sql/log:1374
3       breakpoint     keep y   0x00005c59b853d498 in File_query_log::write_slow(THD*, unsigned long long, unsigned long long, char const*, unsigned long, unsigned long long, unsigned long long, bool, char const*, unsigned long) at /usr/local/mysql-8.0.40/sql/log:687
(gdb)

2.3 开始执行SQL调试

在sql里执行一个慢SQL

代码语言：javascript代码运行次数：0运行复制
mysql> select sleep(2);

gdb里命中第一个断点：Query_logger::general_log_write

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.
[Switching to Thread 0x7ba3a4fff640 (LWP 32375)]
Thread 39 "connection" hit Breakpoint 2, Query_logger::general_log_write (this=0x5c59bd33d140 <query_logger>, thd=0x7ba310001200, command=COM_QUERY, query=0x7ba31002fc90 "select sleep(2)", query_length=15) at /usr/local/mysql-8.0.40/sql/log:1374
1374	                                     const char *query, size_t query_length) {
(gdb)

gdb继续命中第二个断点：mysql_execute_command

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.

Thread 39 "connection" hit Breakpoint 1, mysql_execute_command (thd=0x7ba310001200, first_level=true) at /usr/local/mysql-8.0.40/sql/sql_parse:2946
2946	int mysql_execute_command(THD *thd, bool first_level) {
(gdb) p m_query_string
No symbol "m_query_string" in current context.
(gdb) p thd.m_query_string
$1 = {str = 0x7ba31002fc90 "select sleep(2)", length = 15}

再继续，命中第三个断点：File_query_log::write_slow

代码语言：javascript代码运行次数：0运行复制
(gdb) c
Continuing.

Thread 39 "connection" hit Breakpoint 3, File_query_log::write_slow (this=0x5c59d9ba18a8, thd=0x7ba310001200, current_utime=1743142862100420, query_start_utime=1743142567761813, user_host=0x7ba3a4ffd5c0 "root[root] @ localhost [127.0.0.1]", query_utime=294338607, lock_utime=0, is_command=false, sql_text=0x7ba31002fc90 "select sleep(2)", sql_text_len=15) at /usr/local/mysql-8.0.40/sql/log:687
687	                                size_t sql_text_len) {
(gdb)

MySQL中也返回了结果

至此，可以验证出MySQL在执行SQL语句时，先写general log、再执行SQL、最后写slowlog。

大致的流程如下

3. 小结

从以上验证结果中可以得出MySQL在执行SQL语句时，先写general log、再执行SQL、最后写slowlog。

不过，还有遗留问题，例如，general log是在sql解析器写入还是解析后写入？ slow log是在事务提交前写入还是提交后写入。继续我们继续探索。

本文参与 腾讯云自媒体同步曝光计划，分享自微信公众号。原始发表：2025-03-28，如有侵权请联系 cloudcommunity@tencent 删除源码学习mysql编译面试日志

本文标签： MySQL源码学习系列（二）

版权声明：本文标题：MySQL源码学习系列（二） 内容由热心网友自发贡献，该文观点仅代表作者本人， 转载请联系作者并注明出处：http://it.en369.cn/jiaocheng/1748095391a2251715.html， 本站仅提供信息存储空间服务，不拥有所有权，不承担相关法律责任。如发现本站有涉嫌抄袭侵权/违法违规的内容，一经查实，本站将立刻删除。