MySQL慢日誌佔滿磁碟空間導致業務主庫宕機解決

MySQL · 發表 2018-09-25 20:01:58

摘要：在MySQL的日常維護中，我們總會遇到這樣或那樣的問題，對於那些經常發生且有處理經驗的事故，不論是新手還是老司機都能在故障規定的容錯時間內解決。而對於那些不常見、比較棘手的問題，新手上路可能就顯得舉足無措了，這個時候新手和老司機的差距就體現出來了。從知識儲備還是工作經驗，可能老司機比新手強一點...

在SQL/">MySQL的日常維護中，我們總會遇到這樣或那樣的問題，對於那些經常發生且有處理經驗的事故，不論是新手還是老司機都能在故障規定的容錯時間內解決。而對於那些不常見、比較棘手的問題，新手上路可能就顯得舉足無措了，這個時候新手和老司機的差距就體現出來了。從知識儲備還是工作經驗，可能老司機比新手強一點，但如果一個新司機沒有日誌排錯的意識，不具備日誌排錯的經驗，那怎麼能學會彎道超車、漂移的快感。我們知道資料庫中有很多重要的日誌，如錯誤日誌error log、慢日誌slow log、二進位制日誌binary log、查詢日誌general log等等其他日誌，錯誤日誌error log是我們分析問題參考的依據，它記錄資料庫的啟動/執行/停止的過程，包含了info、warning、error三個級別，分析error log也有助於我們瞭解資料庫的執行機制。

我們知道資料庫中的binary log、relay log都是資料庫本身自帶的purge清理執行緒處理過時的沒有用的日誌，這種處理能有效釋放磁碟空間。而對於慢日誌slow log、錯誤日誌error log這種記錄資料庫例項整個執行階段的日誌，不會被定期處理，那麼就有可能會被記錄得過多，佔據過多的磁碟空間。對於錯誤日誌error log，預設記錄；對於slow log需要我們自己選擇是否記錄。建議開啟slow log功能，這對於資料庫優化之一的SQL優化有很大的幫助。

通常我們在業務主庫是開啟慢日誌功能並通過引數long_query_time這個引數來控制執行時間多長的SQL被記錄進慢日誌中，且對於執行時間超過1s的SQL就認為是慢SQL，這樣的設定值，很多場合下不會記錄太多的慢SQL，因而不會佔據太多的磁碟空間。然而當開發上線的程式有問題，SQL執行效率不高，且執行的頻率非常高，這些慢SQL被記錄就會存在磁碟空間被撐爆的安全隱患，從而導致資料庫宕機並嘗試重啟且多次嘗試失敗，嚴重影響業務。不過值得慶幸的是，該部分業務我們有MMM高可用架構，VIP已經漂移到另一臺master上了。

2018-05-29 09:09:18 28094 [ERROR] Error writing file '/opt/app/mysql/logs/slow.log' (errno: 1 - No space left on device)

180529 09:09:19 mysqld_safe mysqld restarted

InnoDB: 3 transaction(s) which must be rolled back or cleaned up

InnoDB: Starting in background the rollback of uncommitted transactions

/opt/app/mysql/bin/mysqld: Error writing file '/opt/app/mysql/logs/slow.log' (Errcode: 28 - No space left on device)

2018-05-29 09:09:33 33114 [ERROR] Could not open /opt/app/mysql/logs/slow.log for logging (error 28). Turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.

2018-05-29 09:09:34 33114 [ERROR] /opt/app/mysql/bin/mysqld: Error writing file '/opt/app/mysql/tmp/mysqld.pid' (Errcode: 28 - No space left on device)

2018-05-29 09:09:34 33114 [ERROR] Can't start server: can't create PID file: No space left on device

如上面的報錯顯示（只是選擇擷取部分錯誤日誌），資料庫發生錯誤的原因是磁碟沒有足夠的空間，慢日誌無法寫入，資料庫嘗試restart並rollback沒有提交的事務（繼續檢視後面的日誌能看到redo log的資訊），而資料庫也對我們提出了建議關閉錯誤日誌的記錄功能。繼續看啟動過程，發現關於pid檔案的No space left on device，資料庫還是無法啟動。排查故障並處理故障，在儘可能短的時間內恢復業務是最重要的，因而這裡就沒有詳細的操作程式碼儲存來說明。通過df -Th檢視發現/空間不足，並ls -lh檢視慢日誌的大小是1.2T，已經嚴重消耗了磁碟空間。這個時候我們並不能直接rm -rf刪除慢日誌檔案，因為資料庫的啟動時需要慢日誌功能切且日誌檔案佔據了磁碟空間，我們只能重定向清空慢日誌，這樣資料庫得以重新啟動。

雖然我們的業務主庫有MMM高可用架構，事實發現VIP確實是漂移到另一臺master上，但仍然給我們的其他slave造成了複製同步錯誤的故障，更為嚴重的是影響到了我們的多源複製庫的使用，內部人員使用和維護也帶來很大的影響。對於資料庫本身來講，error log和slow log不能自動清理，這有一定的優點，但同時也會有磁碟空間可能被撐爆的潛在危險。

如果能夠通過一個crontab，或者一個告警，定期或者提醒我們對慢日誌進行清理，我想也不會造成如今的這個麻煩。我們可以通過如下的一個Shell指令碼，策略是刪除幾天以前的慢日誌，保留最近幾天的慢日誌，或者使用過Inception工具的，可以將慢日誌定期拉走，備份到遠端。

[root@172-16-3-190 shells]# cat clean_mysql_slow_log.sh

#!/binbash

#author=lyx

#time:2018-05-29

cur_date=`date +%y%m%d`

#step_days=5 #clean slowlog 6 days ago

for step_days in $(seq 5 -1 0)

end_date=`expr $cur_date - $step_days`

clean_line_num=`cat /opt/shells/slow.log |grep -n "^# Time: $end_date"|head -n 1|cut -d : -f 1`

if ((${#clean_line_num} > 1))

then

clean_max_line_num=`expr $clean_line_num - 1`

sed -i "1,$clean_max_line_num d" /opt/shells/slow.log

break

done

echo $clean_max_line_num

echo $step_days

該指令碼的策略是根據當前時間，保留最近5天的慢日誌，每次執行指令碼則保留的日誌天數減少一天。當然如果你有更好的業務策略或者指令碼邏輯也可以擇優選擇，比如你可以根據慢日誌的檔案大小，配置告警並觸發清理，或者crontab都可以。