1. 程式人生 > >19 | 為什麽我只查一行的語句,也執行這麽慢?

19 | 為什麽我只查一行的語句,也執行這麽慢?

select語句 結束 信息 sql 在哪裏 nod 沒有 執行 朋友

一般情況下,如果我跟你說查詢性能優化,你首先會想到一些復雜的語句,想到查詢需要返回大量的數據。但有些情況下,“查一行”,也會執行得特別慢。今天,我就跟你聊聊這個有趣的話題,看看什麽情況下,會出現這個現象。

需要說明的是,如果MySQL數據庫本身就有很大的壓力,導致數據庫服務器CPU占用率很高或ioutil(IO利用率)很高,這種情況下所有語句的執行都有可能變慢,不屬於我們今天的討論範圍。

為了便於描述,我還是構造一個表,基於這個表來說明今天的問題。這個表有兩個字段id和c,並且我在裏面插入了10萬行記錄。

mysql> CREATE TABLE `t` (
`id` int(11) NOT NULL,
`c` int(11) DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB;

delimiter ;;
create procedure idata()
begin
declare i int;
set i=1;
while(i<=100000)do
insert into t values(i,i);
set i=i+1;
end while;
end;;
delimiter ;

call idata();

接下來,我會用幾個不同的場景來舉例,有些是前面的文章中我們已經介紹過的知識點,你看看能不能一眼看穿,來檢驗一下吧。

第一類:查詢長時間不返回

如圖1所示,在表t執行下面的SQL語句:

mysql> select * from t where id=1;

查詢結果長時間不返回。

技術分享圖片

圖1 查詢長時間不返回

一般碰到這種情況的話,大概率是表t被鎖住了。接下來分析原因的時候,一般都是首先執行一下show processlist命令,看看當前語句處於什麽狀態。

然後我們再針對每種狀態,去分析它們產生的原因、如何復現,以及如何處理。

等MDL鎖

如圖2所示,就是使用show processlist命令查看Waiting for table metadata lock的示意圖。

技術分享圖片

圖2 Waiting for table metadata lock狀態示意圖

出現這個狀態表示的是,現在有一個線程正在表t上請求或者持有MDL寫鎖,把select語句堵住了。

在第6篇文章《全局鎖和表鎖 :給表加個字段怎麽有這麽多阻礙?》中,我給你介紹過一種復現方法。但需要說明的是,那個復現過程是基於MySQL 5.6版本的。而MySQL 5.7版本修改了MDL的加鎖策略,所以就不能復現這個場景了。

不過,在MySQL 5.7版本下復現這個場景,也很容易。如圖3所示,我給出了簡單的復現步驟。
技術分享圖片

圖3 MySQL 5.7中Waiting for table metadata lock的復現步驟

session A 通過lock table命令持有表t的MDL寫鎖,而session B的查詢需要獲取MDL讀鎖。所以,session B進入等待狀態。

這類問題的處理方式,就是找到誰持有MDL寫鎖,然後把它kill掉。

但是,由於在show processlist的結果裏面,session A的Command列是“Sleep”,導致查找起來很不方便。不過有了performance_schema和sys系統庫以後,就方便多了。(MySQL啟動時需要設置performance_schema=on,相比於設置為off會有10%左右的性能損失)

通過查詢sys.schema_table_lock_waits這張表,我們就可以直接找出造成阻塞的process id,把這個連接用kill 命令斷開即可。

技術分享圖片

圖4 查獲加表鎖的線程id

等flush

接下來,我給你舉另外一種查詢被堵住的情況。

我在表t上,執行下面的SQL語句:

mysql> select * from information_schema.processlist where id=1;

這裏,我先賣個關子。

你可以看一下圖5。我查出來這個線程的狀態是Waiting for table flush,你可以設想一下這是什麽原因。
技術分享圖片

圖5 Waiting for table flush狀態示意圖

這個狀態表示的是,現在有一個線程正要對表t做flush操作。MySQL裏面對表做flush操作的用法,一般有以下兩個:

flush tables t with read lock;

flush tables with read lock;

這兩個flush語句,如果指定表t的話,代表的是只關閉表t;如果沒有指定具體的表名,則表示關閉MySQL裏所有打開的表。

但是正常這兩個語句執行起來都很快,除非它們也被別的線程堵住了。

所以,出現Waiting for table flush狀態的可能情況是:有一個flush tables命令被別的語句堵住了,然後它又堵住了我們的select語句。

現在,我們一起來復現一下這種情況,復現步驟如圖6所示:

技術分享圖片

圖6 Waiting for table flush的復現步驟

在session A中,我故意每行都調用一次sleep(1),這樣這個語句默認要執行10萬秒,在這期間表t一直是被session A“打開”著。然後,session B的flush tables t命令再要去關閉表t,就需要等session A的查詢結束。這樣,session C要再次查詢的話,就會被flush 命令堵住了。

圖7是這個復現步驟的show processlist結果。這個例子的排查也很簡單,你看到這個show processlist的結果,肯定就知道應該怎麽做了。

技術分享圖片

圖 7 Waiting for table flush的show processlist 結果

等行鎖

現在,經過了表級鎖的考驗,我們的select 語句終於來到引擎裏了。

mysql> select * from t where id=1 lock in share mode; 

上面這條語句的用法你也很熟悉了,我們在第8篇《事務到底是隔離的還是不隔離的?》文章介紹當前讀時提到過。

由於訪問id=1這個記錄時要加讀鎖,如果這時候已經有一個事務在這行記錄上持有一個寫鎖,我們的select語句就會被堵住。

復現步驟和現場如下:

技術分享圖片

圖 8 行鎖復現

技術分享圖片

圖 9 行鎖show processlist 現場

顯然,session A啟動了事務,占有寫鎖,還不提交,是導致session B被堵住的原因。

這個問題並不難分析,但問題是怎麽查出是誰占著這個寫鎖。如果你用的是MySQL 5.7版本,可以通過sys.innodb_lock_waits 表查到。

查詢方法是:

mysql> select * from t sys.innodb_lock_waits where locked_table=`‘test‘.‘t‘`\G

技術分享圖片

圖10 通過sys.innodb_lock_waits 查行鎖

可以看到,這個信息很全,4號線程是造成堵塞的罪魁禍首。而幹掉這個罪魁禍首的方式,就是KILL QUERY 4或KILL 4。

不過,這裏不應該顯示“KILL QUERY 4”。這個命令表示停止4號線程當前正在執行的語句,而這個方法其實是沒有用的。因為占有行鎖的是update語句,這個語句已經是之前執行完成了的,現在執行KILL QUERY,無法讓這個事務去掉id=1上的行鎖。

實際上,KILL 4才有效,也就是說直接斷開這個連接。這裏隱含的一個邏輯就是,連接被斷開的時候,會自動回滾這個連接裏面正在執行的線程,也就釋放了id=1上的行鎖。

第二類:查詢慢

經過了重重封“鎖”,我們再來看看一些查詢慢的例子。

先來看一條你一定知道原因的SQL語句:

mysql> select * from t where c=50000 limit 1;

由於字段c上沒有索引,這個語句只能走id主鍵順序掃描,因此需要掃描5萬行。

作為確認,你可以看一下慢查詢日誌。註意,這裏為了把所有語句記錄到slow log裏,我在連接後先執行了 set long_query_time=0,將慢查詢日誌的時間閾值設置為0。

技術分享圖片

圖11 全表掃描5萬行的slow log

Rows_examined顯示掃描了50000行。你可能會說,不是很慢呀,11.5毫秒就返回了,我們線上一般都配置超過1秒才算慢查詢。但你要記住:壞查詢不一定是慢查詢。我們這個例子裏面只有10萬行記錄,數據量大起來的話,執行時間就線性漲上去了。

掃描行數多,所以執行慢,這個很好理解。

但是接下來,我們再看一個只掃描一行,但是執行很慢的語句。

如圖12所示,是這個例子的slow log。可以看到,執行的語句是

mysql> select * from t where id=1;

雖然掃描行數是1,但執行時間卻長達800毫秒。

技術分享圖片

圖12 掃描一行卻執行得很慢

是不是有點奇怪呢,這些時間都花在哪裏了?

如果我把這個slow log的截圖再往下拉一點,你可以看到下一個語句,select * from t where id=1 lock in share mode,執行時掃描行數也是1行,執行時間是0.2毫秒。

技術分享圖片

圖 13 加上lock in share mode的slow log

看上去是不是更奇怪了?按理說lock in share mode還要加鎖,時間應該更長才對啊。

可能有的同學已經有答案了。如果你還沒有答案的話,我再給你一個提示信息,圖14是這兩個語句的執行輸出結果。

技術分享圖片

圖14 兩個語句的輸出結果

第一個語句的查詢結果裏c=1,帶lock in share mode的語句返回的是c=1000001。看到這裏應該有更多的同學知道原因了。如果你還是沒有頭緒的話,也別著急。我先跟你說明一下復現步驟,再分析原因。

技術分享圖片

圖15 復現步驟

你看到了,session A先用start transaction with consistent snapshot命令啟動了一個事務,之後session B才開始執行update 語句。

session B執行完100萬次update語句後,id=1這一行處於什麽狀態呢?你可以從圖16中找到答案。

技術分享圖片

圖16 id=1的數據狀態

session B更新完100萬次,生成了100萬個回滾日誌(undo log)。

帶lock in share mode的SQL語句,是當前讀,因此會直接讀到1000001這個結果,所以速度很快;而select * from t where id=1這個語句,是一致性讀,因此需要從1000001開始,依次執行undo log,執行了100萬次以後,才將1這個結果返回。

註意,undo log裏記錄的其實是“把2改成1”,“把3改成2”這樣的操作邏輯,畫成減1的目的是方便你看圖。

小結

今天我給你舉了在一個簡單的表上,執行“查一行”,可能會出現的被鎖住和執行慢的例子。這其中涉及到了表鎖、行鎖和一致性讀的概念。

在實際使用中,碰到的場景會更復雜。但大同小異,你可以按照我在文章中介紹的定位方法,來定位並解決問題。

最後,我給你留一個問題吧。

我們在舉例加鎖讀的時候,用的是這個語句,select * from t where id=1 lock in share mode。由於id上有索引,所以可以直接定位到id=1這一行,因此讀鎖也是只加在了這一行上。

但如果是下面的SQL語句,

begin;
select * from t where c=5 for update;
commit;

這個語句序列是怎麽加鎖的呢?加的鎖又是什麽時候釋放呢?

你可以把你的觀點和驗證方法寫在留言區裏,我會在下一篇文章的末尾給出我的參考答案。感謝你的收聽,也歡迎你把這篇文章分享給更多的朋友一起閱讀。

上期問題時間

在上一篇文章最後,我留給你的問題是,希望你可以分享一下之前碰到過的、與文章中類似的場景。

@封建的風 提到一個有趣的場景,值得一說。我把他的問題重寫一下,表結構如下:

mysql> CREATE TABLE `table_a` (
`id` int(11) NOT NULL,
`b` varchar(10) DEFAULT NULL,
PRIMARY KEY (`id`),
KEY `b` (`b`)
) ENGINE=InnoDB;

假設現在表裏面,有100萬行數據,其中有10萬行數據的b的值是’1234567890’, 假設現在執行語句是這麽寫的:

mysql> select * from table_a where b=‘1234567890abcd‘;

這時候,MySQL會怎麽執行呢?

最理想的情況是,MySQL看到字段b定義的是varchar(10),那肯定返回空呀。可惜,MySQL並沒有這麽做。

那要不,就是把’1234567890abcd’拿到索引裏面去做匹配,肯定也沒能夠快速判斷出索引樹b上並沒有這個值,也很快就能返回空結果。

但實際上,MySQL也不是這麽做的。

這條SQL語句的執行很慢,流程是這樣的:

  1. 在傳給引擎執行的時候,做了字符截斷。因為引擎裏面這個行只定義了長度是10,所以只截了前10個字節,就是’1234567890’進去做匹配;

  2. 這樣滿足條件的數據有10萬行;

  3. 因為是select *, 所以要做10萬次回表;

  4. 但是每次回表以後查出整行,到server層一判斷,b的值都不是’1234567890abcd’;

  5. 返回結果是空。

這個例子,是我們文章內容的一個很好的補充。雖然執行過程中可能經過函數操作,但是最終在拿到結果後,server層還是要做一輪判斷的。

19 | 為什麽我只查一行的語句,也執行這麽慢?