当前位置：首页 >> 资讯 > > 正文

故障分析 | TRUNCATE 到底因何而慢？

2023-06-19 17:02:04来源：互联网

作者：李锡超

一个爱笑的江苏苏宁银行数据库工程师，主要负责数据库日常运维、自动化建设、DMP 平台运维。擅长 MySQL、Python、Oracle，爱好骑行、研究技术。

(资料图)

本文来源：原创投稿

* 爱可生开源社区出品，原创内容未经授权不得随意使用，转载请联系小编并注明来源。

1问题现象

收到反馈某测试环境执行批量操作时，有 truncate 语句存在于慢查询日志中。担心上线后可能影响数据库，请求 DBA 配合分析。

关键配置

配置项说明

数据库版本	MySQL 5.7
参数 long_query_time 慢查询阈值，单位为秒	0.1（100 毫秒）
参数 innodb_adaptive_hash_index	ON

问题分析总结

总结下来主要有如下几个问题：

Q1: TRUNCATE 语句是如何执行的？fd 句柄不变化？为什么执行时间长？

TRUNCATE 语句如何执行？

关键堆栈：

关键操作 debug：

为什么执行时间长？

从以上堆栈可以看到，耗时过程主要是 row_drop_table_for_mysql、os_file_delete_func。

其中：row_drop_table_for_mysql 主要是调用 btr_drop_ahi_for_table 执行 AHI 的 page 页的删除。os_file_delete_func 主要调用 unlink 执行文件的清理。

句柄为什么不变化？

假如需要 truncate 的表分配的 fd 为 43，truncate 过程中，会先将表 rename。这个时候这个 fd 会被关闭，43 就被释放了。然后执行 create table 操作。一般这个间隙过程很短，因此新建立的表可以使用被释放的 43 了，所以会看到 fd 没有变化。

如果 rename 之后，在内部执行 create table 之前，又打开了新文件，那这时候 fd 43 就会被其它打开的文件持有，truncate 之后表的 fd 也就会发生变化。

注意：MySQL 8.0 是真正使用 rename + create + drop实现的 truncate，但 MySQL 5.7 是通过文件的 truncate 实现的。

Q2: 如何分析 TRUNCATE 慢的问题？

方式一：慢日志？

只能看到慢的结果，无法确认原因。

方式二：执行计划？

不支持 truncate 语句。

方式三：PROFILE

从 profile 结果来看，对于 truncate 语句，只能看到耗时过程都在System lock 上，无法看到更近一步的原因。

方式四：DEBUG

//推荐设置//其中 T 其实是 MySQL 支持（在 trace 中打印时间）的，但官方文档中缺少了说明。已提交bug说明：Bug #111174setglobaldebug="d:t:T:i:n:N:o,/tmp/debug_3306.trace.f";setglobaldebug="";

① 表示 show processlist 的线程 ID

② 执行时间

③ 函数调用层级

④ 函数名称

MySQL 8.0 切换对比

//TRUNCATE//默认规范配置//innodb_flush_method=on&innodb_flush_method=O_DIRECT(root@127.1)[eolbimsdb]08:44:4615>truncatetablet5;QueryOK,0rowsaffected(0.98sec)//设置innodb_adaptive_hash_index=off(root@127.1)[eolbimsdb]08:52:035>truncatetablet5;QueryOK,0rowsaffected(0.03sec)//设置innodb_flush_method=fsync(root@127.1)[eolbimsdb]09:03:3428>truncatetablet5;QueryOK,0rowsaffected(1.04sec)//设置innodb_adaptive_hash_index=off&innodb_flush_method=fsync(root@127.1)[eolbimsdb]09:20:245>truncatetablet5;QueryOK,0rowsaffected(0.22sec)//DROP//默认规范配置//innodb_flush_method=on&innodb_flush_method=O_DIRECT(root@127.1)[eolbimsdb]10:05:419>droptablet5;QueryOK,0rowsaffected(0.94sec)//设置innodb_adaptive_hash_index=off&innodb_flush_method=O_DIRECT(root@127.1)[eolbimsdb]09:44:245>droptablet5;QueryOK,0rowsaffected(0.01sec)//设置innodb_flush_method=on&innodb_flush_method=fsync(root@127.1)[eolbimsdb]09:32:1513>droptablet5;QueryOK,0rowsaffected(1.13sec)//设置innodb_adaptive_hash_index=off&innodb_flush_method=fsync(root@127.1)[eolbimsdb]09:25:1014>droptablet5;QueryOK,0rowsaffected(0.19sec)

Q3: 能否优化？慢在哪里？post_ddl 如何调用？

从 Q1 的结果中可以看出，执行的主要耗时在 row_drop_table_for_mysql、os_file_delete_func：

MySQL 8.0 的优化措施

row_drop_table_for_mysql 慢的问题，可以通过设置 innodb_adaptive_hash_index = off 进行优化；

os_file_delete_func 慢的问题，可以设置 innodb_flush_method = O_DIRECT 或者配置表的 HARD LINK 进行优化。

MySQL 5.7 的优化措施

详见后面 3-Q1、3-Q4 部分。

post_ddl 如何调用？

MySQL 8.0 引入了 scope guard^[1]功能：当定义了 scope guard 之后，会创建 Scope_guard 对象。正常情况下，当执行 return 操作前，会执行 scope guard 定义的逻辑。除非在函数结束前执行 Scope_guard 对象的 commit 操作，文件的删除功能是在 scope guard 的 cleanup_base 阶段调用实现的。

Q4: 生产执行 TRUNCATE 是否存在隐患？

从实现机制来看，主要有以下风险：

IO 压力

当触发 truncate 操作后，需要在短时间由数据库线程将文件 unlink 或 truncate，如果被处理的文件很大，服务器的 IO 压力可能会影响正常的数据库请求。

内存并发

在执行 truncate、drop 的过程中，由于需要对内存的数据进行清理，特别是对 LRU 和 flush_LRU 进行扫描，并释放对应的数据块。这个过程是需要逐个根据 buffer pool instance 获取 mutex 资源的。如果在业务高峰期，特别是 buffer pool 较大时，可能会影响正常的业务情况。

同时，执行 create drop table 操作时需要 dict_operation_lock 的 X 锁（RW_X_LATCH），而一些其他后台线程，比如 Main Thread 检查 dict cache 时，也需要获取 dict_operation_lock 的 X 锁，因此被阻塞。然后用户线程可能由于获取不到锁而处于挂起状态，当无法立刻获得锁时。更多参考：《Drop Table 对 MySQL 的性能影响分析》^[2]。

Q5: 不同版本对于 TRUNCATE 的实现是否存在差异？

通过对比 2-Q1 与 3-Q4:

MySQL 8.0的 truncate 实现方式基本和 drop 实现方式相同，包括主要的耗时位置（都在 row_drop_table_for_mysql、os_file_delete_func）都是相同的。

MySQL 5.7的 truncate 和 drop 实现差异较大，整个实现过程几乎是完全独立的代码。truncate 使用 row_truncate_table_for_mysql，drop 使用 row_drop_table_for_mysql；truncate 操作的主要的耗时有 dict_drop_index_tree、os_file_truncate。

2DROP TABLE 优化失败分析

下面来看一个 MySQL 5.7 测试环境上线 DROP TABLE 优化方案失败问题。

Q1：上线为什么会失败？HARD LINK 为什么不生效？AHI 为什么不生效?

当 MySQL 5.7 使用规范配置启动时，从 debug-trace 过程来看，在row_drop_single_table_tablespace、row_drop_table_from_cache 函数执行期间根本没有耗时，所以实施优化方案后，没有效果；

耗时的过程在 que_eval_sql: query: PROCEDURE DROP_TABLE_PROC ---> dict_drop_index_tree；

row_drop_single_table_tablespace 的耗时被 MySQL 5.7 配置innodb_flush_method=O_DIRECT 优化了。

Q2：该优化是否适用于 MySQL 8.0？

设置 innodb_flush_method=O_DIRECT 的优化操作，同样适用于 MySQL 8.0。

Q3：MySQL 8.0 如何解决 DROP TABLE 时执行 DROP_TABLE_PROC 慢的问题？

WL#9536: InnoDB_New_DD: Support crash-safe DDL；

依赖于自 Version 8.0.3 的 NEW DD；

整个 drop 慢的 que_eval_sql、DROP_TABLE_PROC 被整体砍掉；

包括 dict_drop_index_tree 在内的整个函数，都被砍了；

具体实现机制，参考分析 NEW DD 实现方法。

Q4：MySQL 5.7 DROP TABLE 和 TRUNCATE 在实现机制、优化措施有何区别呢？

执行 truncate 操作的耗时，仍然是在 dict_drop_index_tree、os_file_truncate 这两个阶段；

os_file_truncate 的耗时：可以通过设置 innodb_flush_method=O_DIRECT参数进行优化（不可以通过 hard link 进行优化）；

dict_drop_index_tree 的耗时，暂时没有优化思路。了解更多：InnoDB 文件系统之文件物理结构^[3]。

Q5：5.7 慢查询为什么有时记录 TRUNCATE 执行慢，有时不记录?

根据源码，MySQL 是否记录慢查询判断时，主要有两个维度：一个是执行时间（不包括 utime_alter_lock）；一个是执行扫描的行数，并对特殊的语句（如 call）进行了忽略。对于 truncate 操作而言，无论执行时间是多少，扫描行数都是 0。当配置了 min_examined_row_limit 大于 0 之后，一般 truncate 操作由于不满足该条件，都不会被记录到慢查询。

但是当 truncate 操作位于存储过程中时，在 truncate 操作之前有其它 DML 操作（如 insert select），这时候由于位于同一个 THD 下，在 MySQL 5.7 版本里面 thd->get_examined_row_count() 返回的结果其实是上一个 DML 语句的（这里应该是缺陷）。如果此时 truncate 操作的执行时间又超过了 long_query_time，那么此时这个 truncate 语句就会被记录慢查询。

同时，在 MySQL 8.0 针对 call 的语句，将不再单独记录 DML 的语句。而是记录为统一的 call 语句里面。需要看存储过程里面的语句执行情况，可以用 show profiles 查看。

慢查询记录堆栈

测试存储过程

DROPPROCEDUREtruncate_test;DELIMITER//CREATEPROCEDUREtruncate_test()BEGINinsertintot1select*fromt1_bak;truncatetablet1;END//DELIMITER;calltruncate_test();mysql>calltruncate_test();QueryOK,0rowsaffected(1min59.58sec)#Time:2023-06-08T00:28:30.969993+08:00#User@Host:root[root]@localhost[]Id:2#Schema:db2Last_errno:0Killed:0#Query_time:119.177518Lock_time:0.000233Rows_sent:0Rows_examined:131072Rows_affected:131072#Bytes_sent:0#Stored_routine:db2.truncate_testusedb2;SETtimestamp=1686155310;insertintot1select*fromt1_bak;#Time:2023-06-08T00:28:31.375873+08:00#User@Host:root[root]@localhost[]Id:2#Schema:db2Last_errno:0Killed:0#Query_time:0.405734Lock_time:0.003310Rows_sent:0Rows_examined:131072Rows_affected:0#Bytes_sent:0#Stored_routine:db2.truncate_testSETtimestamp=1686155311;truncatetablet1;

与 MySQL 8.0 对比

mysql>calltruncate_test();QueryOK,0rowsaffected(2min28.51sec)#Time:2023-06-07T17:18:39.215632Z#User@Host:root[root]@localhost[]Id:8#Query_time:148.516478Lock_time:0.000372Rows_sent:0Rows_examined:172032usetestdb;SETtimestamp=1686158318;calltruncate_test();

MySQL 8.0 如何跟踪？

mysql>calltruncate_test();QueryOK,0rowsaffected(2min24.84sec)mysql>mysql>mysql>showprofiles;+----------+--------------+-----------------------------------------+|Query_ID|Duration|Query|+----------+--------------+-----------------------------------------+|1|144.55113600|insertintoltb2select*fromltb3_bak||2|0.29312375|truncatetableltb2|+----------+--------------+-----------------------------------------+2rowsinset,1warning(0.00sec)

以上包括 truncate 执行慢的分析，如针对细节有任何疑问和建议，欢迎留言交流。

参考资料

[1]

跟着 MySQL 8.0 学 C++：scope_guard: https://www.bookstack.cn/read/aliyun-rds-core/20cbcfdcbd68888c.md

[2]

Drop Table 对 MySQL 的性能影响分析: https://www.cnblogs.com/CtripDBA/p/11465315.html

[3]

InnoDB 文件系统之文件物理结构: http://mysql.taobao.org/monthly/2016/02/01/

本文关键字：#MySQL##InnoDB# #truncate# #源码#

文章推荐：

技术分享 | ibdata1 “减肥” 记

技术分享 | DBA 抓包神器 tshark 测评

故障分析 | 一个因 SSL 配置导致的复制异常报错

源码分析 | MySQL 的 commit 是怎么 commit 的？

技术分享 | 一文了解 MySQL Optimizer Trace 的神奇功效

故障分析 | innodb_thread_concurrency 导致数据库异常的问题分析

故障分析 | MySQL 升级到 8.0 变慢问题分析

技术分享 | 一招解决 MySQL 中 DDL 被阻塞的问题

故障分析 | 一条本该记录到慢日志的 SQL 是如何被漏掉的

关于 SQLE

爱可生开源社区的 SQLE 是一款面向数据库使用者和管理者，支持多场景审核，支持标准化上线流程，原生支持 MySQL 审核且数据库类型可扩展的 SQL 审核工具。

SQLE 获取

类型地址

版本库	https://github.com/actiontech/sqle
文档	https://actiontech.github.io/sqle-docs/
发布信息	https://github.com/actiontech/sqle/releases
数据审核插件开发文档	https://actiontech.github.io/sqle-docs-cn/3.modules/3.7_auditplugin/auditplugin_development.html