天天看點

Mysql Slaves_Mysql slave 延遲故障一列

首先還是給出我見過的一些延遲可能:

大事物延遲 延遲略為2*執行時間 狀态為:reading event from the relay log

大表DDL延遲 延遲略為1*執行時間 狀态為:altering table

長期未送出的事物延遲,會造成延遲的瞬時增加

表上沒有主鍵或者唯一鍵 狀态為:system lock 或者 reading event from the relay log

innodb層鎖造成延遲 狀态為:system lock 或者 reading event from the relay log

從庫參數設定如sync_binlog,sync_relay_log,innodb_flush_log_at_trx_commit等參數

一、故障描述

本案例是一個朋友的,從各方面進行展示故障

按照他的描述是在主庫進行了大量形如delete from where col='';的操作,每次delete會删除大量的行。主庫删除并不慢,但是從庫追不上。

下面是現象:

延遲較大且無好轉迹象

Mysql Slaves_Mysql slave 延遲故障一列

image.png

系統整體負載不高但是mysqld程序100%

Mysql Slaves_Mysql slave 延遲故障一列

image.png

無I/O壓力

Mysql Slaves_Mysql slave 延遲故障一列

image.png

有大事物的存在

Mysql Slaves_Mysql slave 延遲故障一列

image.png

這裡這個5G是binlog的拷貝。

二、故障初次分析

首先我們要明白沒有I/O壓力代表了什麼,沒有I/O壓力代表了我們常說的fsync沒有壓力,對應的不會是下面幾個參數的問題:

sync_binlog

sync_relay_log

innodb_flush_log_at_trx_commit

也就是跟I/O相關的調整我們是不需要考慮的。

我們再來看CPU的問題,用top -HU可以看到線程的資源消耗如下:

Mysql Slaves_Mysql slave 延遲故障一列

image.png

我們可以清楚的看到某個MySQL線程耗用CPU為100%,因為是5.7我們可以友善的使用語句

select a.thd_id,b.THREAD_OS_ID,a.user ,a.conn_id,b.TYPE,a.source,a.program_name from sys.processlist a,performance_schema.threads b where b.thread_id=a.thd_id;

找到MySQL線程和作業系統的對應關系如下:

Mysql Slaves_Mysql slave 延遲故障一列

image.png

我們可以清楚看到是我們的SQL_THREAD,是以我們找到的根源是SQL_THREAD耗用了過多的CPU資源但是I/O并不是問題。

三、故障再次分析

一般來講我們遇到SQL_THREAD可能伴随着I/O問題,但是這裡并沒有,是以瓶頸可能在緩存資料的查找方面。我們使用perf進行一下分析排名靠前的如下:

Mysql Slaves_Mysql slave 延遲故障一列

image.png

其中btr_search_guess_on_hash适合AHI自适應的hash索引相關的函數,而rec_get_offsets_func是對索引的每個flied進行定位的函數(當然我也沒仔細看過源碼隻是看了一下所在的檔案位置和函數描述資訊),也就是他們貌似都是二級索引資料的查找有關,我們再來看這個表的表結構如下:

Mysql Slaves_Mysql slave 延遲故障一列

image.png

我們發現這個表除了二級索引并沒有主鍵,問題基本已經定位,也就是我開始給除的延遲中的一條:

表上沒有主鍵或者唯一鍵 狀态為:system lock 或者 reading event from the relay log

是以原因可能就是,因為沒有主鍵或者唯一鍵,event回放的時候使用到了二級索引讓回放速度慢且進行了大量的記憶體資料查找造成了CPU 100%而沒有I/O的現象。

四、問題解決

也就是對本表加一個自增字段作為主鍵,速度馬上提高了。當然這個解決辦法其實我很最早就猜測到了,但是我想盡量找到為什麼會這樣。perf中的函數具體的邏輯等我學習AHI的在分析。呵呵呵呵!

作者微信:

Mysql Slaves_Mysql slave 延遲故障一列