審計日志是RDS安全策略中非常重要的一環，它采集了數據庫中所有的訪問請求，包括常見的insert，update，delete，select，alter，drop，create語句， 還有一些比如set，commit，rollback命令語句。有了這些日志后可以幫助我們進行問題回溯，分析問題。下面這則案例講述如何使用審計日志來分析只讀實例延遲問題，如果沒有審計日志我們很難想象該問題該如何解決。 ## 問題描述： 一客戶使用了2個RDS只讀節點來承擔業務的讀流量，兩個RDS的資源規格和業務流量完全一樣，但是離奇的發現兩個只讀中有一個實例出現了延遲，讓用戶百思不得其解：  只讀Slave1出現延遲（圖一）：  只讀Slave2正常同步（圖二）：  ## 分析： 1. 從上圖監控可以看出延遲的曲線是一條直線，出現這樣的直線通常是數據庫的復制線程被block，導致slave一直無法完成與主庫的數據同步，? 比如：主庫的一個超大事務或DDL傳到備庫。 2. 但是兩個只讀實例中只有一個只讀實例出現延遲（圖二），那么需要看一下出現延遲的時候只讀實例當時的線程狀態，以此來判斷出問題所在。 ## 問題排查： * 檢查延遲只讀實例slave2在延遲期間的數據庫快照，發現數據庫中有大量的Waiting for table metadata lock 等待? （出現延遲時候可以使用show processlist將數據庫的線程狀態保存下來）：? 表：xxx_user? SQL： ~~~ SELECT user_id ...... FROM xxx_user where latest_time >= DATE_FORMAT('2016/06/15 23:40:09.000000000','%Y-%m-%d %k:%i:%s') ~~~  ### 分析： 1. 出現select等待MDL鎖的原因通常是該表上有DDL操作，在DDL操作的過程中會加上一個MDL鎖，但是如果該表上有大查詢，大事務或者未提交的事務，則會導致DDL操作無法獲得MDL鎖，進而阻塞住該表上的所有查詢。 2. 由于當前實例是只讀實例，所以DDL操作來源于主庫，所以我們看一下主庫是否真正在該表上有DDL操作。 * 從后端審計日志中果然發現在2016-06-17 00:41:17 時主庫做了一次DDL操作，但是該DDL操作執行非常快，那么很有可能DDL傳遞到只讀節點的時候，由于只讀節點上該表有一個未提交的事務或者查詢，導致DDL操作被blcok。  * 在診斷快照中發現了一個事務在2016-06-16 19:17:09 就已經開始了，所以該事務很有可能就是導致DDL無法獲取MDL鎖的根源，那我們看一下這個事務做了哪些事情，線程id：1435503。  * 查看審計日志： 通過查看審計日志發現，線程id：1435503最后一次設置autocommit=0，時間是在16-06-16 14:10:03，之后對xx_user這個表執行了一個select，時間是在2016-06-16 19:17:09，但是一直沒有提交，所以就是這個語句拿著MDL鎖，直到2016-06-16 05:08:42 被kill后才被釋放。該線程kill掉之后只讀節點的延遲迅速下降。    ## 總結： 1. 此次slave延遲的原因為只讀節點有未提交的事務導致主庫的DDL被阻塞，所以在日常做DDL的過程中一定要觀察數據庫中是否存在大查詢，大事務或者未提交的事務。 2. 善于使用show processlist來保存數據庫的快照，如果該問題出現在自建數據庫中，也是需要按照上述的方法進行排查，但是如果沒有RDS的審計日志，排查問題起來會非常麻煩，可以通過審計日志去發現RDS中執行過的是有SQL，RDS不是黑盒子。 3. 只讀實例延遲排查常見思路：一看資源是否達到瓶頸；二看線程狀態是否有鎖；三判斷是否存在大事務或未提交的事務。 4. 要注意set autocommit=0的使用，一定要在語句結束后顯式commit掉，不然會導致數據庫中存在長時間未提交的事務，進而引發很多潛在的問題。 5. 為了審計以及排查問題方便，建議打開審計日志。