一、案例分享

1.1 問題描述

大查詢長時間執行無法釋放DML讀鎖，後續同步主庫的DDL操作擷取DML寫鎖資源被阻塞等待，導緻後續同步主庫的操作堆積，主從延遲增長嚴重。從同步延遲的監控來看，延遲從17:11開始，17:51:59進行kill大查詢操作，直到17:53建議業務方将大查詢kill掉後才結束。

1.2 處理流程

1、當接收到隻讀執行個體的同步延遲告警後，登入到RDS的管理控制台檢視執行個體目前會話執行情況，判斷隻讀執行個體目前負載壓力。從目前會話截圖可以看到，會話并無明顯堆積，但是有兩個執行時間很久的大查詢操作。

2、17:11延遲開始，17:51 kill大查詢，17:53主從延遲恢複。我們仍需要排查這個期間主執行個體和隻讀執行個體的運作情況，分析造成主從延遲的具體原因

3、對主執行個體的排查

1）檢視延遲期間主庫是否有一些批處理/大事務操作，主庫業務業務請求上漲或者有批量的更新操作。對此，我們主要觀察主執行個體的QPS/TPS監控、MySQL_COMDML和日志讀寫的監控名額。

從以上截圖中可以看到，主庫TPS在主從延遲期間并沒有明顯的上漲，說明期間主庫業務壓力正常；主庫MySQL_COMDML和日志讀寫在主從延遲期間也沒有明顯的上漲，說明期間主庫也沒有執行一些批量更新的大事務操作。

2）檢視延遲期間主庫是否有執行消耗較大的DDL操作。在RDS中若開啟了審計日志，我們可以通過時間以及操作類型進行過濾排查

通過對審計日志的搜尋，我們搜查到一條對視圖定義進行alter的操作，該alter操作僅僅執行了2.32ms，其資源消耗本身并不大。

4、對隻讀執行個體的排查

1）檢視延遲期間隻讀執行個體是否有較大負載壓力，從隻讀執行個體延遲期間的會話執行情況以及資源消耗可以知道，延遲期間隻讀執行個體并無較大負載壓力

2）從隻讀執行個體的QPS/TPS監控中可以看到，17:51kill掉大查詢後隻讀執行個體的TPS異常上漲，17:53TPS恢複正常，延遲恢複。說明17:51～17:53期間隻讀執行個體在大量應用主庫傳輸過來的binlog日志，恢複主從複制延遲。

5、捕捉延遲期間會話中的異常現象，大查詢長時間執行未結束，執行explain操作顯示為MDL鎖等待，結合我們在主庫審計日志中搜尋到的alter操作，我們可以推斷造成主從延遲的原因可能是隻讀執行個體大查詢阻塞了從主庫傳輸過來的Alter操作，導緻後續延遲一直上漲，并在我們kill掉大查詢後恢複。

6、為了印證我們的猜想，我們通過審計日志把相關操作的時間線進行梳理

隻讀執行個體view_order_logistics_new相關的大查詢執行了3602s還未執行完，一直持有表的DML讀鎖，不影響表的正常讀寫操作
17:10 主庫執行了ALTER ALGORITHM=UNDEFINED DEFINER=super_sha_prd_db@% SQL SECURITY DEFINER VIEW view_order_logistics_new 的操作
隻讀執行個體view_order_logistics_new的大查詢仍在執行中，此時主庫執行alter操作傳輸到隻讀執行個體，alter操作需要的DML寫鎖與大查詢持有的DML讀鎖沖突
alter操作無法擷取到DML寫鎖進而開始等待鎖資源，從主要傳輸過來的binlog也被阻塞，主從延遲開始上漲
17:51:59 隻讀執行個體kill掉了view_order_logistics_new的大查詢，隻讀執行個體TPS上漲，隻讀執行個體開始應用alter操作之後的所有binlog日志
17:53:08 隻讀執行個體TPS恢複，應用延遲期間的binlog完畢，主從複制恢複正常

更多技術資訊請檢視雲掣官網

MySQL|主從延遲問題排查（一）一、案例分享