應用程式偶發連線不上資料庫的排查案例

weixin_39512482發表於2020-10-17

問題現象

有一個應用,偶爾會出現訪問不了的情況。具體表現為,當其它應用呼叫它的介面時,可能會出現超時,過一段時間後,再呼叫它的介面可能又正常了。為了判斷這個介面超時是否因為連線資料庫的原因,單獨寫了個程式,不連線資料庫,單純返回字串給前端,數小時後訪問,果然不會出現超時。。。。這一步,排除了使用者端和應用層的網路連線是正常的
接著,我們在應用程式中增加了資料庫連線查詢,使用簡易的,絕對不會產生耗時的sql語句查詢,第一次訪問正常,
(原本的程式可能處理異常的原因,介面不會丟擲異常,為使得能在每次在觸發資料庫連線連線異常能丟擲來,增加了會話主動斷開連線),於是我們為了等到第二天,再次請求介面,觀察應用程式介面服務,介面沒給出響應,直到等了有30秒,丟擲異常,這時候再去請求介面程式,發現,介面遲遲不能給出響應,並且丟擲異常了,如圖
在這裡插入圖片描述
ORA-03113/ORA-03114這類錯誤大致就是丟失了資料庫連線,客戶端向Oracle伺服器提交SQL時,由於TCP連線已經中斷,這時客戶端偵測到連線中斷,那麼客戶端就會報ORA-03113/ORA-03114這類錯誤,然後會話中斷。
其實就是應用端與資料庫建立的tcp連線因為某些原因斷開了,而導致了“管道破裂”。一般資料庫連線池會與資料庫保持長連線,在需要的時候省去建立連線的過程,直接使用,而為什麼這些空閒的連線會被斷開呢?被誰斷開了?資料庫連線池機制不能檢測連線狀態建立新的連線嗎?(本該直接去觀察應用日誌發現錯誤提示,可是我們程式配置的日誌沒有捕捉到有用的資訊)

為什麼資料庫TCP連線會被斷開

一開始百思不得其解,想著是因為Oracle資料庫主動斷開了連線嗎?因為某些原因,比如從伺服器到資料庫的連線太多?明顯不是,這個專案還在試執行階段,用的人不多

這個被呼叫的應用會偶發性地連線不上資料庫。因為該應用沒有辦法及時地查詢到資料庫,應用返回資料時間過長,也就導致呼叫該應用介面的其它應用超時。這種情況比較偶發,一天大概幾次,沒什麼特別規律。

而真實環境的應用程式時python開發,被gunicorn管理,gunicorn有個檢測應用狀態機制,導致重啟程式,這個問題產生,在應用日誌中只能大概看出,gunicorn使得應用大量的重啟,沒有太多其它的資訊:

現在已經確定是應用連線不上資料庫導致的故障,但,為什麼該應用會連線不上資料庫並且還是偶發性的呢?

關於這個問題,和開發人員等人一同排查了好久。。,竟然沒有任何頭緒,最後,我抱著探索學習的想法,絕對攻破它!而我,也沒什麼經驗可談,邊邊角角學習所得,而最近又各種類似”保姆服務”的測試工作,巨多,只能抽空下班後的時間,才能集中精力去排查,於是我查閱了各個方面的資料(還專門買了tcp網路用書,嘎嘎)。
再說這個系統是我測試的,不管哪裡的原因,出了問題。我也不光彩,好吧。其實是因為這個應用當初是我部署上線的,我怎麼能允許我自己部署的應用出現問題呢。況且,其它連線資料庫的應用也沒說過有問題啊,然而,事實證明,這個問題涉及到的水比較深。

出現連線不上資料庫的那個應用是Python程式來的,它使用了Flask框架的擴充套件庫SQLAlchemy連線池來連線資料庫。而資料庫本身是Oracle資料庫,

可能原因的解釋

當一個請求進來,SQLAlchemy 會建立一個資料庫連線,執行結束後把連線放回池子裡。下一個請求來的時候,就可以直接使用之前的連線。當然,如果同時進來多個不夠分配的時候,會建立另外的連線用於使用,執行結束後又放回池子裡。池子裡的最大連線數是可以配置的。這種方式可以避免頻繁建立、銷燬連線,從而提高執行效率。
但是,這帶來另一個問題。當資料庫突然掛掉或者資料庫過一定時間清理未活動連線的時候,SQLAlchemy 是不知道的。當一個請求進來時,會被分配一個失效的連線,自然會丟擲一些異常。

連線池的連線在不知情的情況下在資料庫伺服器上被關掉了。這個大致分為兩種情況:
一、資料庫異常或者誤操作,比如資料庫掛掉、重啟、有的連線被誤操作給 kill 掉了等 等這種情況下只好重啟應用程式, 讓應用重新維護連線池;
二、連線長時間未活動。這又有兩種情況:
1. 連線池中的連線的回收時間大於資料庫配置的未活動連線過期時間,由於連線的回收時間一般都是設定的一兩個小時,而資料庫(mysql)的未活動連線過期時間預設是八個小時,所以這種情況一般不會出現;
2. 應用程式裡的邏輯程式碼有問題,在進行資料庫的寫入操作後,缺少 commit、 rollback、close 的操作將連線放回連線池,連線池沒法管理,當這個連線被資料庫回收後(或者網路干預),也就出現了上面的異常。這種情況,有以下幾個解決辦法:
(1)檢視相關的業務,補充缺失的連線維護操作(推薦);
(2)可以通過重啟應用程式解決,不過指標不治本,執行一段時間後,問題依舊會出現;
(3)SQLAlchemy 開啟 autocommit,不過這樣就不能手動 rollback 了,在很多插入、更新場景中,不大實用;
(4)徹底一點的,直接不用連線池,在 create_engine 時指定引數 poolclass 為 NullPool。不過連線的使用效率就不如之前了,自己權衡。
我們先來分析下Flask-SQLAlchemy,他是一個為Flask應用增加SQLAlchemy支援的擴充套件。其中就有連線資料庫的一些引數,比如常見的關注項:資料庫連線池大小(預設5),資料庫連線池的超時時間(預設10),自動回收連線的秒數(這對mysql是必須的,預設情況下,mysql會自動移除閒置8小時或者以上的連線。需要注意的是如果使用mysql,的話,Falsk-salalchemy會自動地設定這個值為2小時),-----查閱自http://www.pythondoc.com/flask-sqlalchemy/config.html,使用Oracle不設定,預設也是2小時,檢視原始碼得知。

好的,我們程式的異常是時隔幾個小時出現的,具體還沒有發現規律,所以我們考慮是否是因為閒置連線時間造成的,從閒置連線入手,於是調整為5分鐘,這個時間,可以確保每次都是採用新的連線,修改這個引數應該就可以避免,然而還是等待數小時才去測試發現,curl去訪問,結果,依然沒什麼鳥用,於是留下了一個疑問,回收閒置連線後,新的連線依舊使用的是連線池中的某個連線,連線池的連線數在應用啟動的時候就建立好了,這樣去除錯,不起作用。

好吧,我們換個角度排查,既然是應用程式連線不上資料庫,(其實資料庫應該有關於連線的日誌資訊,因為不會看oracle監聽日誌,就忽略了這個辦法,能不能從oracle監聽日誌看的到,後續再說),不會是網路連線根本就沒有到達資料庫吧,那麼可以觀察下網路連線。

要查網路,首先想到,linux有沒有提供檢視埠監聽和網路連線的命令呢,我們平常已經使用了netstat檢視埠監聽是否開啟,是否netstat 加個查詢引數就可以看到具體的連線資訊呢,於是直接問度娘,哦哦,答案是有的,正是這個nesstat命令,最終使用netstat -antpo | grep 1521。(另外可以通過tcpdump去抓包,然後開啟wireshark去分析,在應用剛啟動和應用空閒時(即應用不主動去訪問資料庫),雖然應用和資料庫之間已正常建立了連線,在應用和資料庫伺服器兩端均可看到等量的並對稱的ESTABLISHED狀態的連線,但抓包卻發現它們之間沒有傳遞任何資料包,後面補充當時抓包詳情)

由於應用採用資料庫連線池來連線Oracle資料庫,也就是說,應用與資料庫之間的連線是tcp長連線。那麼正常情況下,在任一時刻,應用與資料庫伺服器兩端的ESTABLISHED狀態的tcp連線數量應該都是一致的。然而,我實際觀察到的情況,卻不是這樣。(此處應該有截圖,當時沒儲存下來)

經過更加細緻的觀察,可以發現,一開始,在該應用剛剛啟動時,兩端的tcp連線數量是相同的。但是,過了一段時間後,oracle資料庫伺服器端與應用伺服器的tcp連線數量急劇減少。而就在這時,我立馬去訪問介面,就出現了開文的問題現象。

這裡有個疑問:
兩端的ESTABLISHED狀態的tcp連線數量不一致是不是一定就有問題的呢?答案是肯定的。因為tcp是面向連線的協議,連線的兩端只有通過"三次握手"正常建立了tcp連線後,它們才能正式通過該tcp連線開始互動資料。如果其中一端不存在該tcp連線的資訊,那麼即便另一端通過該tcp連線傳送帶應用資料的資料包過來了,不存在tcp連線資訊的這一端收到資料包後也會直接將該資料包丟棄,從而導致兩端無法正常互動資料。因此,問題就出在這了,正是因為應用和資料庫伺服器兩端的tcp連線不對稱,才導致了應用無法正常訪問資料庫。簡單來說,我們使用netstat命令即可查詢出結果來。
這說明,因為某種原因,從應用伺服器發出的資料包在網路中丟失了。具體是什麼原因,現在還無法確定

按理說,資料包在網路中丟失了,那麼,就應該找網路工程師一起排查下是什麼問題。但無奈,線上環境的對接人,他們可能不是專業的網路工程師,得到的回覆是,沒有看到防火牆關於連線時間的額外設定。簡單來說,我從那裡沒有獲取到任何有價值的資訊,他們也不認為網路本身有什麼問題,也不願意協助排查,我也沒有許可權看不了防火牆,所以我只能自己想辦法排查了。

tcp連線的保持

前面我提到,在抓包時,我發現了3個怪異的現象。其中,第一個現象是,在應用剛啟動,應用空閒時(即應用不主動去訪問資料庫),雖然應用和資料庫之間已正常建立了連線,在應用和資料庫伺服器兩端均可看到等量的並對稱的ESTABLISHED狀態的連線,但抓包卻發現它們之間沒有傳遞任何資料包。
關於這個問題,我查閱了<<TCP/IP Illustrated, Volume 1: The Protocols>>。其中,TCP Keepalive這章裡面有提到:

Many newcomers to TCP/IP are surprised to learn that no data whatsoever flows across an idle TCP connection. That is, if neither process at the ends of a TCP connection is sending data to the other, nothing is exchanged between the two TCP endpoints. There is no polling, for example, as you might find with other networking protocols. This means that we can start a client process that establishes a TCP connection with a server and walk away for hours, days, weeks, or months, and the connection should remain up. In theory, intermediate routers can crash and reboot, data lines may go down and back up, but as long as neither host at the ends of the connection reboots (or changes its IP address), the connection remains established. This is how TCP/IP was designed.

上面這段話的意思是:空閒的TCP連線是沒有資料流動的,也就是說,如果TCP連線的兩端如果都不傳送資料給對方,就沒有任何東西在它們之間互動;也不會有定時的資料包輪詢;當一個客戶端和一臺伺服器建立TCP連線之後,若伺服器離開幾個小時、幾天或幾個月,連線也都還在的,即便中間的路由器和線路掛了、重啟了或斷了,但只要TCP連線兩端的主機都沒有重啟(或更改它的IP地址),連線會一直保持ESTABLISHED狀態;TCP/IP就是這麼設計的。

也就是說,我觀察到的第一個現象(應用空閒時,雖然應用伺服器和資料庫伺服器之間建立了ESTABLISHED狀態的連線,但卻沒有資料包互動),該現象是正常的。TCP/IP就是這麼設計的。

於是我值守式的去觀察並記錄斷開連線的時間,經歷了5輪,歷經半天,發現了規律。

當經過2個小時後,資料庫所在伺服器的tcp連線莫名的失去連線,這時候檢視應用伺服器,該連線還在,看到這裡我們似乎找到了問題的根源,但是為什麼資料庫所在的連線會丟失呢?是不是中間有防火牆,防火牆是否會設定一個TCP超時時間,是否設定的就是2小時呢,防火牆這時候在拆除連線時,不會向連線的兩端傳送任何資料來通知連線已經拆除?,這樣的話,調大防火牆的超時時間一切問題就解決了啊!!

一堆疑問,我第二天立馬聯絡了機房管理員,說沒有檢視到關於防火牆連線額外的設定(可能不是專業的吧,再說不能因為你一個子系統,讓人家更改防火牆規則啊。),。。。吐血,這是怎麼回事呢,無奈只能檢查自己的問題,,

但是,在該章的其它地方,它說:存在一種TCP keepalive機制,但它是可選的。TCP keepalive特性並不是TCP規範的一部分(因為可能會有誤判及產生額外的流量等),然而,大多數TCP實現都提供了keepalive能力。即便如此,TCP keepalive功能預設也可能是關閉的。

TCP keepalive功能可以在TCP連線的其中一端,或兩端啟用,或兩端都不啟用。它的運作機制是這樣的:如果TCP連線上有一段時間(叫做keepalive time)沒有活動,那麼,啟用了keepalive的一端就會傳送存活探測資料包給它的對端。如果沒有收到任何響應資料包,該探測包就會週期性地(週期間隔為keepalive interval)重複傳送,直到探測次數達到keepalive probes的設定值。當發生這種情況時,對端的系統將被判定為是不可恢復的並且該TCP連線會被終止。

變數keepalive time、keepalive interval和keepalive probes的值通常是可以修改的。一些系統允許在per-connection的基礎上進行這些修改,另一些系統則只能在全域性範圍修改(或可能兩種都支援)。在Linux中,這些值可以通過sysctl系統引數來相應修改:
net.ipv4.tcp_keepalive_time、
net.ipv4.tcp_keepalive_intvl
net.ipv4.tcp_keepalive_probes。
預設值分別是7200 (seconds,或2 hours)、75 (seconds)和9 (probes)。

Linux並未提供一個原生的工具來為那些未請求啟用TCP keepalive的應用強制開啟TCP keepalive功能。換句話說,雖然Linux支援TCP keepalive特性,也可以調整相關的定時器設定,但某一個TCP連線究竟是否啟用TCP keepalive特性,由上層的應用程式說了算(需要應用程式呼叫系統的API),Linux本身並沒有工具/設定項來讓你為所有TCP連線都強制開啟TCP keepalive特性。

說到這裡我們會提出疑問,應用層的資料庫模組在開發時,不該是應用程式模組的工作嘛?

不妨試想,Python應用資料庫模組在開發時讓設定tcp keepalive為true,這樣tcp連線在一定時間內沒有任何資料包文傳輸則啟動探測,但是這個時間一般是作業系統規定,Linux系統中可以通過設定net.ipv4.tcp_keepalive_time來修改,預設是7200秒,即2小時。

當然在程式設計時也可以設定這個時間用於當前socket,而Java或者Python的Socket API中好像只有設定keepalive=true,並沒法設定tcp_keepalive_time,當設定了tcp keepalive之後,只要tcp探測包傳送的時間小於防火牆的連線超時時間,防火牆就會檢查到連線中仍然有資料傳輸,就不會斷開這個連線。

悲劇的就是,使用Python的SQLALCHARY建立的連線是沒有設定keepalive的,你怎麼知道的呢?
這點可以通過Linux的netstat或ss命令在資料庫客戶端(即應用端)驗證,使用命令netstat -ano 或 ss -ano,其中引數o都是顯示timer計時器,timer計時器在連線建立狀態下可以對連線保活計時,netstat命令對沒有開啟keepalive的tcp連線顯示為:off (0.00/0/0),ss命令對沒有keepalive的tcp連線,不會顯示timer計時器

那麼有人提出疑問了,程式中人為的也可以主動做這種心跳檢測啊,但是另當別論,還是覺得不妥,除非你的知識沉澱真的厚。為了避免踩到雷區,我們系統的問題,就先預留這個方案。(也許高版本的資料庫連線池已經支援了!)

到這裡,因為目前的方案慢慢要給作業系統核心做調整了,心裡頓時默唸,謹慎行事!
我多了個想法,難道強大的racle就沒有類似tcp keepalive的機制?

查閱資料後,發現:Oracle提供了類似tcp keepalive的機制,也就是DCD(Dead Conneciton Detection)。在$ORACLE_HOME/network/admin/sqlnet.ora檔案中增加如下一行:
sqlnet.expire_time=NNN
這裡NNN為分鐘數,Oracle資料庫會在會話IDLE時間超過這個指定的時間時,檢測這個會話的對端(即客戶端)是否還有效。避免客戶端由於異常退出,導致會話一直存在。同樣的如果DCD的時間比防火牆切斷空閒連線的時間短,連線也可以一直保持,

我嘗試性的設定了2,就是2min時間,這個時間間隔絕對小於防火牆的超時機制了,下來,修改後重新載入監聽配置,使其生效(不是重啟),過了1小時後,再去訪問介面,問題缺還是依然存在,難道真的要修改作業系統核心的tcp超時時間嗎?

回到問題本身,應用伺服器是centos系統,屬於Linux的一種,自然也支援上面提到的三個屬性:

[root@bx ~]# sysctl -a | grep 'keepalive'
net.ipv4.tcp_keepalive_time = 7200
net.ipv4.tcp_keepalive_probes = 9
net.ipv4.tcp_keepalive_intvl = 75

各引數含義:
net.ipv4.tcp_keepalive_time:如果TCP連線啟用了TCP keepalive特性,那麼,當TCP連線空閒時間達到該項設定值時,伺服器就會傳送存活探測資料包給它的對端。預設值是7200 (seconds,或2 hours)。
net.ipv4.tcp_keepalive_probes:傳送存活探測資料包後,若未收到來自對端的響應資料包,伺服器會嘗試重新傳送探測資料包,直到總的探測次數達到該項設定值。預設值是9 (probes)次。若最後一次探測時仍未收到對端的響應資料包,伺服器會清除掉自己本端的該TCP連線。
net.ipv4.tcp_keepalive_intvl:每次傳送探測資料包的間隔時間。預設值是75 (seconds)。那麼來說,從開始探測到最後清除TCP連線,總共需要經過tcp_keepalive_intvl * tcp_keepalive_probes的時間,若以預設值計算,為75 * 9 = 675秒,約為11分鐘多。

即便如此,我又怎麼知道應用伺服器去往資料庫伺服器的TCP連線是否啟用了TCP keepalive呢?畢竟,我無法知道應用程式是否有要求啟用TCP keepalive。其實,通過netstat命令的 -o 選項可以檢視到,在應用伺服器上執行以下命令:

最後一列都是off的,說明在應用伺服器這端,所有與資料庫伺服器的TCP連線都是沒有啟用TCP keepalive特性的。如果有啟用的話,那麼最後一列會顯示keepalive的字樣。

改完後!執行生效命令,準備過1小時後,再去請求介面,然而,這時候我國慶回家火車,我得去敢火車了,路上,我心裡還牽掛這個問題,是不是一定好呢,反正沒有其他可能了,好不好就解決到這裡,回老家有點忙,第二天早上我拿出了從北京帶到老家的筆記本,上去就是一個netstat -o 命令,ji發現一行一行的陌生而又熟悉的ESTABLISHED狀態 出現了,並且出現keepalive;

我立即登陸系統(早上的時間去訪問介面,之前測試必會出現超時),介面是再正常不過的訪問速度了,我發了朋友圈,本系統的專案經理評論說:是xxx系統問題嗎?,我說:“是”,他再次回覆了我一個大拇指。(不是嘚瑟,我僅僅只想記錄下自己認真的經歷);雖然這個系統在公司專案的分量不大,但是這一刻的感覺真不錯!

問題總結

到這裡為止,問題已經很清楚了。這種問題的發生其實並不侷限於訪問Oracle資料庫的情況,只要是長連線,當滿足以下所有條件時,這種問題就會發生:
1、 兩臺伺服器之間存在有硬體防火牆。
2、 使用了TCP長連線,比如在使用TCP連線池的場景中。
3、 在TCP連線的兩端均未啟用TCP keeplive特性,或任意一端或兩端啟用了TCP keeplive特性,但空閒檢測時間(如Linux的net.ipv4.tcp_keepalive_time引數,AIX的tcp_keepidle引數)大於硬體防火牆的會話超時時間。是否有啟用TCP keeplive特性通常由上層應用程式決定,但可以通過命令來觀察。
4、 不存在應用層的定時輪詢,或存在應用層的定時輪詢,但輪詢間隔大於硬體防火牆的會話超時時間。是否存在應用層的定時輪詢通常要根據具體的應用程式及配置(如資料庫連線池的配置)而定。
5、 在硬體防火牆的會話超時時間內,長連線中沒有資料包傳輸。通常,如果應用本身沒什麼訪問量,或者是在凌晨等時段訪問量比較低,又或者是長連線數量太多,都有可能使某些長連線一直空閒,長時間沒有資料包傳輸。

其它問題

有時,我們會想,客戶端的資料庫連線池中有很多與資料庫伺服器端的連線,假設其中仍然有一部分連線是仍然可以訪問到資料庫的,那麼這時候應用訪問資料庫會不會有問題呢?
仍然是可能有問題的。根據我的觀察,當應用訪問資料庫時,應用可能是從連線池中隨機選取一個連線的(具體的選取規則我不是很確定),但重點是,在沒有做檢測的情況下,應用並不知道連線池中的哪些連線是實際可用的。如果應用選取到的是一個實際不可用的連線,那麼這時,由於資料包傳送出去了但沒有回包,(至少在Linux上)作業系統會一直嘗試重傳並超過最大重試次數(正如前面所說),這個過程至少也要10分鐘以上,而應用層通常早就超時報錯了。當確定了連線不可用之後,應用會再從連線池中選取一個連線。若這個連線仍然不可用,應用才會嘗試建立一個新連線。整個過程下來,可能要20多分鐘,而應用層通常都不會等待這麼久的時間。

當然,如果應用最開始從連線池中選取到的那個連線恰好仍然可用,此時應用訪問資料庫是沒有問題的。因此,總的來說,這種情況就是看概率啦。不過,通常,出問題的概率比較大。

本文講的是與Oracle資料庫之間的問題,如果換成MySQL資料庫,會是什麼情況呢?

MySQL資料庫有一點不同,據我觀察,應用通過MySQL驅動與MySQL資料庫建立長連線時,應用這一端是啟用了TCP keepalive特性的。可能並不是所有MySQL驅動都是這樣的,但假設是這樣的話,那麼,問題的發生會變得更加隱晦。其實原理都是一樣的,套用原理分析一下就行,我就不囉嗦了。

通過此次排查問題的經歷,暴露了技能的欠缺,也衍生出了此類問題存在,在其他專案的通用性參考,以及達到一定業務量時,很多中介軟體,應用程式,資料庫,網路、作業系統等業務節點,需要考慮調整及優化的地方。
No pain, no gain !
在這裡插入圖片描述

相關文章