化實戰(zhàn))
1. 慢查詢到底是什么為什么你必須關注它第一次接手線上MySQL數據庫的時候我最頭疼的事不是別人問MySQL怎么安裝而是深更半夜收到一條警報CPU飆升、接口超時、用戶開始罵人。翻遍代碼找不到問題最后打開慢查詢日志一眼就看見那條該死的SQL——三張表join一張表幾百萬行數據連索引都沒有一次查詢跑了幾十秒。從那以后我就養(yǎng)成了一個習慣接手任何數據庫第一件事就是確認慢查詢日志有沒有開沒開就先開上再談別的。很多人覺得慢查詢日志是事后諸葛亮出了問題才去翻。這個想法大錯特錯。慢查詢日志的價值恰恰在于提前發(fā)現(xiàn)——它不是在你已經故障的時候才出現(xiàn)而是每天都把那些執(zhí)行時間超標的SQL悄悄記下來等你有空的時候去翻一翻就能提前發(fā)現(xiàn)那些現(xiàn)在還不致命、但數據量一漲就會爆炸的隱患。我見過太多案例一個小查詢在十萬行數據時跑50毫秒沒人管等數據漲到一千萬行的時候變成5秒直接拖垮整個業(yè)務。慢查詢日志的意義就是讓你在50毫秒的時候就注意到它而不是等到5秒才被迫處理。那到底什么叫慢查詢MySQL的定義很簡單凡是執(zhí)行時間超過long_query_time閾值的SQL語句都會被記錄到慢查詢日志里。默認情況下這個閾值是10秒但說實話10秒這個值在互聯(lián)網業(yè)務里太奢侈了一般我建議線上業(yè)務改成1秒甚至更低。注意這里說的執(zhí)行時間不光是SQL本身執(zhí)行的時間還包括鎖等待、排序、回表這些環(huán)節(jié)的耗時也就是說一條SQL從開始執(zhí)行到返回結果的完整時間。慢查詢日志解決的核心問題就兩個第一知道哪些SQL慢第二知道它們慢在哪。前者靠日志記錄后者靠執(zhí)行計劃分析。這篇文章我會從怎么開啟慢查詢日志開始一步步講到怎么讀日志、怎么用工具聚合分析、怎么用EXPLAIN定位瓶頸最后分享一些我在實際運維中踩過的坑。無論是剛入門的DBA、后端開發(fā)還是自己折騰服務器的博主這篇文章都值得你從頭到尾看一遍因為慢查詢排查這活兒不管你用什么數據庫中間件、什么云平臺思路永遠是通用的。2. 開啟慢查詢日志的正確姿勢2.1 先看當前狀態(tài)——別急著改配置接手一臺MySQL服務器第一件事永遠都是先查現(xiàn)狀而不是直接改參數。我用得最多的就是這組命令SHOW VARIABLES LIKE slow_query_log; SHOW VARIABLES LIKE slow_query_log_file; SHOW VARIABLES LIKE long_query_time; SHOW VARIABLES LIKE log_queries_not_using_indexes;這四個參數是慢查詢日志的四大核心配置。slow_query_log是開關ON就是開著slow_query_log_file是日志文件路徑long_query_time是時間閾值單位是秒支持小數比如0.5就是500毫秒log_queries_not_using_indexes記錄那些沒走索引的查詢。這里有個細節(jié)很多人容易搞混long_query_time的判定從MySQL 5.1開始就是超過這個值才記錄等于不算是嚴格大于的關系。另外在MySQL 5.1.6之前還有個log_long_queries參數老版本用的現(xiàn)在早就廢了看到網上老教程里出現(xiàn)就別照著抄了。還有一個坑是slow_query_log_file指定的目錄。MySQL進程要有權限寫這個文件否則日志起不來或者寫一半卡住。常見的情況是用了默認路徑但那個分區(qū)磁盤滿了慢查詢日志寫不進去你還在那傻等。我給個建議把這個文件放到獨立的數據盤目錄下跟數據目錄分開這樣就算日志暴增也不會拖垮系統(tǒng)盤。2.2 臨時開啟與永久開啟兩種方式都要會臨時開啟是針對當前實例的重啟MySQL后配置就丟了。這種方式適合你只是想臨時排查問題不想動配置文件-- 臨時開啟慢查詢日志 SET GLOBAL slow_query_log ON; -- 設置閾值 SET GLOBAL long_query_time 1; -- 記錄沒有走索引的查詢 SET GLOBAL log_queries_not_using_indexes ON;注意一點SET GLOBAL改的是全局值但對當前已經存在的連接不生效。也就是說你改了之后新發(fā)起的連接才會用新值之前那些連接還是老配置。如果你想對當前會話也生效得加上SET SESSION。這個細節(jié)在實際操作中非常容易踩我曾經就是改了全局閾值結果測試客戶端用的是長連接跑了半天發(fā)現(xiàn)日志里一條都沒記還以為是配置出了問題實際上是會話級參數沒跟上。永久開啟需要修改配置文件my.cnfLinux或my.iniWindows在[mysqld]段落里加上[mysqld] # 開啟慢查詢日志 slow_query_log 1 # 日志文件路徑建議用絕對路徑 slow_query_log_file /var/log/mysql/mysql-slow.log # 閾值1秒線上業(yè)務建議這個值往下調 long_query_time 1 # 記錄未使用索引的查詢 log_queries_not_using_indexes 1 # 限制日志文件大小避免撐爆磁盤5.7支持這個參數 slow_query_log_file_size 1073741824改完之后重啟MySQL服務生效。不過這里要提醒你生產環(huán)境盡量別動不動重啟我一般做法是先用SET GLOBAL在線開啟然后再改配置文件等下次維護窗口重啟的時候自然永久生效。這樣既不間斷業(yè)務又能保證配置最終落盤。2.3 閾值到底設多少才合理long_query_time設置多少合適這個問題沒有標準答案得看你的業(yè)務場景。我見過最極端的一個案例有個團隊把所有SQL都設為閾值0結果慢查詢日志每分鐘幾十萬條直接把磁盤打爆了。也見過一個傳統(tǒng)企業(yè)項目閾值設成20秒等于什么都沒記錄。我個人的經驗是分場景來定業(yè)務場景建議閾值原因高并發(fā)互聯(lián)網業(yè)務0.5秒~1秒接口響應要求快超過1秒已經影響用戶體驗一般企業(yè)應用1秒~2秒容忍度稍高但慢SQL仍需記錄離線分析/數倉5秒~10秒大批量跑數幾百毫秒不現(xiàn)實日常排查初期先1秒逐漸下調避免第一天日志量太大嚇到自己還有一點log_queries_not_using_indexes這個開關我建議在開發(fā)環(huán)境開著生產環(huán)境要看情況。它在MySQL 5.6之后有個變化不是所有沒走索引的查詢都會被記錄比如全表掃描的行數小于一定閾值時不會記。而且這個開關產生的日志量極大生產環(huán)境如果沒有專人盯日志容易被大量無效記錄淹沒反而看不清真正的問題。我一般是開發(fā)環(huán)境開啟線上謹慎開啟或者關閉。3. 慢查詢日志里到底記了什么——讀懂每行內容3.1 日志字段逐一拆解開啟慢查詢日志之后過一段時間你就能看到類似這樣的內容# Time: 2024-06-15T10:23:45.123456Z # UserHost: root[root] localhost [127.0.0.1] Id: 812345 # Query_time: 2.345678 Lock_time: 0.001234 Rows_sent: 100 Rows_examined: 1000000 # Thread_id: 8 Schema: orders Last_errno: 0 Killed: 0 # InnoDB_trx_id: 18875 SET timestamp1718442225; SELECT o.order_id, u.user_name, p.product_name FROM orders o LEFT JOIN users u ON o.user_id u.user_id LEFT JOIN products p ON o.product_id p.product_id WHERE o.status pending ORDER BY o.create_time DESC LIMIT 100;這段日志信息量很大一個一個說。Query_time是查詢總耗時這是你判斷SQL是否超時的直接依據Lock_time是鎖等待時間如果這個值很高說明SQL在等待其他事務釋放鎖問題未必在SQL本身的執(zhí)行效率上Rows_sent是實際返回給客戶端的行數Rows_examined是這條SQL為了返回結果而掃描過的行數——這個數值是重中之重Rows_examined和Rows_sent的差距越大說明掃描了大量行卻只返回了少量行典型的索引問題或者查詢邏輯問題。SET timestamp...這行在日志里容易被忽略但它很重要。因為慢查詢日志里記錄的SQL是后補的如果你直接復制SQL執(zhí)行得到的執(zhí)行計劃和當時會有差異。SET timestamp讓你知道這條SQL當時執(zhí)行的時間點配合監(jiān)控系統(tǒng)就能還原當時的服務器狀態(tài)。3.2 日志格式MySQL 5.7和8.0的差異MySQL 5.7默認的慢查詢日志格式是文本格式可讀性好但解析起來麻煩。MySQL 8.0引入了log_output參數設置日志輸出格式可以是FILE文本文件、TABLE記錄到mysql.slow_log表或者兩者都寫。我建議生產環(huán)境用FILE格式理由有兩個一是文件格式可以用各種現(xiàn)成工具分析二是表格式寫入本身有開銷高并發(fā)下會影響性能。log_outputTABLE的場景也有就是當你需要直接用SQL查詢慢查詢記錄時很方便比如SELECT * FROM mysql.slow_log ORDER BY start_time DESC LIMIT 10;但說實話我用得很少還是文件格式加工具分析最順手。MySQL 8.0里還有一個long_query_time支持微秒級別的設置比如0.000100表示100微秒不過日常用不到這么細。3.3 日志會記錄哪些SQL不會記錄哪些SQL慢查詢日志記錄的是執(zhí)行完成的SQL。也就是說如果一條SQL因為鎖等待超時、被客戶端取消或者其他原因導致沒有執(zhí)行完成它不會被記錄。這是一個很容易被誤解的點——你以為慢查詢日志能捕獲所有卡住的查詢實際上它只捕獲慢但最終執(zhí)行完的查詢。那些被kill掉的、陷入死鎖的SQL還得靠其他手段排查比如performance_schema里的事件記錄。另外慢查詢日志記錄的是DML語句SELECT、UPDATE、DELETE、INSERT等預編譯語句也會記錄比如PreparedStatement方式執(zhí)行的SQL會記錄對應的語句文本。但存儲過程內部執(zhí)行的SQL在存儲過程級別不會被記錄除非內部SQL本身超時了才會記錄那條SQL。管理類語句像CREATE INDEX、ALTER TABLE這種DDL操作雖然也耗時但默認情況下不記錄在慢查詢日志里。這點經常讓人迷惑——你明明在凌晨跑了兩個小時的ALTER TABLE加索引慢查詢日志里卻什么都沒有。MySQL 5.7開始有個log_slow_admin_statements參數可以控制是否記錄這種管理語句建議需要分析DDL耗時時把它開開。4. 慢查詢日志別用眼睛看工具才是親爹4.1 日志一多就抓瞎先學會用mysqldumpslow慢查詢日志開了一段時間后文件可能是幾百MB甚至幾個GB。這時候你如果還是用tail -f或者less一頁頁翻效率極低。MySQL自帶了mysqldumpslow工具專門用來匯總分析慢查詢日志。它的基本用法很簡單# 查看日志里最慢的10條SQL mysqldumpslow -s c -t 10 /var/log/mysql/mysql-slow.log參數說明-s是指定排序方式c代表按執(zhí)行次數計數排序t是返回前N條al是平均鎖等待時間at是平均查詢時間。我常用的是# 按平均查詢時間排序看最慢的20條 mysqldumpslow -s at -t 20 /var/log/mysql/mysql-slow.log # 按執(zhí)行次數排序看哪些SQL被頻繁執(zhí)行且耗時 mysqldumpslow -s c -t 20 /var/log/mysql/mysql-slow.logmysqldumpslow有個很聰明的設計它會自動歸一化SQL。什么叫歸一化就是把SQL里的具體值替換成抽象的占位符。比如SELECT * FROM users WHERE id 10086; SELECT * FROM users WHERE id 10087;這兩條在工具看來是同一類SQL會合并統(tǒng)計。這樣你看到的就是某類慢查詢的總共執(zhí)行次數、平均耗時、最大耗時而不是被幾千條相似SQL淹沒。不過mysqldumpslow也有局限它只支持基本統(tǒng)計看不到SQL執(zhí)行計劃的細節(jié)而且對復雜的多表查詢、子查詢歸一化處理得不算好。正常情況下我拿它做第一輪篩選找出嫌疑SQL然后再對每一條單獨做EXPLAIN分析。4.2 pt-query-digest慢查詢分析的終極武器要說慢查詢日志分析工具里哪個最能打那必須是Percona Toolkit里的pt-query-digest。這個工具比mysqldumpslow強太多了它不僅能分析慢查詢日志還能分析通用日志、二進制日志。安裝Percona Toolkit的方式各個系統(tǒng)不一樣Ubuntu上是sudo apt-get install percona-toolkitCentOS上需要先配置Percona的yum源再安裝這里不展開。裝好之后分析慢查詢日志的姿勢pt-query-digest /var/log/mysql/mysql-slow.log輸出結果分三大塊。第一塊是總體報告包括分析時間段、SQL總數、唯一SQL數、總耗時、最長耗時等。第二塊是按查詢類型分組的排名會列出每個查詢組的執(zhí)行次數、總耗時、平均耗時、占比默認按總耗時排序。第三塊是每個查詢組的詳細profile展示該組SQL的響應時間分布、歸一化后的SQL文本、示例SQL等。這個工具最厲害的地方在于它會把所有SQL按指紋分組這個指紋是基于SQL文本生成的哈希值跟mysqldumpslow的歸一化類似但更精細。你一眼就能看出哪類SQL消耗了數據庫80%的時間然后重點針對它優(yōu)化。用pt-query-digest還有一個場景我特別推薦對比分析。比如大促前后分別收集一個慢查詢日志然后用工具的--review選項對比兩次的差異就能知道哪些SQL的耗時在大促期間惡化最嚴重。這個功能在容量規(guī)劃和限流策略制定時非常有價值。4.3 沒有Percona Toolkit時怎么辦——純SQL查詢方案有些環(huán)境不讓裝第三方工具或者你覺得裝重量級工具不劃算。沒關系還有土辦法。MySQL 5.7可以把慢查詢日志輸出到表里然后直接用SQL分析-- 開啟表格式輸出 SET GLOBAL log_output TABLE; SET GLOBAL slow_query_log ON; -- 按執(zhí)行次數排序看高頻慢SQL SELECT LEFT(SUBSTRING(sql_text, 1, 50), 30) AS sql_prefix, COUNT(*) AS cnt, ROUND(AVG(query_time), 2) AS avg_query_time, MAX(query_time) AS max_query_time FROM mysql.slow_log GROUP BY sql_prefix ORDER BY cnt DESC LIMIT 20;不過我得說這種方法的分析能力有限只能做初步統(tǒng)計。而且mysql.slow_log表引擎是CSV查詢效率感人數據量大了會越來越慢。所以它只適合救急真正的高效分析還得靠文件格式加專業(yè)工具。5. 從發(fā)現(xiàn)慢SQL到定位瓶頸——EXPLAIN實戰(zhàn)解讀5.1 一條慢SQL的標準分析流程日志發(fā)現(xiàn)了慢SQL復制到測試庫怎么一步步找到問題根源我的標準動作是第一步看SQL本身搞清楚它是干什么的涉及哪些表邏輯是否合理。第二步用EXPLAIN看執(zhí)行計劃。第三步分析每個表的訪問方式、關聯(lián)順序、掃描行數。第四步結合索引情況和數據分布驗證。第五步改寫SQL或者加索引。EXPLAIN的用法很簡單就是在SQL前面加上EXPLAIN關鍵字EXPLAIN SELECT o.order_id, u.user_name, p.product_name FROM orders o LEFT JOIN users u ON o.user_id u.user_id LEFT JOIN products p ON o.product_id p.product_id WHERE o.status pending ORDER BY o.create_time DESC LIMIT 100;執(zhí)行后你會得到一張表重點關注這么幾個列type訪問類型從好到差依次是system、const、eq_ref、ref、range、index、ALL。看到ALL就說明在做全表掃描這是最常見的慢查詢根因。key實際用到的索引如果為空說明沒走任何索引。rows預估掃描的行數這個數是優(yōu)化器估計的不一定精確但量級很有參考價值。Extra這一列信息量巨大看到Using filesort說明需要文件排序看到Using temporary說明用了臨時表看到Using where說明索引條件下推不充分。還是用上面那個例子如果EXPLAIN結果顯示orders表的type為ALL預估掃描100萬行那問題就很明顯了WHERE o.status pending這個條件沒有索引可用MySQL只能挨個翻表看看哪行符合條件。再加個ORDER BY o.create_time DESC又觸發(fā)文件排序雙重debuff不慢才怪。5.2 一個完整的優(yōu)化案例拆解我給你看一個我自己實際處理過的案例。業(yè)務反饋某個列表頁接口越來越慢最開始50毫秒現(xiàn)在1.2秒還沒到警報線但趨勢不對。抓慢查詢日志找到SQLSELECT id, title, user_id, create_time FROM articles WHERE category_id 105 AND status 1 ORDER BY create_time DESC LIMIT 10;EXPLAIN結果type: ref key: idx_category rows: 23456 Extra: Using where; Using filesort表面看起來走了idx_category索引不算太差為什么慢仔細分析category_id 105這個分類下有兩萬多行然后還要在結果里過濾status 1再按create_time排序最后取10條。問題就出在這里——索引只過濾了分類沒有同時處理狀態(tài)和排序導致MySQL查完兩萬多行后還要做文件排序當然快不起來。優(yōu)化方案是建一個聯(lián)合索引ALTER TABLE articles ADD INDEX idx_cat_status_time (category_id, status, create_time);注意索引列的順序有講究等值條件的列放前面這里是category_id和status排序字段create_time放最后。這樣設計的原因是MySQL可以用這個索引同時完成過濾和排序避免Using filesort。優(yōu)化后EXPLAIN變成type: ref key: idx_cat_status_time rows: 186 Extra: Using index condition掃描行數從兩萬多降到186行接口耗時從1.2秒回到30毫秒。這個案例就是說慢SQL排查不能只滿足于走了索引要看索引是否真的覆蓋了查詢的所有需求。5.3 索引沒生效的幾種常見原因索引建了但沒用上這是比沒建索引更讓人頭疼的情況。我總結了幾個常見原因隱式類型轉換。如果字段是VARCHAR類型SQL里寫WHERE user_id 12345數字MySQL會隱式把字符串轉成數字導致索引失效。正確寫法是WHERE user_id 12345。對索引列使用函數。WHERE DATE(create_time) 2024-06-15會讓索引失效因為MySQL要先對每一行的create_time執(zhí)行DATE函數才能比較。正確做法是WHERE create_time 2024-06-15 00:00:00 AND create_time 2024-06-16 00:00:00。前導模糊查詢。WHERE title LIKE %MySQL%百分號在最前面的模糊匹配沒法用索引只能全表掃。這個沒有特別好的索引解法如果確實有需求考慮全文索引或者搜索引擎。聯(lián)合索引不滿足最左前綴原則。建了(a, b, c)聯(lián)合索引但查詢條件只用到b和c不包含a索引失效。優(yōu)化器選擇不用索引。這也是一種情況你以為MySQL會走索引但優(yōu)化器經過成本估算認為全表掃描更快比如數據量很少或者要回表的行數占比太高比如超過20%~30%。這種情況有時候可以通過FORCE INDEX強制走索引但我不建議直接這么干更健康的做法是優(yōu)化SQL本身的邏輯或者更換索引設計。排查索引問題最實用的工具是EXPLAIN之外再配合SHOW WARNINGS。執(zhí)行完EXPLAIN后再加一句SHOW WARNINGSMySQL會告訴你它實際重寫后的SQL長什么樣方便對照。6. 慢查詢的治理閉環(huán)——從發(fā)現(xiàn)到預防6.1 日志只是起點要建立問題跟蹤機制很多團隊開了慢查詢日志之后就再也不管了三個月后日志文件幾個GB但沒有任何人看過。這是典型的開了個寂寞。我建議是形成一套循環(huán)每日采集 → 每周分析 → 每季度治理回顧。每日采集可以靠定時任務比如每天凌晨跑一次pt-query-digest把結果輸出成當天報告存到固定的目錄。每周抽時間看一周匯總挑出Top 10耗時組織開會討論。新增慢SQL要登記優(yōu)化完要驗證沒優(yōu)化完的要放進待辦池。這套機制看起來簡單但真正堅持下來的團隊不多。很多人的思維是業(yè)務不報障就不管等業(yè)務方找上門來的時候往往已經是用戶都感知到卡頓的階段了。我覺得做技術的應該有這種主動出擊的覺悟。6.2 結合監(jiān)控平臺實時告警日志分析是事后行為實時告警才能防患于未然?，F(xiàn)在主流做法是把MySQL的SHOW GLOBAL STATUS里的指標或者performance_schema的數據采集到Prometheus這類監(jiān)控平臺配上Grafana做可視化看板。關鍵的告警項有這么幾個告警指標建議閾值說明慢查詢數每分鐘超過基線值3倍觀察趨勢突然增長往往是SQL性能退化或數據量突增單條SQL最大耗時超過3秒直接告警尤其是核心交易鏈路全表掃描次數持續(xù)上升可能有新SQL沒建索引或索引被誤刪Threads_running經常超過50數據庫連接池打滿的前兆實時監(jiān)控的一個難點是閾值怎么定。我建議是先從半年的慢查詢日志里算出每天的平均數和P95值再用這個做基線。不要拍腦袋定一個1秒因為不同業(yè)務差異太大。6.3 推薦一套我常用的慢查詢巡檢腳本我把自己日常巡檢用的一個Shell腳本簡化后放在這里邏輯很簡單每天跑一次把當天的慢查詢日志分析結果郵件發(fā)給自己或者寫到指定文件里周末再匯總。#!/bin/bash LOG_DIR/var/log/mysql SLOW_LOG${LOG_DIR}/mysql-slow.log REPORT_DIR/var/log/slow_report TODAY$(date %Y%m%d) mkdir -p ${REPORT_DIR} # 用pt-query-digest分析當天的慢日志 pt-query-digest ${SLOW_LOG} --since 24h ${REPORT_DIR}/report_${TODAY}.txt # 取Top 5輸出到單獨文件 pt-query-digest ${SLOW_LOG} --since 24h \ --limit 5:95:1 ${REPORT_DIR}/top5_${TODAY}.txt # 統(tǒng)計當天慢查詢總量 slow_count$(grep -c ^# Query_time: ${SLOW_LOG}) echo Date: ${TODAY} SlowQueries: ${slow_count} ${REPORT_DIR}/summary.txt這個腳本你可以用crontab每天凌晨跑一次0 2 * * * /usr/local/bin/slow_query_analyze.sh腳本運行完之后早上上班第一件事就是隨手翻一下報告看看昨天有沒有新的慢SQL冒出來。養(yǎng)成這個習慣之后你會發(fā)現(xiàn)線上SQL的性能問題基本都能在爆發(fā)之前被扼殺在搖籃里。7. 那些年我踩過的坑——慢查詢日志的隱秘角落7.1 參數改了不生效的連環(huán)坑慢查詢日志相關參數有全局和會話之分這是最基礎的坑。但更隱蔽的坑是MySQL 8.0里SET GLOBAL設置了slow_query_log之后如果配置文件里寫的是slow_query_log OFF重啟之后會被配置文件覆蓋回去。你以為永久開啟了實際上重啟之后又關了。這種問題在日志文件上看不出來直到某天發(fā)現(xiàn)慢查詢日志突然不更新了才察覺。解決方法是改完配置文件后必須驗證一遍用SHOW VARIABLES確認所有相關參數的實際值。我自己有個習慣改完配置之后寫一條慢SQL故意觸發(fā)一下然后去看日志文件有沒有新增記錄。這個驗證動作只要幾秒鐘能省掉后面無數排查時間。7.2 磁盤滿導致日志寫不進去慢查詢日志默認會無限增長如果不做日志輪轉遲早占滿磁盤。磁盤滿了MySQL會怎么樣不會崩潰但會拒絕寫操作造成寫入阻塞這比慢查詢本身更嚴重。我在生產環(huán)境見過最慘的一次就是慢查詢日志直接把根分區(qū)寫滿所有業(yè)務寫入全部卡死最后不得不刪日志緊急恢復。我的處理經驗是三層防護。第一日志文件和數據庫數據目錄分開別放在同一個分區(qū)。第二用logrotate做日志切割按天或者按大小輪轉保留最近7天。第三開啟slow_query_log_file_size限制單個文件大小超過自動輪轉。這三層都做到基本不會出大問題。7.3 不要忽視鎖等待時間高的慢查詢有時候Pull出來的慢SQLQuery_time很高但Rows_examined并不大執(zhí)行計劃也走了索引。這時候問題很可能不在SQL本身而在Lock_time上。Lock_time高說明SQL大部分時間在等待鎖釋放。怎么驗證看慢查詢日志里Lock_time和Query_time的比值。如果Lock_time占了大頭你需要排查其他并發(fā)事務。特別是線上業(yè)務用了SELECT ... FOR UPDATE、UPDATE、DELETE這類會加鎖的語句在高并發(fā)場景下容易互相阻塞。這時候光優(yōu)化SQL沒用得從業(yè)務層下手比如減小事務范圍、減少鎖的持有時間、用樂觀鎖代替悲觀鎖。7.4 慢查詢日志記錄的是因還是果最后講一個我自己的理解。很多人一看到慢查詢日志里某條SQL耗時5秒就認定這條SQL是性能問題的根源急著改寫SQL。但慢查詢日志記錄的只是表象真正的因可能是它執(zhí)行時的系統(tǒng)狀態(tài)——比如當時服務器負載本來就高磁盤IO飽和CPU被打滿任何SQL執(zhí)行都會變慢。所以分析慢查詢日志時一定要結合當時的時間點和監(jiān)控數據來看。如果某條SQL平時執(zhí)行很快只有特定時間段才慢那要考慮的不光是SQL本身還有服務器的資源競爭、定時任務沖突、備份作業(yè)并發(fā)等問題。慢查詢排查是一個系統(tǒng)性的工作不能只盯著SQL文本而要把它放到整個運行環(huán)境里去理解。8. 最后一個老運維的心里話做了這么多年數據庫運維我越來越覺得慢查詢排查這事兒真正考驗人的不是工具用得有多熟練而是你有沒有一套完整的思路。日志開沒開、閾值合不合理、看到慢SQL之后能不能快速定位到索引問題和鎖問題、優(yōu)化完之后有沒有持續(xù)跟蹤驗證每一步都環(huán)環(huán)相扣。我個人最深的體會是慢查詢日志不是用來背鍋的而是用來幫團隊提前發(fā)現(xiàn)隱患的。它記錄的每一條慢SQL都是數據庫在告訴你我這兒有個地方快撐不住了你有空來修一下。你認真對待它它能幫你把很多故障消滅在萌芽狀態(tài)你無視它它就會在某個深夜給你一個大驚喜。如果你現(xiàn)在還沒有開啟慢查詢日志今天就動手開起來閾值設成1秒然后把日志分析工具裝上。一個月后再回頭看你會感謝當時的這個決定。 MySQL慢查詢日志全解析：從開啟配置到EXPLAIN優(yōu)化實戰(zhàn)
1. 慢查詢到底是什么為什么你必須關注它第一次接手線上MySQL數據庫的時候我最頭疼的事不是別人問MySQL怎么安裝而是深更半夜收到一條警報CPU飆升、接口超時、用戶開始罵人。翻遍代碼找不到問題最后打開慢查詢日志一眼就看見那條該死的SQL——三張表join一張表幾百萬行數據連索引都沒有一次查詢跑了幾十秒。從那以后我就養(yǎng)成了一個習慣接手任何數據庫第一件事就是確認慢查詢日志有沒有開沒開就先開上再談別的。很多人覺得慢查詢日志是事后諸葛亮出了問題才去翻。這個想法大錯特錯。慢查詢日志的價值恰恰在于提前發(fā)現(xiàn)——它不是在你已經故障的時候才出現(xiàn)而是每天都把那些執(zhí)行時間超標的SQL悄悄記下來等你有空的時候去翻一翻就能提前發(fā)現(xiàn)那些現(xiàn)在還不致命、但數據量一漲就會爆炸的隱患。我見過太多案例一個小查詢在十萬行數據時跑50毫秒沒人管等數據漲到一千萬行的時候變成5秒直接拖垮整個業(yè)務。慢查詢日志的意義就是讓你在50毫秒的時候就注意到它而不是等到5秒才被迫處理。那到底什么叫慢查詢MySQL的定義很簡單凡是執(zhí)行時間超過long_query_time閾值的SQL語句都會被記錄到慢查詢日志里。默認情況下這個閾值是10秒但說實話10秒這個值在互聯(lián)網業(yè)務里太奢侈了一般我建議線上業(yè)務改成1秒甚至更低。注意這里說的執(zhí)行時間不光是SQL本身執(zhí)行的時間還包括鎖等待、排序、回表這些環(huán)節(jié)的耗時也就是說一條SQL從開始執(zhí)行到返回結果的完整時間。慢查詢日志解決的核心問題就兩個第一知道哪些SQL慢第二知道它們慢在哪。前者靠日志記錄后者靠執(zhí)行計劃分析。這篇文章我會從怎么開啟慢查詢日志開始一步步講到怎么讀日志、怎么用工具聚合分析、怎么用EXPLAIN定位瓶頸最后分享一些我在實際運維中踩過的坑。無論是剛入門的DBA、后端開發(fā)還是自己折騰服務器的博主這篇文章都值得你從頭到尾看一遍因為慢查詢排查這活兒不管你用什么數據庫中間件、什么云平臺思路永遠是通用的。2. 開啟慢查詢日志的正確姿勢2.1 先看當前狀態(tài)——別急著改配置接手一臺MySQL服務器第一件事永遠都是先查現(xiàn)狀而不是直接改參數。我用得最多的就是這組命令SHOW VARIABLES LIKE slow_query_log; SHOW VARIABLES LIKE slow_query_log_file; SHOW VARIABLES LIKE long_query_time; SHOW VARIABLES LIKE log_queries_not_using_indexes;這四個參數是慢查詢日志的四大核心配置。slow_query_log是開關ON就是開著slow_query_log_file是日志文件路徑long_query_time是時間閾值單位是秒支持小數比如0.5就是500毫秒log_queries_not_using_indexes記錄那些沒走索引的查詢。這里有個細節(jié)很多人容易搞混long_query_time的判定從MySQL 5.1開始就是超過這個值才記錄等于不算是嚴格大于的關系。另外在MySQL 5.1.6之前還有個log_long_queries參數老版本用的現(xiàn)在早就廢了看到網上老教程里出現(xiàn)就別照著抄了。還有一個坑是slow_query_log_file指定的目錄。MySQL進程要有權限寫這個文件否則日志起不來或者寫一半卡住。常見的情況是用了默認路徑但那個分區(qū)磁盤滿了慢查詢日志寫不進去你還在那傻等。我給個建議把這個文件放到獨立的數據盤目錄下跟數據目錄分開這樣就算日志暴增也不會拖垮系統(tǒng)盤。2.2 臨時開啟與永久開啟兩種方式都要會臨時開啟是針對當前實例的重啟MySQL后配置就丟了。這種方式適合你只是想臨時排查問題不想動配置文件-- 臨時開啟慢查詢日志 SET GLOBAL slow_query_log ON; -- 設置閾值 SET GLOBAL long_query_time 1; -- 記錄沒有走索引的查詢 SET GLOBAL log_queries_not_using_indexes ON;注意一點SET GLOBAL改的是全局值但對當前已經存在的連接不生效。也就是說你改了之后新發(fā)起的連接才會用新值之前那些連接還是老配置。如果你想對當前會話也生效得加上SET SESSION。這個細節(jié)在實際操作中非常容易踩我曾經就是改了全局閾值結果測試客戶端用的是長連接跑了半天發(fā)現(xiàn)日志里一條都沒記還以為是配置出了問題實際上是會話級參數沒跟上。永久開啟需要修改配置文件my.cnfLinux或my.iniWindows在[mysqld]段落里加上[mysqld] # 開啟慢查詢日志 slow_query_log 1 # 日志文件路徑建議用絕對路徑 slow_query_log_file /var/log/mysql/mysql-slow.log # 閾值1秒線上業(yè)務建議這個值往下調 long_query_time 1 # 記錄未使用索引的查詢 log_queries_not_using_indexes 1 # 限制日志文件大小避免撐爆磁盤5.7支持這個參數 slow_query_log_file_size 1073741824改完之后重啟MySQL服務生效。不過這里要提醒你生產環(huán)境盡量別動不動重啟我一般做法是先用SET GLOBAL在線開啟然后再改配置文件等下次維護窗口重啟的時候自然永久生效。這樣既不間斷業(yè)務又能保證配置最終落盤。2.3 閾值到底設多少才合理long_query_time設置多少合適這個問題沒有標準答案得看你的業(yè)務場景。我見過最極端的一個案例有個團隊把所有SQL都設為閾值0結果慢查詢日志每分鐘幾十萬條直接把磁盤打爆了。也見過一個傳統(tǒng)企業(yè)項目閾值設成20秒等于什么都沒記錄。我個人的經驗是分場景來定業(yè)務場景建議閾值原因高并發(fā)互聯(lián)網業(yè)務0.5秒~1秒接口響應要求快超過1秒已經影響用戶體驗一般企業(yè)應用1秒~2秒容忍度稍高但慢SQL仍需記錄離線分析/數倉5秒~10秒大批量跑數幾百毫秒不現(xiàn)實日常排查初期先1秒逐漸下調避免第一天日志量太大嚇到自己還有一點log_queries_not_using_indexes這個開關我建議在開發(fā)環(huán)境開著生產環(huán)境要看情況。它在MySQL 5.6之后有個變化不是所有沒走索引的查詢都會被記錄比如全表掃描的行數小于一定閾值時不會記。而且這個開關產生的日志量極大生產環(huán)境如果沒有專人盯日志容易被大量無效記錄淹沒反而看不清真正的問題。我一般是開發(fā)環(huán)境開啟線上謹慎開啟或者關閉。3. 慢查詢日志里到底記了什么——讀懂每行內容3.1 日志字段逐一拆解開啟慢查詢日志之后過一段時間你就能看到類似這樣的內容# Time: 2024-06-15T10:23:45.123456Z # UserHost: root[root] localhost [127.0.0.1] Id: 812345 # Query_time: 2.345678 Lock_time: 0.001234 Rows_sent: 100 Rows_examined: 1000000 # Thread_id: 8 Schema: orders Last_errno: 0 Killed: 0 # InnoDB_trx_id: 18875 SET timestamp1718442225; SELECT o.order_id, u.user_name, p.product_name FROM orders o LEFT JOIN users u ON o.user_id u.user_id LEFT JOIN products p ON o.product_id p.product_id WHERE o.status pending ORDER BY o.create_time DESC LIMIT 100;這段日志信息量很大一個一個說。Query_time是查詢總耗時這是你判斷SQL是否超時的直接依據Lock_time是鎖等待時間如果這個值很高說明SQL在等待其他事務釋放鎖問題未必在SQL本身的執(zhí)行效率上Rows_sent是實際返回給客戶端的行數Rows_examined是這條SQL為了返回結果而掃描過的行數——這個數值是重中之重Rows_examined和Rows_sent的差距越大說明掃描了大量行卻只返回了少量行典型的索引問題或者查詢邏輯問題。SET timestamp...這行在日志里容易被忽略但它很重要。因為慢查詢日志里記錄的SQL是后補的如果你直接復制SQL執(zhí)行得到的執(zhí)行計劃和當時會有差異。SET timestamp讓你知道這條SQL當時執(zhí)行的時間點配合監(jiān)控系統(tǒng)就能還原當時的服務器狀態(tài)。3.2 日志格式MySQL 5.7和8.0的差異MySQL 5.7默認的慢查詢日志格式是文本格式可讀性好但解析起來麻煩。MySQL 8.0引入了log_output參數設置日志輸出格式可以是FILE文本文件、TABLE記錄到mysql.slow_log表或者兩者都寫。我建議生產環(huán)境用FILE格式理由有兩個一是文件格式可以用各種現(xiàn)成工具分析二是表格式寫入本身有開銷高并發(fā)下會影響性能。log_outputTABLE的場景也有就是當你需要直接用SQL查詢慢查詢記錄時很方便比如SELECT * FROM mysql.slow_log ORDER BY start_time DESC LIMIT 10;但說實話我用得很少還是文件格式加工具分析最順手。MySQL 8.0里還有一個long_query_time支持微秒級別的設置比如0.000100表示100微秒不過日常用不到這么細。3.3 日志會記錄哪些SQL不會記錄哪些SQL慢查詢日志記錄的是執(zhí)行完成的SQL。也就是說如果一條SQL因為鎖等待超時、被客戶端取消或者其他原因導致沒有執(zhí)行完成它不會被記錄。這是一個很容易被誤解的點——你以為慢查詢日志能捕獲所有卡住的查詢實際上它只捕獲慢但最終執(zhí)行完的查詢。那些被kill掉的、陷入死鎖的SQL還得靠其他手段排查比如performance_schema里的事件記錄。另外慢查詢日志記錄的是DML語句SELECT、UPDATE、DELETE、INSERT等預編譯語句也會記錄比如PreparedStatement方式執(zhí)行的SQL會記錄對應的語句文本。但存儲過程內部執(zhí)行的SQL在存儲過程級別不會被記錄除非內部SQL本身超時了才會記錄那條SQL。管理類語句像CREATE INDEX、ALTER TABLE這種DDL操作雖然也耗時但默認情況下不記錄在慢查詢日志里。這點經常讓人迷惑——你明明在凌晨跑了兩個小時的ALTER TABLE加索引慢查詢日志里卻什么都沒有。MySQL 5.7開始有個log_slow_admin_statements參數可以控制是否記錄這種管理語句建議需要分析DDL耗時時把它開開。4. 慢查詢日志別用眼睛看工具才是親爹4.1 日志一多就抓瞎先學會用mysqldumpslow慢查詢日志開了一段時間后文件可能是幾百MB甚至幾個GB。這時候你如果還是用tail -f或者less一頁頁翻效率極低。MySQL自帶了mysqldumpslow工具專門用來匯總分析慢查詢日志。它的基本用法很簡單# 查看日志里最慢的10條SQL mysqldumpslow -s c -t 10 /var/log/mysql/mysql-slow.log參數說明-s是指定排序方式c代表按執(zhí)行次數計數排序t是返回前N條al是平均鎖等待時間at是平均查詢時間。我常用的是# 按平均查詢時間排序看最慢的20條 mysqldumpslow -s at -t 20 /var/log/mysql/mysql-slow.log # 按執(zhí)行次數排序看哪些SQL被頻繁執(zhí)行且耗時 mysqldumpslow -s c -t 20 /var/log/mysql/mysql-slow.logmysqldumpslow有個很聰明的設計它會自動歸一化SQL。什么叫歸一化就是把SQL里的具體值替換成抽象的占位符。比如SELECT * FROM users WHERE id 10086; SELECT * FROM users WHERE id 10087;這兩條在工具看來是同一類SQL會合并統(tǒng)計。這樣你看到的就是某類慢查詢的總共執(zhí)行次數、平均耗時、最大耗時而不是被幾千條相似SQL淹沒。不過mysqldumpslow也有局限它只支持基本統(tǒng)計看不到SQL執(zhí)行計劃的細節(jié)而且對復雜的多表查詢、子查詢歸一化處理得不算好。正常情況下我拿它做第一輪篩選找出嫌疑SQL然后再對每一條單獨做EXPLAIN分析。4.2 pt-query-digest慢查詢分析的終極武器要說慢查詢日志分析工具里哪個最能打那必須是Percona Toolkit里的pt-query-digest。這個工具比mysqldumpslow強太多了它不僅能分析慢查詢日志還能分析通用日志、二進制日志。安裝Percona Toolkit的方式各個系統(tǒng)不一樣Ubuntu上是sudo apt-get install percona-toolkitCentOS上需要先配置Percona的yum源再安裝這里不展開。裝好之后分析慢查詢日志的姿勢pt-query-digest /var/log/mysql/mysql-slow.log輸出結果分三大塊。第一塊是總體報告包括分析時間段、SQL總數、唯一SQL數、總耗時、最長耗時等。第二塊是按查詢類型分組的排名會列出每個查詢組的執(zhí)行次數、總耗時、平均耗時、占比默認按總耗時排序。第三塊是每個查詢組的詳細profile展示該組SQL的響應時間分布、歸一化后的SQL文本、示例SQL等。這個工具最厲害的地方在于它會把所有SQL按指紋分組這個指紋是基于SQL文本生成的哈希值跟mysqldumpslow的歸一化類似但更精細。你一眼就能看出哪類SQL消耗了數據庫80%的時間然后重點針對它優(yōu)化。用pt-query-digest還有一個場景我特別推薦對比分析。比如大促前后分別收集一個慢查詢日志然后用工具的--review選項對比兩次的差異就能知道哪些SQL的耗時在大促期間惡化最嚴重。這個功能在容量規(guī)劃和限流策略制定時非常有價值。4.3 沒有Percona Toolkit時怎么辦——純SQL查詢方案有些環(huán)境不讓裝第三方工具或者你覺得裝重量級工具不劃算。沒關系還有土辦法。MySQL 5.7可以把慢查詢日志輸出到表里然后直接用SQL分析-- 開啟表格式輸出 SET GLOBAL log_output TABLE; SET GLOBAL slow_query_log ON; -- 按執(zhí)行次數排序看高頻慢SQL SELECT LEFT(SUBSTRING(sql_text, 1, 50), 30) AS sql_prefix, COUNT(*) AS cnt, ROUND(AVG(query_time), 2) AS avg_query_time, MAX(query_time) AS max_query_time FROM mysql.slow_log GROUP BY sql_prefix ORDER BY cnt DESC LIMIT 20;不過我得說這種方法的分析能力有限只能做初步統(tǒng)計。而且mysql.slow_log表引擎是CSV查詢效率感人數據量大了會越來越慢。所以它只適合救急真正的高效分析還得靠文件格式加專業(yè)工具。5. 從發(fā)現(xiàn)慢SQL到定位瓶頸——EXPLAIN實戰(zhàn)解讀5.1 一條慢SQL的標準分析流程日志發(fā)現(xiàn)了慢SQL復制到測試庫怎么一步步找到問題根源我的標準動作是第一步看SQL本身搞清楚它是干什么的涉及哪些表邏輯是否合理。第二步用EXPLAIN看執(zhí)行計劃。第三步分析每個表的訪問方式、關聯(lián)順序、掃描行數。第四步結合索引情況和數據分布驗證。第五步改寫SQL或者加索引。EXPLAIN的用法很簡單就是在SQL前面加上EXPLAIN關鍵字EXPLAIN SELECT o.order_id, u.user_name, p.product_name FROM orders o LEFT JOIN users u ON o.user_id u.user_id LEFT JOIN products p ON o.product_id p.product_id WHERE o.status pending ORDER BY o.create_time DESC LIMIT 100;執(zhí)行后你會得到一張表重點關注這么幾個列type訪問類型從好到差依次是system、const、eq_ref、ref、range、index、ALL。看到ALL就說明在做全表掃描這是最常見的慢查詢根因。key實際用到的索引如果為空說明沒走任何索引。rows預估掃描的行數這個數是優(yōu)化器估計的不一定精確但量級很有參考價值。Extra這一列信息量巨大看到Using filesort說明需要文件排序看到Using temporary說明用了臨時表看到Using where說明索引條件下推不充分。還是用上面那個例子如果EXPLAIN結果顯示orders表的type為ALL預估掃描100萬行那問題就很明顯了WHERE o.status pending這個條件沒有索引可用MySQL只能挨個翻表看看哪行符合條件。再加個ORDER BY o.create_time DESC又觸發(fā)文件排序雙重debuff不慢才怪。5.2 一個完整的優(yōu)化案例拆解我給你看一個我自己實際處理過的案例。業(yè)務反饋某個列表頁接口越來越慢最開始50毫秒現(xiàn)在1.2秒還沒到警報線但趨勢不對。抓慢查詢日志找到SQLSELECT id, title, user_id, create_time FROM articles WHERE category_id 105 AND status 1 ORDER BY create_time DESC LIMIT 10;EXPLAIN結果type: ref key: idx_category rows: 23456 Extra: Using where; Using filesort表面看起來走了idx_category索引不算太差為什么慢仔細分析category_id 105這個分類下有兩萬多行然后還要在結果里過濾status 1再按create_time排序最后取10條。問題就出在這里——索引只過濾了分類沒有同時處理狀態(tài)和排序導致MySQL查完兩萬多行后還要做文件排序當然快不起來。優(yōu)化方案是建一個聯(lián)合索引ALTER TABLE articles ADD INDEX idx_cat_status_time (category_id, status, create_time);注意索引列的順序有講究等值條件的列放前面這里是category_id和status排序字段create_time放最后。這樣設計的原因是MySQL可以用這個索引同時完成過濾和排序避免Using filesort。優(yōu)化后EXPLAIN變成type: ref key: idx_cat_status_time rows: 186 Extra: Using index condition掃描行數從兩萬多降到186行接口耗時從1.2秒回到30毫秒。這個案例就是說慢SQL排查不能只滿足于走了索引要看索引是否真的覆蓋了查詢的所有需求。5.3 索引沒生效的幾種常見原因索引建了但沒用上這是比沒建索引更讓人頭疼的情況。我總結了幾個常見原因隱式類型轉換。如果字段是VARCHAR類型SQL里寫WHERE user_id 12345數字MySQL會隱式把字符串轉成數字導致索引失效。正確寫法是WHERE user_id 12345。對索引列使用函數。WHERE DATE(create_time) 2024-06-15會讓索引失效因為MySQL要先對每一行的create_time執(zhí)行DATE函數才能比較。正確做法是WHERE create_time 2024-06-15 00:00:00 AND create_time 2024-06-16 00:00:00。前導模糊查詢。WHERE title LIKE %MySQL%百分號在最前面的模糊匹配沒法用索引只能全表掃。這個沒有特別好的索引解法如果確實有需求考慮全文索引或者搜索引擎。聯(lián)合索引不滿足最左前綴原則。建了(a, b, c)聯(lián)合索引但查詢條件只用到b和c不包含a索引失效。優(yōu)化器選擇不用索引。這也是一種情況你以為MySQL會走索引但優(yōu)化器經過成本估算認為全表掃描更快比如數據量很少或者要回表的行數占比太高比如超過20%~30%。這種情況有時候可以通過FORCE INDEX強制走索引但我不建議直接這么干更健康的做法是優(yōu)化SQL本身的邏輯或者更換索引設計。排查索引問題最實用的工具是EXPLAIN之外再配合SHOW WARNINGS。執(zhí)行完EXPLAIN后再加一句SHOW WARNINGSMySQL會告訴你它實際重寫后的SQL長什么樣方便對照。6. 慢查詢的治理閉環(huán)——從發(fā)現(xiàn)到預防6.1 日志只是起點要建立問題跟蹤機制很多團隊開了慢查詢日志之后就再也不管了三個月后日志文件幾個GB但沒有任何人看過。這是典型的開了個寂寞。我建議是形成一套循環(huán)每日采集 → 每周分析 → 每季度治理回顧。每日采集可以靠定時任務比如每天凌晨跑一次pt-query-digest把結果輸出成當天報告存到固定的目錄。每周抽時間看一周匯總挑出Top 10耗時組織開會討論。新增慢SQL要登記優(yōu)化完要驗證沒優(yōu)化完的要放進待辦池。這套機制看起來簡單但真正堅持下來的團隊不多。很多人的思維是業(yè)務不報障就不管等業(yè)務方找上門來的時候往往已經是用戶都感知到卡頓的階段了。我覺得做技術的應該有這種主動出擊的覺悟。6.2 結合監(jiān)控平臺實時告警日志分析是事后行為實時告警才能防患于未然?，F(xiàn)在主流做法是把MySQL的SHOW GLOBAL STATUS里的指標或者performance_schema的數據采集到Prometheus這類監(jiān)控平臺配上Grafana做可視化看板。關鍵的告警項有這么幾個告警指標建議閾值說明慢查詢數每分鐘超過基線值3倍觀察趨勢突然增長往往是SQL性能退化或數據量突增單條SQL最大耗時超過3秒直接告警尤其是核心交易鏈路全表掃描次數持續(xù)上升可能有新SQL沒建索引或索引被誤刪Threads_running經常超過50數據庫連接池打滿的前兆實時監(jiān)控的一個難點是閾值怎么定。我建議是先從半年的慢查詢日志里算出每天的平均數和P95值再用這個做基線。不要拍腦袋定一個1秒因為不同業(yè)務差異太大。6.3 推薦一套我常用的慢查詢巡檢腳本我把自己日常巡檢用的一個Shell腳本簡化后放在這里邏輯很簡單每天跑一次把當天的慢查詢日志分析結果郵件發(fā)給自己或者寫到指定文件里周末再匯總。#!/bin/bash LOG_DIR/var/log/mysql SLOW_LOG${LOG_DIR}/mysql-slow.log REPORT_DIR/var/log/slow_report TODAY$(date %Y%m%d) mkdir -p ${REPORT_DIR} # 用pt-query-digest分析當天的慢日志 pt-query-digest ${SLOW_LOG} --since 24h ${REPORT_DIR}/report_${TODAY}.txt # 取Top 5輸出到單獨文件 pt-query-digest ${SLOW_LOG} --since 24h \ --limit 5:95:1 ${REPORT_DIR}/top5_${TODAY}.txt # 統(tǒng)計當天慢查詢總量 slow_count$(grep -c ^# Query_time: ${SLOW_LOG}) echo Date: ${TODAY} SlowQueries: ${slow_count} ${REPORT_DIR}/summary.txt這個腳本你可以用crontab每天凌晨跑一次0 2 * * * /usr/local/bin/slow_query_analyze.sh腳本運行完之后早上上班第一件事就是隨手翻一下報告看看昨天有沒有新的慢SQL冒出來。養(yǎng)成這個習慣之后你會發(fā)現(xiàn)線上SQL的性能問題基本都能在爆發(fā)之前被扼殺在搖籃里。7. 那些年我踩過的坑——慢查詢日志的隱秘角落7.1 參數改了不生效的連環(huán)坑慢查詢日志相關參數有全局和會話之分這是最基礎的坑。但更隱蔽的坑是MySQL 8.0里SET GLOBAL設置了slow_query_log之后如果配置文件里寫的是slow_query_log OFF重啟之后會被配置文件覆蓋回去。你以為永久開啟了實際上重啟之后又關了。這種問題在日志文件上看不出來直到某天發(fā)現(xiàn)慢查詢日志突然不更新了才察覺。解決方法是改完配置文件后必須驗證一遍用SHOW VARIABLES確認所有相關參數的實際值。我自己有個習慣改完配置之后寫一條慢SQL故意觸發(fā)一下然后去看日志文件有沒有新增記錄。這個驗證動作只要幾秒鐘能省掉后面無數排查時間。7.2 磁盤滿導致日志寫不進去慢查詢日志默認會無限增長如果不做日志輪轉遲早占滿磁盤。磁盤滿了MySQL會怎么樣不會崩潰但會拒絕寫操作造成寫入阻塞這比慢查詢本身更嚴重。我在生產環(huán)境見過最慘的一次就是慢查詢日志直接把根分區(qū)寫滿所有業(yè)務寫入全部卡死最后不得不刪日志緊急恢復。我的處理經驗是三層防護。第一日志文件和數據庫數據目錄分開別放在同一個分區(qū)。第二用logrotate做日志切割按天或者按大小輪轉保留最近7天。第三開啟slow_query_log_file_size限制單個文件大小超過自動輪轉。這三層都做到基本不會出大問題。7.3 不要忽視鎖等待時間高的慢查詢有時候Pull出來的慢SQLQuery_time很高但Rows_examined并不大執(zhí)行計劃也走了索引。這時候問題很可能不在SQL本身而在Lock_time上。Lock_time高說明SQL大部分時間在等待鎖釋放。怎么驗證看慢查詢日志里Lock_time和Query_time的比值。如果Lock_time占了大頭你需要排查其他并發(fā)事務。特別是線上業(yè)務用了SELECT ... FOR UPDATE、UPDATE、DELETE這類會加鎖的語句在高并發(fā)場景下容易互相阻塞。這時候光優(yōu)化SQL沒用得從業(yè)務層下手比如減小事務范圍、減少鎖的持有時間、用樂觀鎖代替悲觀鎖。7.4 慢查詢日志記錄的是因還是果最后講一個我自己的理解。很多人一看到慢查詢日志里某條SQL耗時5秒就認定這條SQL是性能問題的根源急著改寫SQL。但慢查詢日志記錄的只是表象真正的因可能是它執(zhí)行時的系統(tǒng)狀態(tài)——比如當時服務器負載本來就高磁盤IO飽和CPU被打滿任何SQL執(zhí)行都會變慢。所以分析慢查詢日志時一定要結合當時的時間點和監(jiān)控數據來看。如果某條SQL平時執(zhí)行很快只有特定時間段才慢那要考慮的不光是SQL本身還有服務器的資源競爭、定時任務沖突、備份作業(yè)并發(fā)等問題。慢查詢排查是一個系統(tǒng)性的工作不能只盯著SQL文本而要把它放到整個運行環(huán)境里去理解。8. 最后一個老運維的心里話做了這么多年數據庫運維我越來越覺得慢查詢排查這事兒真正考驗人的不是工具用得有多熟練而是你有沒有一套完整的思路。日志開沒開、閾值合不合理、看到慢SQL之后能不能快速定位到索引問題和鎖問題、優(yōu)化完之后有沒有持續(xù)跟蹤驗證每一步都環(huán)環(huán)相扣。我個人最深的體會是慢查詢日志不是用來背鍋的而是用來幫團隊提前發(fā)現(xiàn)隱患的。它記錄的每一條慢SQL都是數據庫在告訴你我這兒有個地方快撐不住了你有空來修一下。你認真對待它它能幫你把很多故障消滅在萌芽狀態(tài)你無視它它就會在某個深夜給你一個大驚喜。如果你現(xiàn)在還沒有開啟慢查詢日志今天就動手開起來閾值設成1秒然后把日志分析工具裝上。一個月后再回頭看你會感謝當時的這個決定。