MySQL:簡單insert 一秒原因排查

這個問題是來自一位朋友@春波，我通過pstack最終确認問題，涉及到兩個參數的設定，我将從源碼進行解釋，如果有誤還請見諒。

語句截圖如下：

耗時截圖如下：

2、profile展示

實際上這裡的query end是一個非常有用的資訊，基本确認是在order_commit函數上的等待。

在我遇到的案例中有大事物造成的小事物commit慢的情況，且狀态也是query end，但是這裡問題顯然不太一樣，如果是大事物造成的會是偶爾出現commit慢的情況而這裡是穩定出現等待1秒的情況。但是我還是要朋友采集了binlog的大事物資訊使用我的一個工具如下:

這個工具是我用C寫的不依賴其他工具解析binlog擷取有用資訊的工具，也很多朋友在用。占時沒有開源，其實也很簡單就是分析binlog的event來擷取有用資訊。

得到的簡化結果如下:

實際上我們很容易看到binlog整個才80M左右确實包含一個大事物如下,大約占用了50M多

但是大事物隻會在送出的那一刻影響其他事物的送出且狀态為query end參考我早期的一篇文章

<a href="http://blog.itpub.net/7728585/viewspace-2133674/">http://blog.itpub.net/7728585/viewspace-2133674/</a>

我們先排除大事物導緻的的問題。那麼到底是什麼問題呢，有朋友說可能是半同步，但是不使用半同步的情況下也一樣。且我覺得半同步的導緻慢的狀态應該不是query end 占時沒有測試。

沒有辦法隻能使用pstack進行分析，幸運的是這個問題确實簡單如下的pstack棧幀：

顯然我的猜測沒有問題确實是ordered_commit上出的問題，直接打開源碼找到如下：

這段代碼位于flush階段之後 sync階段之前，目的在于通過人為的設定delay來加大整個group commit組的事物數量，進而減少進行磁盤刷盤sync的次數。這塊代碼雖然以前看過但是沒用過這兩個參數也就直接跳過了。

這個函數還是非常簡單如下邏輯 看注釋即可:

從源碼我們分析一下參數binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count的含義:

binlog_group_commit_sync_delay：通過人為的設定delay來加大整個group commit組的事物數量，進而減少進行磁盤刷盤sync的次數，但是受到binlog_group_commit_sync_no_delay_count的限制,機關1/1000000秒。最大值1000000也就是1秒

binlog_group_commit_sync_no_delay_count：如果delay的時間内如果group commit中的事物數量達到了這個設定就直接跳出等待，而不需要等待binlog_group_commit_sync_delay的時間,機關group commit中事物的數量。

舉個列子比如我binlog_group_commit_sync_delay設定為10，binlog_group_commit_sync_no_delay_count設定為10，整個group commit将在這裡等待，達到2個條件中的1個将會退出等待:

等待達到了1/100000 秒

group commit中事物數量達到了10

最後叫朋友檢視了他們庫的設定如下:

居然binlog_group_commit_sync_delay設定為了最大值1000000也就是1秒，這也就解釋了為什麼簡單的insert都會等待1秒了，且狀态為query end。

整個問題的排除最終還是依賴的pstack，這也再一次展現了它的重要性。棧幀是不會騙人的隻有不懂的

要對query end代表的什麼比較清楚

至此我知道了2種query end(或者顯示commit為starting)狀态下小事物送出慢的可能

1、某個大事物送出引起偶爾的送出慢

2、binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count 設定不正确引起送出慢

作者微信：