資料庫核心月報 － 2015 / 06-MySQL · 捉蟲動态 · 任性的 normal shutdown

在rds生産環境中，一個mysql執行個體莫名地被shutdown了, 日志中有如下資訊：

以下日志是 rds 執行個體特有的日志，rds執行個體會将使用者的重要操作記錄在錯誤日志中。

從日志可以看出：

執行個體是正常關閉的

使用者在極短的時間内執行了多次shutdown指令

首先我們來檢視使用者userxx資訊，比較奇怪的是，使用者userxx為普通使用者，并沒有執行shutdown的權限。

第一感覺很可能是mysql權限子產品出現了bug, 導緻普通使用者也可以執行shutdown指令。于是在一個測試執行個體上，建立相同權限的同名使用者，驗證發現userxx确實沒有權限執行shutdown指令。

進一步從源碼中來分析，查找源碼中所有可能執行shutdown的路徑。從源碼中掃描com_shutdown 出現的地方,于是在<code>dispatch_command</code>函數中發現一處比較可疑的地方，代碼如下：

mysql 每次執行一條指令前，會擷取一個系統目前時間(<code>thd-&gt;set_time()</code>)，如果擷取的時間不合法(超過2038年或小于0），那麼此條指令會自動轉為shutdown指令。

如果使用者多個連接配接并發執行指令，并且擷取的時間不合法，那麼每個連接配接都會執行shutdown指令，這和我們前面看到的日志中的現象很吻合。

看來問題集中在為什麼擷取時間會不合法？

最可能的原因是目前主機系統時間設定超過了2038, 于是檢視系統時間，然而并沒有如我們所願，系統時間是正常的。

最後我們從系統日志中發現了端倪，

差不多在同一時刻系統出現較多的軟中斷，導緻擷取系統時間出現錯誤，即超過2038年或小于0。

從錯誤日志中我們表面上看到普通使用者執行了shutdown指令，這個帶來了疑惑和誤導。是以我們做了如下改進：

此種情況下，在錯誤日志中列印詳細的日志資訊，說明shutdown是由于時間擷取錯誤導緻；

增加重試機制，在第一次擷取時間不合法情況下，不直接執行shutdown，而是增加重試重新擷取時間，如果還是不合法，再執行shutdown。