如何使用 MySQL 慢查詢日誌進行效能優化 - Profiling、mysqldumpslow 例項詳解

HiJiangChuan發表於2021-11-17

使用 MySQL 慢查詢日誌進行效能優化

當我們開始關注資料庫整體效能優化時,我們需要一套 MySQL 查詢分析工具。特別是在開發中大型專案時,往往有數百個查詢分佈在程式碼庫中的各個角落,並實時對資料庫進行大量訪問和查詢。如果沒有一套趁手的分析方法和工具,就很難發現在執行過程中程式碼的效率瓶頸,我們需要通過這套工具去定位 SQL 語句在執行中緩慢的問題和原因。

本教程帶領大家學習和實踐 MySQL Server 內建的查詢分析工具 —— 慢查詢日誌、mysqldumpslowProfiling,詳細講解如何使用他們提升程式碼執行效率。如果你想根據自己的工作流開發一套資料庫查詢管理工具,推薦使用卡拉雲。只要你會寫 SQL,無需會前端也可以輕鬆搭建屬於自己的後臺查詢工具,詳見本文文末。

一. 有關 MySQL 慢查詢日誌

1.慢查詢日誌是什麼?

MySQL 慢查詢日誌是用來記錄 MySQL 在執行命令中,響應時間超過預設閾值的 SQL 語句。

記錄這些執行緩慢的 SQL 語句是優化 MySQL 資料庫效率的第一步。

預設情況下,慢查詢日誌功能是關閉的,需要我們手動開啟。當然,如果不是調優需求的話,一般也不建議長期啟動這個功能,因為開啟慢查詢多少會對資料庫的效能帶來一些影響。慢查詢日誌支援將記錄寫入檔案,當然也可以直接寫入資料庫的表中。

2.配置並開啟慢查詢日誌

(1)在 MySQL Server 中臨時開啟慢查詢功能

在 MySQL Server 中,預設情況慢查詢功能是關閉的,我們可以通過檢視此功能的狀態

show variables like 'slow_query_log'; 

slow_query_log

如上圖所示,慢查詢日誌(slow_query_log )的狀態為關閉。

我們可以使用以下命令開啟並配置慢查詢日誌功能,在 mysql 中執行以下命令

SET GLOBAL slow_query_log = 'ON';
SET GLOBAL slow_query_log_file = '/var/log/mysql/kalacloud-slow.log';
SET GLOBAL log_queries_not_using_indexes = 'ON';
SET SESSION long_query_time = 1;
SET SESSION min_examined_row_limit = 100;

SET GLOBAL slow_query_log :全域性開啟慢查詢功能。

SET GLOBAL slow_query_log_file :指定慢查詢日誌儲存檔案的地址和檔名。

SET GLOBAL log_queries_not_using_indexes:無論是否超時,未被索引的記錄也會記錄下來。

SET SESSION long_query_time:慢查詢閾值(秒),SQL 執行超過這個閾值將被記錄在日誌中。

SET SESSION min_examined_row_limit:慢查詢僅記錄掃描行數大於此引數的 SQL。

特別注意:在實踐中常常會碰到無論慢查詢閾值調到多小,日誌就是不被記錄。這個問題很有可能是 min_examined_row_limit 行數過大,導致沒有被記錄。min_examined_row_limit 在配置中常被忽略,這裡要特別注意。

接著我們來執行查詢語句,看看配置。(在 MySQL Server 中執行)

show variables like 'slow_query_log%';
show variables like 'log_queries_not_using_indexes';
show variables like 'long_query_time';
show variables like 'min_examined_row_limit';

show-variables-like

以上修改 MySQL 慢查詢配置的方法是用在臨時監測資料庫執行狀態的場景下,當 MySQL Server 重啟時,以上修改全部失效並恢復原狀。

擴充套件閱讀:六類 MySQL 觸發器使用教程及應用場景實戰案例

(2)將慢查詢設定寫入 MySQL 配置檔案,永久生效

雖然我們可以在命令列中對慢查詢進行動態設定,但動態設定會隨著重啟服務而失效。如果想長期開啟慢查詢功能,需要把慢查詢的設定寫入 MySQL 配置檔案中,這樣無論是重啟伺服器,還是重啟 MySQL ,慢查詢的設定都會保持不變。

MySQL conf 配置檔案通常在 /etc/usr 中。我們可以使用 find 命令找到配置檔案具體的存放位置。

sudo find /etc -name my.cnf

sudo-find

找到位置後,使用 nano 編輯 my.cnf 將慢查詢設定寫入配置檔案。

sudo nano /etc/mysql/my.cnf
[mysqld]

slow-query-log = 1
slow-query-log-file = /var/log/mysql/localhost-slow.log
long_query_time = 1
log-queries-not-using-indexes

使用 nano 開啟配置檔案,把上面的的程式碼寫在 [mysqld] 的下面即可。 ctrl+X 儲存退出。

sudo systemctl restart mysql

重啟 MySQL Server 服務,使剛剛修改的配置檔案生效。

特別注意:直接在命令列中設定的慢查詢動態變數與直接寫入 my.cnf 配置檔案的語法有所不同。

擴充套件閱讀:10種 MySQL 管理工具 橫向測評 - 免費和付費到底怎麼選?

舉例:動態變數是slow_query_log,寫入配置檔案是slow-query-log。這裡要特別注意。

更多 MySQL 8.0 動態變數語法可檢視 MySQL 官方文件

二. 使用慢查詢功能記錄日誌

到這裡我們已經配置好慢查詢功能所需要的一切。下面我們們寫一個示例,在這個示例中我們來一起學習如何檢視和分析慢查詢日誌。

你可以開啟兩個連線到伺服器的命令列視窗,一個用來寫 MySQL 程式碼,另一個用來檢視日誌。

注意:以下教程中,有些程式碼是在命令列中執行,有些是在 MySQL Server 中執行,請注意分辨。

登入 MySQL Server,建立一個資料庫,寫入一組示例資料。

CREATE DATABASE kalacloud_demo;
USE kalacloud_demo;
CREATE TABLE users ( id TINYINT PRIMARY KEY AUTO_INCREMENT, name VARCHAR(255) );
INSERT INTO users (name) VALUES ('Jack Ma'),('Lei Jun'),('Wang Xing'),('Pony Ma'),('Zhang YiMing'),('Ding Lei'),('Robin Li'),('Xu Yong'),('Huang Zheng'),('Richard Liu');

為了保證大家與教程配置保持一致,我們們一起使用動態變數,再設定一邊慢查詢引數。

在 MySQL Server 中執行以下 SQL 程式碼:

SET GLOBAL slow_query_log = 1;
SET GLOBAL slow_query_log_file = '/var/log/mysql/kalacloud-slow.log';
SET GLOBAL log_queries_not_using_indexes = 1;
SET long_query_time = 10;
SET min_examined_row_limit = 0;

現在我們有了一個表中有資料的示例資料庫。慢查詢功能也已經開啟,我們特意把時間閾值(long_query_time)設定為 10 並且把最小行(min_examined_row_limit)設定為 0。

接著我們來執行一段程式碼測試一下:

USE kalacloud_demo;
SELECT * FROM users WHERE id = 1;

使用主鍵索引對錶進行 select 查詢,這種查詢速度非常快,又使用了索引。因此慢查詢日誌中不會有任何記錄。

我們開啟慢查詢日誌,驗證一下是否有記錄,在命令列中執行以下命令:

sudo cat /var/log/mysql/kalacloud-slow.log

可以看到kalacloud-slow.log還沒有任何記錄。
kalacloud-slow-log

接著我們在 MySQL Server 中執行以下程式碼:

SELECT * FROM users WHERE name = 'Wang Xing';

這段查詢程式碼使用非索引列(name)來進行查詢,所以慢查詢日誌在會記錄下這個查詢。

我們開啟日誌檢視記錄變化:

sudo cat /var/log/mysql/kalacloud-slow.log

通過 cat 檢視 log

我們可以看到這個非索引查詢,已經被記錄在慢查詢日誌中了。

再舉個例子。我們提高最小檢查行(min_examined_row_limit)的檢查行數設定為 100,然後再執行查詢。

在 MySQL Server 中執行以下程式碼:

SET min_examined_row_limit = 100;
SELECT * FROM users WHERE name = 'Zhang YiMing';

執行後,再開啟 kalacloud-slow.log ,可以看到條小於 100 行的查詢,沒有被記錄到日誌中。

特別注意:如果慢查詢日誌中,沒有記錄任何資料,可以檢查以下內容。

(1)建立日誌的目錄許可權問題,是否有對應的許可權。

cd /var/log
mkdir mysql
chmod 755 mysql
chown mysql:mysql mysql

(2)另一個可能是查詢變數配置問題,把 my.conf 檔案內有關慢查詢的配置清乾淨,然後重啟服務,重新配置。看看是不是這裡出的問題。

擴充套件閱讀:如何將 MySQL 的查詢結果儲存到檔案

三. 慢查詢日誌記錄引數詳解

接著我們來講解慢查詢日誌應該如何分析

慢查詢日誌分析

日誌中資訊的說明:

  • Time :被日誌記錄的程式碼在伺服器上的執行時間。
  • User@Host:誰執行的這段程式碼。
  • Query_time:這段程式碼執行時長。
  • Lock_time:執行這段程式碼時,鎖定了多久。
  • Rows_sent:慢查詢返回的記錄。
  • Rows_examined:慢查詢掃描過的行數。

這些被記錄的資訊非常有意義,所有超過閾值的程式碼都會被記錄在日誌中,我們可以通過這些資訊找到 MySQL 查詢時效率不佳的程式碼,有助於我們優化 MySQL 效能。

擴充套件閱讀:如何在 MySQL 裡查詢資料庫中帶有某個欄位的所有表名

四. 使用 mysqldumpslow 工具對慢查詢日誌進行分析

實際工作中,慢查詢日誌可不像上文描述的那樣,僅僅有幾行記錄。現實中慢查詢日誌會記錄大量慢查詢資訊,寫入也非常頻繁。日誌記錄的內容會越來越長,分析資料也變的困難。 好在 MySQL 內建了 mysqldumpslow 工具,它可以把相同的 SQL 歸為一類,並統計出歸類項的執行次數和每次執行的耗時等一系列對應的情況。

我們先來執行幾行程式碼讓慢查詢日誌記錄下來,然後再用 mysqldumpslow 進行分析。

上文我們把min_examined_row_limit 設定為 100,在這裡,我們要將它改為 0 ,慢查詢才能有記錄。在 MySQL Server 中執行以下程式碼:

SET min_examined_row_limit = 0;

接著我們執行幾條查詢命令:

SELECT * FROM users WHERE name = 'Wang Xing';
SELECT * FROM users WHERE name = 'Huang Zheng';
SELECT * FROM users WHERE name = 'Zhang YiMing';

根據前文的慢查詢設定,這三條記錄都將被記錄在日誌中。

現在,我們切換到命令列的視窗中,執行 mysqldumpslow 命令:

sudo mysqldumpslow -s at /var/log/mysql/kalacloud-slow.log

返回的資料:

mysqldumpslow

我們可以看到,返回的資料中,已經把三條類似的 SQL 語句記錄抽象成一條記錄SELECT * FROM users WHERE name = 'S' 並且針對這條記錄列出了對應的總量和平均量的記錄。

常見的 mysqldumpslow 命令 平時大家也可以根據自己的常用需求來總結,存好這些指令碼備用。

  • mysqldumpslow -s at -t 10 kalacloud-slow.log:平均執行時長最長的前 10 條 SQL 程式碼。
  • mysqldumpslow -s al -t 10 kalacloud-slow.log:平均鎖定時間最長的前10條 SQL 程式碼。
  • mysqldumpslow -s c -t 10 kalacloud-slow.log:執行次數最多的前10條 SQL 程式碼。
  • mysqldumpslow -a -g 'user' kalacloud-slow.log:顯示所有 user 表相關的 SQL 程式碼的具體值
  • mysqldumpslow -a kalacloud-slow.log:直接顯示 SQL 程式碼的情況。

mysqldumpslow 的引數命令

Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

Parse and summarize the MySQL slow query log. Options are

  --verbose    verbose
  --debug      debug
  --help       write this text to standard output
  -v           verbose
  -d           debug
  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default
                al: average lock time
                ar: average rows sent
                at: average query time
                 c: count
                 l: lock time
                 r: rows sent
                 t: query time
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the top n queries
  -a           don't abstract all numbers to N and strings to 'S'
  -n NUM       abstract numbers with at least n digits within names
  -g PATTERN   grep: only consider stmts that include this string
  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),
               default is '*', i.e. match all
  -i NAME      name of server instance (if using mysql.server startup script)
  -l           don't subtract lock time from total time

常用的引數講解:

-s

  • al:平均鎖定時間
  • at:平均查詢時間 [預設]
  • ar:平均返回記錄時間
  • c:count 總執行次數
  • l:鎖定時間
  • r:返回記錄
  • t:查詢時間

-t:返回前 N 條的資料

-g:可寫正則表達,類似於 grep 命令,過濾出需要的資訊。如,只查詢 X 表的慢查詢記錄。

-r:rows sent 總返回行數。

mysqldumpslow 日誌查詢工具好用就好用在它特別靈活,又可以合併同類項式的分析慢查詢日誌。我們在日常工作的使用中,就能夠體會 mysqldumpslow 的好用之處。

另外 mysqldumpslow 的使用引數也可在 MySQL 8.0 使用手冊 中找到。

擴充套件閱讀:如何檢視 MySQL 資料庫、表、索引容量大小?找到佔用空間最大的表

五. Profilling - MySQL 效能分析工具

為了更精準的定位一條 SQL 語句的效能問題,我們需要拆分這條語句執行時到底在什麼地方消耗了多少資源。 我們可以使用 Profilling 工具來進行這類細緻的分析。我們可通過 Profilling 工具獲取一條 SQL 語句在執行過程中對各種資源消耗的細節。

進入 MySQL Server 後,執行以下程式碼,啟動 Profilling

SET SESSION profiling = 1; 

檢查 profiling 的狀態

SELECT @@profiling;

返回資料: 0 表示未開啟,1 表示已開啟。
profiling

執行需要定位問題的 SQL 語句。

USE kalacloud_demo;
SELECT * FROM users WHERE name = 'Jack Ma';

檢視 SQL 語句狀態。

SHOW PROFILES;

開啟 profiling 後,SHOW PROFILES; 會顯示一個將 Query_ID 連結到 SQL 語句的表。

show-profiles
Query_ID:SQL 語句的 ID 編號。
Duration:SQL 語句執行時長。
Query:具體的 SQL 語句。

執行以下 SQL 程式碼,將 [# Query_ID] 替換為我們要分析的 SQL 程式碼Query_ID的編號。

SHOW PROFILE CPU, BLOCK IO FOR QUERY [# Query_ID];

SHOW PROFILE CPU, BLOCK IO FOR QUERY 4;

show-profiles-all

Status 是執行查詢過程中的具體步驟,Duration 是完成該步驟所需的時間(以秒為單位)。

我們可以根據這些細節來具體分析,如何優化對應的 SQL 程式碼。

六. 慢查詢教程總結

慢查詢是讓我們看到資料庫真實執行狀態的工具,對伺服器和資料庫效能優化有著指導性的意義。無論是生產環境、開發、QA,都可以謹慎的開啟慢查詢來記錄效能日誌。

我們可以先把動態變數long_query_time 設定的大一些,觀察一下,然後在進行微調。有了慢查詢日誌,我們就有了優化效能的方向和目標,再使用 mysqldumpslowprofiling 進行巨集觀和微觀的日誌分析。找到低效 SQL 語句的細節,進行微調,最終使我們的系統可以獲得最佳執行效能。

至此,MySQL 慢查詢日誌我們就講解完了,如果你週期性的檢視 log 日誌,可以使用卡拉雲搭一個日誌看板,自己不僅檢視、分析資料方便,還可以一鍵分享給組內的小夥伴共享資料。

卡拉雲是新一代低程式碼開發工具,免安裝部署,可一鍵接入包括 MySQL 在內的常見資料庫及 API。不僅可以像命令列一樣靈活,還可根據自己的工作流,定製開發。無需繁瑣的前端開發,只需要簡單拖拽,即可快速搭建企業內部工具。數月的開發工作量,使用卡拉雲後可縮減至數天,歡迎免費試用卡拉雲

卡拉雲可快速接入的常見資料庫及 API

卡拉雲可快速接入的常見資料庫及 API

卡拉雲可根據公司工作流需求,輕鬆搭建資料看板,並且可分享給組內的小夥伴共享資料

快速搭建企業內部工具

僅需拖拽一鍵生成前端程式碼,簡單一行程式碼即可對映資料到指定元件中。

卡拉雲搭建資料庫看板

卡拉雲可直接新增匯出按鈕,匯出適用於各類分析軟體的資料格式,方便快捷。立即開通卡拉雲,匯入匯出你的資料

有關 MySQL 教程,可繼續擴充學習:

本作品採用《CC 協議》,轉載必須註明作者和本文連結

相關文章