(9)MySQL 5.7 录制慢SQL方法

在my.cnf配置文件打开慢SQL开关：

[mysqld]

log_slow_admin_statements = ON

log_slow_slave_statements = ON

slow_query_log = ON

slow_query_log_file = /opt/slowquery.log(自定义路径)

log_output = TABLE # TABLE, FILE模式

配置完成后，需要重启mysqld服务，然后连接上mysql客户端，输入selete 1测试一下。

要确定是否生效，可以使用select * from mysql.slow_log查询。

一、背景

近期，公司RDS云产品的MySQL Server版本进行升级，由目前使用的5.7.26版本升级到最新版本5.7.31；升级后测试同学发现：在MySQL创建用户后，5.7.31版本重新启动集群会出现启动失败的现象；而5.7.26版本在相同测试场景下是正常启动的。这到底是为什么呢?

二、问题复现

2.1 实验环境

2.2 *** 作步骤

按照测试同学的测试步骤，首先创建一个用户：

然后关闭mysqld；这里需要介绍一下，我们集群的关闭方式是如下方式：

这种方式的内部实现类似于kill -9模式。所以我在线下环境使用kill -9的方式来复现， *** 作如下：

然后重启mysqld， *** 作如下：

此时问题复现了，mysqld启动失败，我们查看了下error日志，信息如下：

根据报错信息可以看出:MySQL的权限系统表发生了损坏，导致了mysqld启动失败；由于在MySQL 5.7及其之前版本该表是MyISAM引擎，且该引擎不支持事务，所以在mysqld异常崩溃会导致该类型引擎表的损坏但在mysqld启动时是有参数控制MyISAM引擎的恢复模式，且该参数在我们产品中也配置到了my.cnf中，如下所示：

2.3 参数解析

对于该参数的官方文档的解释如下：

设置MyISAM存储引擎恢复模式。选项值是OFF、DEFAULT、BACKUP、FORCE或QUICK的值的任意组合。如果指定多个值，请用逗号分隔。指定不带参数的选项与指定DEFAULT相同，指定显式值" "将禁用恢复(与OFF值相同)。如果启用了恢复，则mysqld每次打开MyISAM表时，都会检查该表是否标记为已崩溃或未正确关闭。(只有在禁用外部锁定的情况下运行，最后一个选项才起作用。)在这种情况下，mysqld在表上运行检查。如果表已损坏，mysqld将尝试对其进行修复。

服务器自动修复表之前，它将有关修复的注释写到错误日志中。如果您希望能够在无需用户干预的情况下从大多数问题中恢复，则应使用选项BACKUP，FORCE。即使某些行将被删除，这也会强制修复表，但是它将旧的数据文件保留为备份，以便您以后可以检查发生了什么。

全局变量，只读变量，默认为OFF。

三、问题修复

这类MySQL用户表损耗的问题解决方式也是有多种，我这里列举其中一种：

（1）my.cnf中的[mysqld]标签下添加skip_grant_tables，启动时跳过加载系统字典。

（2）重启mysqld，然后修复mysql schema下的所有表。

（3）在[mysqld]标签下注释或删除掉skip_grant_tables，然后重启mysqld。

此时mysqld是可以正常启动的，无异常。

四、深入排查

在产品化中，以上修复方式很不优雅，只是作为临时的解决方案并且也存在一些令人疑惑的点：

带着这些疑问，我们继续排查出现该现象的原因；此时Google也没有找到一些有效的信息，那么只能通过MySQL源代码来寻找一些答案。

首先需要下载mysql 5.7.31版本的源代码，并搭建mysql debug环境；具体步骤可以自动Google搜索一下，本文就不再赘述了。

在源代码中搜索一下关键词，用于打断点的位置，然后进行调试：

定位到相关代码，大概是sql/mysqld.cc的4958行，且存在if条件判断，此时我们开始调试：

通过以上调试信息，可以判断出acl_init函数返回的值为真此时我们查看该函数的代码 (sql/auth/sql_auth_cache.cc:1365)：

根据该函数的注释发现：该函数是初始化负责用户/数据库级特权检查的结构，并从mysql schema中的表中为其加载特权信息；且return值为1代表的是初始化权限失败。

此后开始逐步调试，观察return相关信息，当调试到lock_table_names函数时，我们发现在Phase 3时return值为true，且根据代码注释发现true代表是Failure；具体代码如下(sql/sql_base.cc:5549)：

调试信息如下：

可以看到flags的值为0，而MYSQL_OPEN_SKIP_SCOPED_MDL_LOCK为宏定义值0x1000，与flags的值 做按位与 *** 作，结果自然也是0，当然MYSQL_LOCK_IGNORE_GLOBAL_READ_ONLY也是如此need_global_read_lock_protection是bool类型值，代表是否需要全局读锁的保护，这个值是在table- >mdl_request.type不为MDL_SHARED_READ_ONLY发生改变check_readonly函数相关信息 下面概述。

此时也查看了下MySQL 5.7.26版本代码作为对比，发现lock_table_names函数下的Phase 3后的部分代 码是在5.7.29版本后新增的。如果是git clone的MySQL代码可以用git blame命令查询文件变化的信息：

上述展示的信息中，最左侧的列值为commit id为05824063和0405ebee，有兴趣的同学可以详细看下。

此功能解决的问题是BUG#28438114: SET READ_ONLY=1 SOMETIMES DOESN'T BLOCK CONCURRENT DDL.；当然这个代码的变更功能也在5.7 Release Notes中有所体现，如下所示( https://dev.mysql.co m/doc/relnotes/mysql/5.7/en/news-5-7-29.html )：

最后我们再查看下check_readonly函数，该函数是基于read_only和super_read_only状态执行标准化检查，是禁止(TRUE)还是允许(FALSE) *** 作。代码如下(sql/auth/sql_authorization.cc:489)：

此时第一反应就是去检查my.cnf中是否包含read_only相关参数，检查之后发现确实是使用了该参数， 如下：

此时注释掉该参数，然后再次启动mysqld，发现MyISAM表可以自动修复，且正常启动；error log信息如下：

由于docker一些限制，我们在mysqld启动会涉及两次所以解决该问题的方式为：第一次mysqld的启动时先关闭read_only参数，第二次启动时开启read_only参数。之所以选择默认开启read_only参数， 是为了避免在mysqld启动后，选主逻辑未完成时的保护措施；当然选主完成后，会自动对master执行 set global read_only=0 *** 作。

五、总结

六、附录

调试的栈帧信息如下，有兴趣的小伙伴可以研究下：

熟悉MySQL体系结构和innodb存储引擎工作原理；以及MySQL备份恢复、复制、数据迁移等技术；专注于MySQL、MariaDB开源数据库，喜好开源技术。

原文链接：https://www.heapdump.cn/articles

从mysql5.7导出所有数据到远程主机： mysqldump --opt -uroot -p --all-databases | gzip -c | ssh user@192.168.0.100 "cat >/tmp/db.sql.gz" 或本地： mysqldump --opt -uroot -p --all-databases | gzip >/tmp/db.sql.zip 导出可加参数: --ignore-table=mysql.innodb_index_stats --ignore-table=mysql.innodb_table_stats 导入到mysql8.0: gunzip -f </tmp/db.sql.gz | mysql -u root -p -f 升级数据字典、Performance Schema 和 INFORMATION_SCHEMA: systemctl stop mysql mysqld --upgrade=FORCE systemctl start mysql

---