MySQL:简单insert 一秒原因排查
這個(gè)問(wèn)題是來(lái)自一位朋友@春波，我通過(guò)pstack最終確認(rèn)問(wèn)題，涉及到兩個(gè)參數(shù)的設(shè)置，我將從源碼進(jìn)行解釋，如果有誤還請(qǐng)見(jiàn)諒。
一、問(wèn)題展示
1、簡(jiǎn)單插入需要1秒
語(yǔ)句截圖如下：
耗時(shí)截圖如下：
2、profile展示
實(shí)際上這里的query end是一個(gè)非常有用的信息，基本確認(rèn)是在order_commit函數(shù)上的等待。
二、問(wèn)題初次分析
在我遇到的案例中有大事物造成的小事物commit慢的情況，且狀態(tài)也是query end，但是這里問(wèn)題顯然不太一樣，如果是大事物造成的會(huì)是偶爾出現(xiàn)commit慢的情況而這里是穩(wěn)定出現(xiàn)等待1秒的情況。但是我還是要朋友采集了binlog的大事物信息使用我的一個(gè)工具如下:
小工具可以分析binlog 的一些信息比如： 1、是否有長(zhǎng)期未提交的事物 2、是否有大事物 3、每個(gè)表生成了多少日志 4、生成速度。 使用: ./infobin mysql-bin.001793 20 2000000 10 -t >log1793.log第一個(gè)20 是分片數(shù)量 第二個(gè)2000000 是大于2M左右的事物定義為大事物 第三個(gè)10 是大于10秒未提交的事物定義為長(zhǎng)期未提交的事物 下載地址: http://pan.baidu.com/s/1jHIWUN0只能用于binlog 不能用于relaylog。最好將binlog拷貝其他機(jī)器執(zhí)行，不要在生產(chǎn)服務(wù)器跑 最好是5.6 5.7 row格式binlog這個(gè)工具是我用C寫(xiě)的不依賴其他工具解析binlog獲取有用信息的工具，也很多朋友在用。占時(shí)沒(méi)有開(kāi)源，其實(shí)也很簡(jiǎn)單就是分析binlog的event來(lái)獲取有用信息。
得到的簡(jiǎn)化結(jié)果如下:
實(shí)際上我們很容易看到binlog整個(gè)才80M左右確實(shí)包含一個(gè)大事物如下,大約占用了50M多
--Large than 2000000(bytes) trx: (1)Trx_size:54586527(bytes)[53307.156(kb)] trx_begin_p:359790[0X57D6E] trx_end_p:54946317[0X3466A0D] Total large trx count size(kb):#53307.156(kb)但是大事物只會(huì)在提交的那一刻影響其他事物的提交且狀態(tài)為query end參考我早期的一篇文章
http://blog.itpub.net/7728585/viewspace-2133674/
我們先排除大事物導(dǎo)致的的問(wèn)題。那么到底是什么問(wèn)題呢，有朋友說(shuō)可能是半同步，但是不使用半同步的情況下也一樣。且我覺(jué)得半同步的導(dǎo)致慢的狀態(tài)應(yīng)該不是query end 占時(shí)沒(méi)有測(cè)試。
三、確認(rèn)問(wèn)題
沒(méi)有辦法只能使用pstack進(jìn)行分析，幸運(yùn)的是這個(gè)問(wèn)題確實(shí)簡(jiǎn)單如下的pstack棧幀：
顯然我的猜測(cè)沒(méi)有問(wèn)題確實(shí)是ordered_commit上出的問(wèn)題，直接打開(kāi)源碼找到如下：
/* Shall introduce a delay. */stage_manager.wait_count_or_timeout(opt_binlog_group_commit_sync_no_delay_count,opt_binlog_group_commit_sync_delay,Stage_manager::SYNC_STAGE);這段代碼位于flush階段之后 sync階段之前，目的在于通過(guò)人為的設(shè)置delay來(lái)加大整個(gè)group commit組的事物數(shù)量，從而減少進(jìn)行磁盤(pán)刷盤(pán)sync的次數(shù)。這塊代碼雖然以前看過(guò)但是沒(méi)用過(guò)這兩個(gè)參數(shù)也就直接跳過(guò)了。
四、stage_manager.wait_count_or_timeout函數(shù)分析和參數(shù)分析
這個(gè)函數(shù)還是非常簡(jiǎn)單如下邏輯 看注釋即可:
void Stage_manager::wait_count_or_timeout(ulong count, ulong usec, StageID stage) {ulong to_wait=DBUG_EVALUATE_IF("bgc_set_infinite_delay", LONG_MAX, usec);/*For testing purposes while waiting for inifinityto arrive, we keep checking the queue size at regular,small intervals. Otherwise, waiting 0.1 * infiniteis too long.*/ulong delta=DBUG_EVALUATE_IF("bgc_set_infinite_delay", 100000, //此處將等待時(shí)間分割 將使用 max<ulong>(1, (to_wait * 0.1))); //binlog_group_commit_sync_delay*0.1 和 1之間的 大的那個(gè)值作為時(shí)間分割 (單位 1/1000000 秒)//binlog_group_commit_sync_delay是 (1000000)1秒則時(shí)間分割為0.1s(100000)while (to_wait > 0 && (count == 0 || static_cast<ulong>(m_queue[stage].get_size()) < count)) //進(jìn)行主體循環(huán)退出條件為 1、binlog_group_commit_sync_delay設(shè)置的時(shí)間消耗完{ //2本組事物數(shù)量>binlog_group_commit_sync_no_delay_count my_sleep(delta);//每次休眠delta時(shí)間如果是1秒則每次休眠0.1秒to_wait -= delta;//進(jìn)行總時(shí)間-delta 時(shí)間 } }從源碼我們分析一下參數(shù)binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count的含義:
- binlog_group_commit_sync_delay：通過(guò)人為的設(shè)置delay來(lái)加大整個(gè)group commit組的事物數(shù)量，從而減少進(jìn)行磁盤(pán)刷盤(pán)sync的次數(shù)，但是受到binlog_group_commit_sync_no_delay_count的限制,單位1/1000000秒。最大值1000000也就是1秒
- binlog_group_commit_sync_no_delay_count：如果delay的時(shí)間內(nèi)如果group commit中的事物數(shù)量達(dá)到了這個(gè)設(shè)置就直接跳出等待，而不需要等待binlog_group_commit_sync_delay的時(shí)間,單位group commit中事物的數(shù)量。
舉個(gè)列子比如我binlog_group_commit_sync_delay設(shè)置為10，binlog_group_commit_sync_no_delay_count設(shè)置為10，整個(gè)group commit將在這里等待，達(dá)到2個(gè)條件中的1個(gè)將會(huì)退出等待:
- 等待達(dá)到了1/100000 秒
- group commit中事物數(shù)量達(dá)到了10
四、問(wèn)題庫(kù)設(shè)置
最后叫朋友查看了他們庫(kù)的設(shè)置如下:
居然binlog_group_commit_sync_delay設(shè)置為了最大值1000000也就是1秒，這也就解釋了為什么簡(jiǎn)單的insert都會(huì)等待1秒了，且狀態(tài)為query end。
五、總結(jié)
- 整個(gè)問(wèn)題的排除最終還是依賴的pstack，這也再一次體現(xiàn)了它的重要性。棧幀是不會(huì)騙人的只有不懂的
- 要對(duì)query end代表的什么比較清楚
- 至此我知道了2種query end(或者顯示commit為starting)狀態(tài)下小事物提交慢的可能
1、某個(gè)大事物提交引起偶爾的提交慢
2、binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count 設(shè)置不正確引起提交慢
這個(gè)問(wèn)題是來(lái)自一位朋友@春波，我通過(guò)pstack最終確認(rèn)問(wèn)題，涉及到兩個(gè)參數(shù)的設(shè)置，我將從源碼進(jìn)行解釋，如果有誤還請(qǐng)見(jiàn)諒。
一、問(wèn)題展示
1、簡(jiǎn)單插入需要1秒
語(yǔ)句截圖如下：
耗時(shí)截圖如下：
2、profile展示
實(shí)際上這里的query end是一個(gè)非常有用的信息，基本確認(rèn)是在order_commit函數(shù)上的等待。
二、問(wèn)題初次分析
在我遇到的案例中有大事物造成的小事物commit慢的情況，且狀態(tài)也是query end，但是這里問(wèn)題顯然不太一樣，如果是大事物造成的會(huì)是偶爾出現(xiàn)commit慢的情況而這里是穩(wěn)定出現(xiàn)等待1秒的情況。但是我還是要朋友采集了binlog的大事物信息使用我的一個(gè)工具如下:
小工具可以分析binlog 的一些信息比如： 1、是否有長(zhǎng)期未提交的事物 2、是否有大事物 3、每個(gè)表生成了多少日志 4、生成速度。 使用: ./infobin mysql-bin.001793 20 2000000 10 -t >log1793.log第一個(gè)20 是分片數(shù)量 第二個(gè)2000000 是大于2M左右的事物定義為大事物 第三個(gè)10 是大于10秒未提交的事物定義為長(zhǎng)期未提交的事物 下載地址: http://pan.baidu.com/s/1jHIWUN0只能用于binlog 不能用于relaylog。最好將binlog拷貝其他機(jī)器執(zhí)行，不要在生產(chǎn)服務(wù)器跑 最好是5.6 5.7 row格式binlog這個(gè)工具是我用C寫(xiě)的不依賴其他工具解析binlog獲取有用信息的工具，也很多朋友在用。占時(shí)沒(méi)有開(kāi)源，其實(shí)也很簡(jiǎn)單就是分析binlog的event來(lái)獲取有用信息。
得到的簡(jiǎn)化結(jié)果如下:
實(shí)際上我們很容易看到binlog整個(gè)才80M左右確實(shí)包含一個(gè)大事物如下,大約占用了50M多
--Large than 2000000(bytes) trx: (1)Trx_size:54586527(bytes)[53307.156(kb)] trx_begin_p:359790[0X57D6E] trx_end_p:54946317[0X3466A0D] Total large trx count size(kb):#53307.156(kb)但是大事物只會(huì)在提交的那一刻影響其他事物的提交且狀態(tài)為query end參考我早期的一篇文章
http://blog.itpub.net/7728585/viewspace-2133674/
我們先排除大事物導(dǎo)致的的問(wèn)題。那么到底是什么問(wèn)題呢，有朋友說(shuō)可能是半同步，但是不使用半同步的情況下也一樣。且我覺(jué)得半同步的導(dǎo)致慢的狀態(tài)應(yīng)該不是query end 占時(shí)沒(méi)有測(cè)試。
三、確認(rèn)問(wèn)題
沒(méi)有辦法只能使用pstack進(jìn)行分析，幸運(yùn)的是這個(gè)問(wèn)題確實(shí)簡(jiǎn)單如下的pstack棧幀：
顯然我的猜測(cè)沒(méi)有問(wèn)題確實(shí)是ordered_commit上出的問(wèn)題，直接打開(kāi)源碼找到如下：
/* Shall introduce a delay. */stage_manager.wait_count_or_timeout(opt_binlog_group_commit_sync_no_delay_count,opt_binlog_group_commit_sync_delay,Stage_manager::SYNC_STAGE);這段代碼位于flush階段之后 sync階段之前，目的在于通過(guò)人為的設(shè)置delay來(lái)加大整個(gè)group commit組的事物數(shù)量，從而減少進(jìn)行磁盤(pán)刷盤(pán)sync的次數(shù)。這塊代碼雖然以前看過(guò)但是沒(méi)用過(guò)這兩個(gè)參數(shù)也就直接跳過(guò)了。
四、stage_manager.wait_count_or_timeout函數(shù)分析和參數(shù)分析
這個(gè)函數(shù)還是非常簡(jiǎn)單如下邏輯 看注釋即可:
void Stage_manager::wait_count_or_timeout(ulong count, ulong usec, StageID stage) {ulong to_wait=DBUG_EVALUATE_IF("bgc_set_infinite_delay", LONG_MAX, usec);/*For testing purposes while waiting for inifinityto arrive, we keep checking the queue size at regular,small intervals. Otherwise, waiting 0.1 * infiniteis too long.*/ulong delta=DBUG_EVALUATE_IF("bgc_set_infinite_delay", 100000, //此處將等待時(shí)間分割 將使用 max<ulong>(1, (to_wait * 0.1))); //binlog_group_commit_sync_delay*0.1 和 1之間的 大的那個(gè)值作為時(shí)間分割 (單位 1/1000000 秒)//binlog_group_commit_sync_delay是 (1000000)1秒則時(shí)間分割為0.1s(100000)while (to_wait > 0 && (count == 0 || static_cast<ulong>(m_queue[stage].get_size()) < count)) //進(jìn)行主體循環(huán)退出條件為 1、binlog_group_commit_sync_delay設(shè)置的時(shí)間消耗完{ //2本組事物數(shù)量>binlog_group_commit_sync_no_delay_count my_sleep(delta);//每次休眠delta時(shí)間如果是1秒則每次休眠0.1秒to_wait -= delta;//進(jìn)行總時(shí)間-delta 時(shí)間 } }從源碼我們分析一下參數(shù)binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count的含義:
- binlog_group_commit_sync_delay：通過(guò)人為的設(shè)置delay來(lái)加大整個(gè)group commit組的事物數(shù)量，從而減少進(jìn)行磁盤(pán)刷盤(pán)sync的次數(shù)，但是受到binlog_group_commit_sync_no_delay_count的限制,單位1/1000000秒。最大值1000000也就是1秒
- binlog_group_commit_sync_no_delay_count：如果delay的時(shí)間內(nèi)如果group commit中的事物數(shù)量達(dá)到了這個(gè)設(shè)置就直接跳出等待，而不需要等待binlog_group_commit_sync_delay的時(shí)間,單位group commit中事物的數(shù)量。
舉個(gè)列子比如我binlog_group_commit_sync_delay設(shè)置為10，binlog_group_commit_sync_no_delay_count設(shè)置為10，整個(gè)group commit將在這里等待，達(dá)到2個(gè)條件中的1個(gè)將會(huì)退出等待:
- 等待達(dá)到了1/100000 秒
- group commit中事物數(shù)量達(dá)到了10
四、問(wèn)題庫(kù)設(shè)置
最后叫朋友查看了他們庫(kù)的設(shè)置如下:
居然binlog_group_commit_sync_delay設(shè)置為了最大值1000000也就是1秒，這也就解釋了為什么簡(jiǎn)單的insert都會(huì)等待1秒了，且狀態(tài)為query end。
五、總結(jié)
- 整個(gè)問(wèn)題的排除最終還是依賴的pstack，這也再一次體現(xiàn)了它的重要性。棧幀是不會(huì)騙人的只有不懂的
- 要對(duì)query end代表的什么比較清楚
- 至此我知道了2種query end(或者顯示commit為starting)狀態(tài)下小事物提交慢的可能
1、某個(gè)大事物提交引起偶爾的提交慢
2、binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count 設(shè)置不正確引起提交慢
作者微信：
總結(jié)
以上是生活随笔為你收集整理的MySQL:简单insert 一秒原因排查的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。
- 上一篇： 路由器无线密码被人知道了怎么办-被别人知
- 下一篇： MySQL 数据库热备的操作