天天看點

崩潰了,淩晨兩點銀行系統出現Too many open fils問題!

作者:從程式員到架構師
崩潰了,淩晨兩點銀行系統出現Too many open fils問題!

分享親身經曆,剛剛上線三天的銀行ESB系統,在淩晨兩點系統監控中出現了load值飙升的情況,并且系統出現了大面積的調用失敗的情況,銀行立即啟動了備用系統,才導緻沒有發生其他的損失。半夜三點,項目經理打電話讓所有的人到銀行解決問題。

問題定位

開始的時候架構師、高工分析可能是出現了應用程式OOM的異常,是以就dump日志,檢視JVM記憶體使用情況,但是花很長時間都沒有發現有啥OOM的異常。所有的GC、堆棧日志都顯示是正常的。

并且檢視了ESB的内部監控平台,也沒有發現應用本身出現OOM的異常或者是其他告警,這就有點麻煩了。

架構師坐到電腦前面瘋狂的輸出之後,又是檢視Oracle、又是檢查伺服器的,最終發現了原來是由于封包記錄導緻了Too many open file 的錯誤資訊。這是個什麼鬼東西?

Too many open files:句柄數超過系統限制,是Linux系統中常見問題,這裡的 files 不僅是系統檔案,還包括請求連接配接 socket,端口監聽等,這是因為在Linux系統中将所有的一切都看做是一個檔案來進行處理,是以要對這些東西進行操作的話就會存在對應的檔案描述符。

問題産生的原因

經過一番排查之後,架構師吃完早餐之後,确定了問題所在,因為在ESB系統中會有封包臨時存儲的情況,在加載完臨時封包存儲之後,删除檔案的句柄沒有釋放,然後在日志配置中又在使勁的建立日志,導緻持有的檔案句柄數超過了Linux最大的句柄連接配接數,導緻後續的封包日志無法操作,最終導緻應用無法提供服務。

檔案句柄的原理

在Linux系統中,将所有的一切的目錄、字元裝置、塊裝置、套接字、列印機等都抽象成了一個檔案處理。也就是經常會提到的Linux中一切皆檔案。

當系統操作這些檔案的時候,為了記錄每個操作檔案通路情況,就會為這檔案建立一個檔案描述符也就是常說的fd,并且這些fd都是存在于Linux的open files table中,而這個table所能容納的fd是有限的。如果超過了這個值,那麼Linux沒有fd的配置設定了,就會拒絕檔案操作請求,最終就出現了Too many open files的異常。

這個異常在伺服器進行Socket連接配接超過伺服器最大連接配接數的時候也會出現。這是因為每一個Socket連接配接都是一個檔案描述符,當超過了65535的之後伺服器就會拒絕連接配接。

如何解決呢?

檢視檔案句柄連接配接數

在Linux通過 ulimit -a 指令來檢視目前所占用的句柄連接配接數。這裡示範如何使用,而非真實場景。

[root@localhost ~]# ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 31142
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 31142
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited
[root@localhost ~]#            

其中open files 所展示的就是單個程序允許打開的最大句柄連接配接

找到對應的程序的PID,檢視該程序對應的檔案句柄。

[root@localhost ~]# ps -ef|grep java
root      7642  7602  0 09:48 pts/0    00:00:00 grep --color=auto java
root     32053     1  0 9月20 ?       00:07:34 java -jar swly-admin-0.0.9-8082.jar
[root@localhost ~]# lsof -p 32053 | wc -l
97
[root@localhost ~]# lsof -p 32053
COMMAND   PID USER   FD      TYPE             DEVICE  SIZE/OFF      NODE NAME
java    32053 root  cwd       DIR              253,0      4096   4721636 /data/swly/admin
java    32053 root  rtd       DIR              253,0       256       128 /
java    32053 root  txt       REG              253,0      8712 101830342 /usr/local/java/jdk/bin/java
java    32053 root  mem       REG              253,0    292520  34594181 /usr/local/java/jdk/jre/lib/amd64/libjpeg.so
java    32053 root  mem       REG              253,0   1048136  34594178 /usr/local/java/jdk/jre/lib/amd64/libmlib_image.so
java    32053 root  mem       REG              253,0    504840  34594192 /usr/local/java/jdk/jre/lib/amd64/libt2k.so           

在正常情況下,可以通過增加open files的方式來解決這個問題,但是我們出現的問題并不能通過這種方式來解決,隻能是保證臨時的解決。要想實際解決還需要檢視代碼的邏輯,發現是代碼邏輯中對日志記錄的問題,檔案流沒有進行close的操作。

臨時解決方案可以執行如下的指令來增加句柄連接配接數。

ulimit -n 2048 # 重新開機後會恢複預設值,非root使用者隻能設定到4096           

或者通過修改配置檔案的方式來永久的進行修改。

[root@localhost ~]# vi /etc/security/limits.conf
 
# 檔案末加入
* soft nofile 655360
* hard nofile 655360           

總結

最終在架構師和高工的共同努力下,通過檢視代碼找到了問題,是因為ESB系統在臨時存儲封包的log日志的時候沒有将檔案流Stream進行關閉,導緻後續的封包進入之後,前面的檔案描述符沒有釋放,在淩晨一點開始核心系統重寫的時候,大量的請求經過ESB系統,導緻log日志占用檔案句柄數過多出現了這麼一個生産問題,最終還加入了日志定時删除的操作。