Linux 6中Cachefilesd服務過量日誌問題解決

我們在實際營運環境中，對作業系統OS的維護是必須進行的。應用系統是一個整體，絕對不僅僅包括應用伺服器上啟動並執行應用程式本身和資料庫伺服器，還包括作業系統、網路、儲存甚至硬體方面。對應用系統整體的監控保障，才能帶來最穩定的運行效能。
 
絕大多數情況下，我們環境中的作業系統都是可以持續啟動並執行，不會引起大的問題。一旦出現當機、伺服器Hange住的情況，就可能導致災難性的結果。所以，亡羊補牢不如防微杜漸，經常性的查看系統運行情況，查看磁碟空間、CPU使用率和各種日誌資訊，都可以儘早協助我們解決作業系統層面問題。
 
本篇介紹一個簡單的Linux進程Bug解決問題。

 

1、問題介紹

 

一個接受的新系統，應用伺服器和資料庫伺服器均為Linux 6版本。系統本身架構比較簡單，而且運行一年來也沒有什麼嚴重故障發生。

 

[root@TESTDB ~]# uname -r

2.6.32-131.0.15.el6.x86_64

[root@TESTDB ~]# cat /etc/RedHat-release

Red Hat Enterprise Linux Server release 6.1 (Santiago)

[root@TESTDB ~]# uptime

 11:28:14 up 66 days, 21:31,  1 user,  load average: 0.50, 0.44, 0.37 –有例行關機維護

 

Linux環境中，最常見日誌為/var/log目錄，檢查message是我們直接的日誌檢查策略。

 

[root@TESTDB ~]# tail -n 10 /var/log/messages

Mar 26 08:31:42 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:32:12 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:32:42 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:33:12 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:33:42 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:34:12 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:34:42 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:35:12 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:35:42 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:36:12 TESTDB cachefilesd[1591]: Scan complete

 

日誌量很大，從每周自動歸檔情況看，日誌總量大已經持續比較長時間了。

 

[root@TESTDB ~]# cd /var/log/

[root@TESTDB log]# ls -l | grep message

-rw-------. 1 root        root        549637 Mar 26 08:55 messages

-rw-------. 1 root        root        1193545 Mar  2 03:31 messages-20140302

-rw-------. 1 root        root        1191893 Mar  9 03:16 messages-20140309

-rw-------. 1 root        root        1194902 Mar 16 03:27 messages-20140316

-rw-------. 1 root        root        1195079 Mar 23 03:39 messages-20140323

 

從日誌上看，服務進程cachefilesd在每隔30s，自動寫入一條記錄。除了日誌過多冗餘條目外，沒有其他問題爆出。

message資訊本身是中性的，通知調錯類資訊。過於頻繁的正常資訊在其中，是容易將錯誤內容淹沒其中的。所以期望還是可以加以解決。

 

2、故障分析

 

我們遇到的故障錯誤是分種類的。一個極端是緊急嚴重，比如作業系統宕機、hang住無響應，直接影響業務運行，甚至資料丟失。另一個極端就是一些短期不會引起大問題的“小故障”。緊急嚴重錯誤考驗的是營運人員的知識、經驗和心理素質，而小故障考驗的職業精神和專業素質。
 
對於這個問題，筆者也沒有什麼很好地思路，只有求助官方資料庫。在Red Hat官網的客戶訂閱中，筆者找到了文章《Why server is flodded with `cachefilesd Scan complete` messages?》其中描述了相同的問題。
 
Cachefilesd進程是負責進行網路檔案系統的檔案和目錄緩衝管理的，比如AFS和NFS這類網路檔案系統，需要在本地系統中存在一個Cache對象。這個問題是由於cachefilesd服務自身的bug造成的，由於內部設定了錯誤的記錄層級（log level）。所以每次cachefilesd在工作進行Scan的時候，都會寫入到/var/log/messages記錄檔裡面。
 
這個問題已經被Red Hat列入為Bug，編號為680127。cachefilesd是作為作業系統的一個後台服務進行工作的。當'/var/cache/fscache/cache'為空白的的時候，就會自動將Scan Completed資訊寫入到日誌中。
 
根據頻率，每分鐘會進行兩條日誌的寫入。這個和我們實際系統的情況相符合。

版本是Linux 6，cachefilesd包版本為0.10.1-2。查看當前系統版本情況。

 

[root@TESTDB ~]# rpm -qa | grep cachefilesd

cachefilesd-0.10.1-2.el6.x86_64

 

修複方法是將cachefilesd版本升級到最新版本，就可以避免問題出現。

 

3、問題解決

 

定位到了問題，解決方案策略就是升級cachefilesd包。從官方網站上搜尋專門的rpm包下載，目錄如下：

 

 

 

下載最新的版本0.10.2.1。使用rpm進行安裝。

 

[root@TESTDB ~]# cd /

[root@TESTDB /]# mkdir updates

[root@TESTDB /]# cd updates

[root@TESTDB updates]# ls -l

total 36

-rw-r--r--. 1 root root 35332 Mar 26 08:52 cachefilesd-0.10.2-1.el6.x86_64.rpm

 

參數-Uvh會去自己判斷目前的版本情況，如果是沒有對應程式就直接安裝，否則就進入升級模式。

 

[root@TESTDB updates]# rpm -Uvh cachefilesd-0.10.2-1.el6.x86_64.rpm

warning: cachefilesd-0.10.2-1.el6.x86_64.rpm: Header V3 RSA/SHA256 Signature, key ID fd431d51: NOKEY
 
Preparing...                ########################################### [100%]

  1:cachefilesd            ########################################### [100%]

 

最後檢查效果，日誌中包括了cachefilesd服務終止重啟的過程。重啟之後，就再沒有新記錄項目產生。

 

Mar 26 08:55:12 TESTDB cachefilesd[1591]: Scan complete

Mar 26 08:55:21 TESTDB cachefilesd[1591]: Daemon Terminated

Mar 26 08:55:21 TESTDB kernel: CacheFiles: File cache on sda3 unregistering

Mar 26 08:55:21 TESTDB kernel: FS-Cache: Withdrawing cache "mycache"

Mar 26 08:55:21 TESTDB cachefilesd[10518]: About to bind cache

Mar 26 08:55:21 TESTDB cachefilesd[10518]: Bound cache

Mar 26 08:55:21 TESTDB kernel: FS-Cache: Cache "mycache" added (type cachefiles)
 
Mar 26 08:55:21 TESTDB kernel: CacheFiles: File cache on sda3 registered

Mar 26 08:55:21 TESTDB cachefilesd[10519]: Daemon Started

 

作為服務的cachefilesd，也工作正常。

 

[root@TESTDB ~]# service cachefilesd status

cachefilesd (pid  10519) is running...

[root@TESTDB ~]# chkconfig --list cachefilesd

cachefilesd    0:off  1:off  2:on    3:on    4:on    5:on    6:off

 

故障解決。

 

4、結論

 

在實際營運環境中，各種故障都是可能發生的。而且診斷問題、解決問題需要很多經驗的積累和總結。及時發現問題、防微杜漸是保障系統持續健康啟動並執行最好保障。“救火隊員”不如“老黃牛”，也就是這個道理。