源码解析丨一次慢SQL排查-低调大师

源码解析丨一次慢SQL排查

2024-03-22 324

当long_query_time=1时（表info的id为主键），出现下面的慢日志，可能会让你吃惊

# Time: 2024-01-28T22:52:24.500491+08:00
# User@Host: root[root] @  [127.0.0.1]  Id:     8
# Query_time: 7.760787  Lock_time: 7.757456 Rows_sent: 0  Rows_examined: 0
use apple;
SET timestamp=1706453536;
delete from info where id < 10;

环境信息

配置	参数
ip	172.17.137.12
hostname	dev
memory	16G
cpu	8C
MySQL version	GreatSQL 8.0.26

慢查询相关参数

greatsql> select * from performance_schema.global_variables where variable_name in('slow_query_log','log_output','slow_query_log_file','long_query_time','log_queries_not_using_indexes','log_slow_admin_statements','min_examined_row_limit','log_throttle_queries_not_using_indexes') order by variable_name;
+----------------------------------------+-------------------------------------+
| VARIABLE_NAME                          | VARIABLE_VALUE                      |
+----------------------------------------+-------------------------------------+
| log_output                             | FILE                                |
| log_queries_not_using_indexes          | OFF                                 |
| log_slow_admin_statements              | OFF                                 |
| log_throttle_queries_not_using_indexes | 0                                   |
| long_query_time                        | 1.000000                            |
| min_examined_row_limit                 | 0                                   |
| slow_query_log                         | ON                                  |
| slow_query_log_file                    | /root/local/8026/log/slow.log       |
+----------------------------------------+-------------------------------------+
8 rows in set (10.49 sec)

slow_query_log：慢日志开关
log_output：慢日志存储方式，FILE或TABLE
long_query_time：慢日志阈值
min_examined_row_limit：设置慢SQL的最小examined扫描行数，建议设置为0，因为有bug：https://bugs.mysql.com/bug.php?id=110804
log_queries_not_using_indexes：不使用索引的慢查询日志是否记录到索引
log_slow_admin_statements：在写入慢速查询日志的语句中包含慢速管理语句（create index,drop index,alter table,analyze table,check table,optimize table,repair table）默认是不会记录的
log_throttle_queries_not_using_indexes：用于限制每分钟输出未使用索引的日志数量。每分钟允许记录到slow log的且未使用索引的sql语句次数，配合long_queries_not_using_indexes开启使用。
log_slow_slave_statements：默认OFF，是否开启主从复制中从库的慢查询

根本原因

一、慢日志写入大致流程

dispatch_command(thd)
- thd->enable_slow_log = true // 初始化enable_slow_log为true
- thd->set_time // 设置开始时间
- dispatch_sql_command
- parse_sql // 语法解析
- mysql_execute_command // 执行SQL
  - lex->m_sql_cmd->execute // 常见的CRUD操作
- thd->update_slow_query_status // 判断是否达到慢日志阈值。若为慢查询，则更新thd的server_status状态，为写slow_log作准备
- log_slow_statement
- log_slow_applicable // 判断是否写入慢日志
  - log_slow_do // 开始写入
    - slow_log_write
      - log_slow
      - write_slow

二、判断是否达到慢日志阈值

8.0.26版本的慢日志判断标准

void THD::update_slow_query_status() {
  if (my_micro_time() > utime_after_lock + variables.long_query_time)
    server_status | = SERVER_QUERY_WAS_SLOW;
}
// my_micro_time() 获取当前系统时间点，单位为微妙
// utime_after_lock 为MDL LOCK和row lock等待时间后的时间点，单位为微妙
// variables.long_query_time 慢日志阈值long_query_time * 1000000 ，单位为微妙
// 等价于：my_micro_time() - utime_after_lock  > variables.long_query_time
// 不包含锁等待时间

8.0.32版本的慢日志判断标准（8.0.28开始）

void THD::update_slow_query_status() {
  if (my_micro_time() > start_utime + variables.long_query_time)
    server_status | = SERVER_QUERY_WAS_SLOW;
}
// 判别标准变成了：（语句执行结束的时间 - 语句开始执行时间） > 慢日志阈值
// my_micro_time() 当前系统时间点，单位为微妙
// start_utime：语句开始执行时间点，单位为微妙
// variables.long_query_time 慢日志阈值long_query_time * 1000000 ，单位为微妙
// 包含锁等待时间

从上面可以看出慢日志的判断标准发生了根本变化

举例说明

greatsql> select * from info;
+----+------+
| id | name |
+----+------+
|  1 |    1 |
|  2 |    2 |
|  5 |    5 |
| 60 |    8 |
| 40 |   11 |
| 20 |   20 |
| 30 |   30 |
+----+------+
7 rows in set (0.05 sec)

greatsql> show create table info\G
*************************** 1. row ***************************
       Table: info
Create Table: CREATE TABLE `info` (
  `id` int NOT NULL AUTO_INCREMENT,
  `name` int NOT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `uk_name` (`name`)
) ENGINE=InnoDB AUTO_INCREMENT=61 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.02 sec)

session1	session2
begin;
delete from info where id < 10;
	`delete from info where id < 10;`
session1等待一段时间超过慢日志阈值long_query_time
rollback；

• 在8.0.26版本中，是不会记录session2中的delete from info where id < 10

• 在8.0.32版本中，会记录session2中的delete from info where id < 10

三、判断是否写入慢日志

void log_slow_statement(THD *thd,
                        struct System_status_var *query_start_status) {
  if (log_slow_applicable(thd)) log_slow_do(thd, query_start_status);
}


//----------------------------------------------------------------

bool log_slow_applicable(THD *thd) {
  DBUG_TRACE;

  /*
    The following should never be true with our current code base,
    but better to keep this here so we don't accidently try to log a
    statement in a trigger or stored function
  */
  if (unlikely(thd->in_sub_stmt)) return false;  // Don't set time for sub stmt

  if (unlikely(thd->killed == THD::KILL_CONNECTION)) return false;

  /*
    Do not log administrative statements unless the appropriate option is
    set.
  */
  if (thd->enable_slow_log && opt_slow_log) {
    bool warn_no_index =
        ((thd->server_status &
          (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
         opt_log_queries_not_using_indexes &&
         !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND));
    bool log_this_query =
        ((thd->server_status & SERVER_QUERY_WAS_SLOW) || warn_no_index) &&
        (thd->get_examined_row_count() >=
         thd->variables.min_examined_row_limit);
    bool suppress_logging = log_throttle_qni.log(thd, warn_no_index);

    if (!suppress_logging && log_this_query) return true;
  }
  return false;
}

若log_slow_applicable(thd)返回值为true，则执行log_slow_do(thd, query_start_status)，写入慢日志
if (unlikely(thd->in_sub_stmt)) return false;if (unlikely(thd->killed == THD::KILL_CONNECTION)) return false;

a. 子查询，返回false

b. 被kill，返回false

c. 解析出错，返回false

d. 执行出错，返回false

warn_no_index 表示log_queries_not_using_indexes开启且（未使用索引或未使用最优索引）
- thd->server_status 该线程状态
- SERVER_QUERY_NO_INDEX_USED 表示未使用索引
- SERVER_QUERY_NO_GOOD_INDEX_USED 表示未使用最优索引
- opt_log_queries_not_using_indexes 表示log_queries_not_using_indexes参数的值，默认OFF
!(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))表示该语句不是SHOW相关的命令。CF_STATUS_COMMAND常量表示执行的命令为show相关的命令。
log_this_query = ((thd->server_status & SERVER_QUERY_WAS_SLOW) || warn_no_index) && (thd->get_examined_row_count() >=thd->variables.min_examined_row_limit);
- (thd->server_status & SERVER_QUERY_WAS_SLOW) 表示该SQL为慢查询
- (thd->get_examined_row_count() >=thd->variables.min_examined_row_limit) 表示SQL的扫描数据行数不小于参数min_examined_row_limit 的值，默认为0
log_throttle_qni.log(thd, warn_no_index) 表示用来计算该条未使用索引的SQL是否需要写入到slow log，计算需要使用到参数log_throttle_queries_not_using_indexes , 该参数表明允许每分钟写入到slow log中的未使用索引的SQL的数量，默认值为0，表示不限制

按照线上配置

log_throttle_queries_not_using_indexes = 0
log_queries_not_using_indexes = OFF
log_slow_admin_statements = OFF
min_examined_row_limit = 0
slow_query_log = ON
long_query_time = 1.000000

那么在GreatSQL-8.0.26中，是否写入到慢日志中，取决于thd->server_status & SERVER_QUERY_WAS_SLOW，即SQL执行总耗时-SQL锁等待耗时>1秒

那么在GreatSQL-8.0.32中，是否写入到慢日志中，取决于thd->server_status & SERVER_QUERY_WAS_SLOW，即SQL执行总耗时>1秒

Enjoy GreatSQL :)

关于 GreatSQL

GreatSQL是适用于金融级应用的国内自主开源数据库，具备高性能、高可靠、高易用性、高安全等多个核心特性，可以作为MySQL或Percona Server的可选替换，用于线上生产环境，且完全免费并兼容MySQL或Percona Server。

相关链接： GreatSQL社区 Gitee GitHub Bilibili

GreatSQL社区：

社区有奖建议反馈： https://greatsql.cn/thread-54-1-1.html

社区博客有奖征稿详情： https://greatsql.cn/thread-100-1-1.html

（对文章有疑问或者有独到见解都可以去社区官网提出或分享哦~）

技术交流群：

微信&QQ群：

QQ群：533341697

微信群：添加GreatSQL社区助手（微信号：wanlidbc ）好友，待社区助手拉您进群。

微信关注我们

原文链接：https://my.oschina.net/GreatSQL/blog/11048534

转载内容版权归作者及来源网站所有！

低调大师中文资讯倾力打造互联网数据资讯、行业资源、电子商务、移动互联网、网络营销平台。持续更新报道IT业界、互联网、市场资讯、驱动更新,是最及时权威的产业资讯及硬件资讯报道平台。

openGauss 5.0.0全密态数据库应用小试

前言 openGaussHCIA教材中，安全是一个重要的章节，在实际项目中，随着网络安全和信息安全形势的变化，企业也越来越重视数据库安全。去年在HALP内部进行openGauss培训时，安全特性就被学员们提出来要重点讲解，而全密态等值查询则又是其中重要的一环。根据官网介绍，实际上openGauss在早期的1.0.0版本就引入了全密态等值查询特性，因此下面结合操作举例，尝试对openGauss 5.0.0版本全密态的使用进行介绍，供有需要的同行参考，不当之处并请提出宝贵意见和建议。一、教材中关于全密态的内容：（教材内容和官网基本一致）全密态数据库关于全密态数据库，官网上的介绍如下：密态数据库意在解决数据全生命周期的隐私保护问题，使得系统无论在何种业务场景和环境下，数据在传输、运算以及存储的各个环节始终都处于密文状态。当数据拥有者在客户端完成数据加密并发送给服务端后，在攻击者借助系统脆弱点窃取用户数据的状态下仍然无法获得有效的价值信息，从而起到保护数据隐私的作用。参见官网：https://docs.opengauss.org/zh/docs/5.0.0/docs/Aboutop...

2024-03-22

281

随着版本迭代，Apache Doris 一直在拓展应用场景边界，从典型的实时报表、交互式 Ad-hoc 分析等 OLAP 场景到湖仓一体、高并发数据服务、日志检索分析及批量数据处理，越来越多用户与企业开始将 Apache Doris 作为统一的数据分析产品，以解决多组件带来的数据冗余、架构复杂、分析时效性低、运维难度大等问题。然而在架构统一和升级的过程中，由于部分大数据分析系统有自己的 SQL 方言、需要对 SQL 语法进行一定程度的修改，另外由于大量原有系统的 SQL 与业务逻辑相关联，需要进行大量业务逻辑的改造，这不可避免地增加了额外迁移成本。为了帮助企业有效应对这些挑战，Apache Doris 2.1 版本提供了 SQL 方言兼容与转换方案—— Doris SQL Convertor，兼容了包括 Presto、Trino、Hive、ClickHouse、PostgreSQL 等在内多种 SQL 语法。用户可以在 Doris 中直接使用相应系统的 SQL 语法执行查询，也可以在可视化界面对原有的 SQL 语句进行批量转换。通过 Doris SQL Convertor，能够有...

2024-03-22

348

资源下载

更多资源

优质分享App

近一个月的开发和优化，本站点的第一个app全新上线。该app采用极致压缩，本体才4.36MB。系统里面做了大量数据访问、缓存优化。方便用户在手机上查看文章。后续会推出HarmonyOS的适配版本。

Mario

马里奥是站在游戏界顶峰的超人气多面角色。马里奥靠吃蘑菇成长，特征是大鼻子、头戴帽子、身穿背带裤，还留着胡子。与他的双胞胎兄弟路易基一起，长年担任任天堂的招牌角色。

Spring

Spring框架（Spring Framework）是由Rod Johnson于2002年提出的开源Java企业级应用框架，旨在通过使用JavaBean替代传统EJB实现方式降低企业级编程开发的复杂性。该框架基于简单性、可测试性和松耦合性设计理念，提供核心容器、应用上下文、数据访问集成等模块，支持整合Hibernate、Struts等第三方框架，其适用范围不仅限于服务器端开发，绝大多数Java应用均可从中受益。

Sublime Text

Sublime Text具有漂亮的用户界面和强大的功能，例如代码缩略图，Python的插件，代码段等。还可自定义键绑定，菜单和工具栏。Sublime Text 的主要功能包括：拼写检查，书签，完整的 Python API ， Goto 功能，即时项目切换，多选择，多窗口等等。Sublime Text 是一个跨平台的编辑器，同时支持Windows、Linux、Mac OS X等操作系统。