源碼解析丨一次慢SQL排查

来源:https://www.cnblogs.com/greatsql/p/18088776
-Advertisement-
Play Games

當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 ...


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

您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • 概述:本指南詳細解釋了在C#中如何在創建控制項的線程以外的線程中訪問GUI。基礎功能使用`Control.Invoke`(WinForms)或`Dispatcher.Invoke`(WPF),高級功能則利用`SynchronizationContext`實現線程間通信,確保代碼清晰可讀。 在C#中,要 ...
  • 概述:.NET應用程式以管理員身份運行的方法包括修改清單文件、項目文件,或在運行時動態請求管理員許可權。清單文件和項目文件通過聲明UAC請求,而動態請求管理員許可權則在程式啟動時檢查並重新啟動。選擇適當的方法取決於項目需求和配置。 在.NET應用程式中強制以管理員身份運行,可以通過清單文件、項目文件或者 ...
  • Nginx的location匹配順序是Nginx配置中非常核心且重要的概念,它決定了Nginx如何處理進入伺服器的請求。理解location匹配順序不僅有助於優化Nginx的性能,還能確保網站或應用的正確運行。下麵將詳細闡述Nginx的location匹配順序,並通過實例加以說明。 Nginx lo ...
  • 來自chatGPT 在CentOS 7.9系統上安裝Docker,你可以遵循以下步驟: 更新你的系統:首先,確保你的系統是最新的。這可以通過運行下麵的命令來實現: sudo yum update 安裝必要的包:為了使得yum源支持https,你需要安裝幾個必要的包: sudo yum install ...
  • 哈嘍大家好,我是鹹魚。 今天分享一個在壓測過程中遇到的問題,當時排查這個問題費了我們好大的勁,所以我覺得有必要寫一篇文章來記錄一下。 問題出現 周末在進行壓測的時候,測試和開發的同事反映壓測有問題,請求打到 A 服務上被拒絕了。 我們登錄伺服器查看 A 服務的日誌,發現頻繁地報 Too many o ...
  • 本文主要學習 FreeRTOS 低功耗的相關知識,包括HAL 庫基礎時鐘、FreeRTOS 基礎時鐘、低功耗處理和 Tickless 模式等知識 ...
  • 背景 近年來隨著國際形勢的變化,信創產業成為我國國家戰略的一部分。一直以來,一直以來,全球 ICT 產業底層標準、架構、產品、生態等要素均由國外公司或機構制定和控制,使我國 ICT 產業乃至廣大用戶面臨被卡脖子、數據泄露、信息安全等諸多風險,尤其是 2018年以來,中興、華為等公司的遭遇成為鮮活的實 ...
  • OGG部署時,抽取進程(Extract)註冊到資料庫時遇到下麵錯誤: REGISTER EXTRACT ***** DATABASE ERROR OGG-08221 Cannot register or unregister EXTRACT because of the following SQL ...
一周排行
    -Advertisement-
    Play Games
  • C#.Net的BCL提供了豐富的類型,最基礎的是值類型、引用類型,而他們的共同(隱私)祖先是 System.Object(萬物之源),所以任何類型都可以轉換為Object。 ...
  • 最近有群友咨詢C#如何調用Python?小編嘗試Python.NET過程中遭遇的版本相容性和環境配置難題,小編決定尋找一個更為簡單、穩定且對初學者友好的解決方案。小編搜索一番,除了Python.NET之外,還有其他途徑能夠幫助我們輕鬆地在C#項目調用Python腳本,那就是通過命令行調用,使用 Sy ...
  • .NET中特性+反射 實現數據校驗 在.NET中,我們可以使用特性+反射來實現數據校驗。特性是一種用於為程式中的代碼添加元數據的機制。元數據是與程式中的代碼相關聯的數據,但不直接成為代碼的一部分。通過特性,我們可以為類、方法、屬性等添加額外的信息,這些信息可以在運行時通過反射獲取和使用。 對反射不太 ...
  • Biwen.Settings 是一個簡易的配置項管理模塊,主要的作用就是可以校驗並持久化配置項,比如將自己的配置存儲到資料庫中,JSON文件中等 使用上也是很簡單,只需要在服務中註入配置, 比如我們有一個GithubSetting的配置項,我們只需要定義好對象然後註入到Service中即可: [De ...
  • EDP是一套集組織架構,許可權框架【功能許可權,操作許可權,數據訪問許可權,WebApi許可權】,自動化日誌,動態Interface,WebApi管理等基礎功能於一體的,基於.net的企業應用開發框架。通過友好的編碼方式實現數據行、列許可權的管控。 ...
  • 前言 VB.NET,全名Visual Basic .NET,是Microsoft .NET框架的一部分,是一種面向對象的編程語言。它繼承了Visual Basic的易用性,同時增加了對面向對象編程的支持。VB.NET提供了大量的內置函數,使得開發者可以更容易地處理字元串、數學計算、文件和目錄訪問等任 ...
  • 自定義可移動點二維坐標軸控制項 目錄 路由參數 坐標軸控制項定義 Demo 路由參數 X_YResultCollection為當前X軸對應Y軸值存儲字典 public class ResultCollectionChangedEventArgs(RoutedEvent routedEvent, obje ...
  • 自定義分頁控制項 tip: 該控制項的樣式用的是materialDesign庫,需要下載Nuget包 Code Xaml <UserControl x:Class="TestTool.CustomControls.PagingControl" xmlns="http://schemas.microsof ...
  • 最近群里有個小伙伴把Dapper遷移SqlSugar幾個不能解決的問題進行一個彙總,我正好寫一篇文章來講解一下 一、sql where in傳參問題: SELECT * FROM users where id IN @ids 答: SqlSugar中應該是 var sql="SELECT * FRO ...
  • 安裝nuget包 Wesky.Net.OpenTools 1.0.8或以上版本。支持.net framework 4.6以上版本,以及所有.net core以及以上版本引用。 開發一個簡單的Winform界面,用來測試使用。如需該winform的demo,可以在公眾號【Dotnet Dancer】後 ...