目前Apache + Weblogic Cluster是很多企業(yè)應用的架構模式，前端Apache負責請求分發(fā)，后端利用Weblogic Cluster的session replication提供failover。絕大多數(shù)情況下，這種模式工作的很好。這篇文章我將以標題中的兩個名詞為中心，探討一下Apache plugin的分發(fā)及failover機制。首先看一下這兩個名詞：

No backend server available：沒有可用的后端服務器。最常見最可能的原因就是：后端server全部沒有啟動或者Apache無法連接到其中的任何一個。復現(xiàn)方式很簡單，只啟動Apache，然后做后端weblogic server的業(yè)務請求，或者中斷Apache到后端服務器的網(wǎng)絡。這種原因很好檢查，也很好解決。本文中我們將探討另外一種情況，網(wǎng)絡沒有問題，而且至少有一個服務器存活，但客戶端仍然碰到“No backend server available”。

HALF_OPEN_SOCKET_RETRY：Weblogic內部自定的異常，這種異常通常由于Apache使用了某個已經(jīng)中斷的連接向后端服務器發(fā)送請求，這種請求肯定會失敗。連接中斷的原因也很多，比如我們關閉后端的服務器，那么Apache手里到這個服務器的連接再次被使用時，Apache將會收到HALF_OPEN_SOCKET_RETRY。

        首先，我們看一下plugin的分發(fā)機制。通常每個非初始請求都會在自己的cookie中有一個JSESSIONID，JSESSIONID由weblogic產(chǎn)生，用戶唯一標識和該用戶相關的Session。JSessionID常見格式為：
SessionHash ! primaryHash ! SecondaryHash，比如：
s4wYKyvDKG2ZDHwQclchD50PYjvCsN9nLSL9hPRMQ2ZzM3pVdbL1!1198345223!-977705075
primary：該Session的主服務器
secondary：該Session的備份服務器，如果沒做SessionReplication，則沒有該列。如果SessionReplication失敗，那么該列會是none或null。

        有了JSESSIONID，在load_utils.getPreferredServersFromCookie()中，plugin會解析這個JSESSIONID，如果我們打開plugin的debug，我們會看到類似如下的信息，

Thu Sep 10 08:56:36 2009 <1899912525369961> Found cookie from cookie header: JSESSIONID=s4wYKyvDKG2ZDHwQclchD50PYjvCsN9nLSL9hPRMQ2ZzM3pVdbL1!1198345223!-977705075
Thu Sep 10 08:56:36 2009 <1899912525369961> Parsing cookie JSESSIONID=s4wYKyvDKG2ZDHwQclchD50PYjvCsN9nLSL9hPRMQ2ZzM3pVdbL1!1198345223!-977705075
Thu Sep 10 08:56:36 2009 <1899912525369961> getpreferredServersFromCookie: [1198345223!-977705075]
Thu Sep 10 08:56:36 2009 <1899912525369961> primaryJVMID: [1198345223]
secondaryJVMID: [-977705075]

      解析出了primaryJVMID、secondaryJVMID，這是plugin需要檢查這兩個id是否為空，如果兩個都為空，那么說明這個請求沒有prefer server，plugin只要按照最基本的load balance策略作請求分發(fā)即可。如果至少有一個不為空，我們繼續(xù)找該session所prefer的server，debug 信息如下：

Thu Sep 10 08:56:36 2009 <1899912525369961>Primary or Secondary JVMID *not* found in cookie, ignore preferred servers //說明沒有從cookie中找到primay或secondary。
Thu Sep 10 08:56:36 2009 <1899912525369961> No of JVMIDs found in cookie: 2 //說明找到了兩個jvmID

        Apache plugin運行過程中會維護一個server list，這個server list就是我們在httpd.conf中指定的server列表，如果我們使用了dynamic server list，那么這個list是隨著后端cluster的變化而動態(tài)更新的。server list中每個server有自己的JVMID。plugin從cookie中解析出primaryJVMID、secondaryJVMID后，需要primaryJVMID、secondary JVMID做校驗，防止cookie中的信息過于陳舊(如果后端服務器發(fā)生過重起，就會出現(xiàn)JVMID不一致的情況)。校驗過程其實很簡單，plugin會遍歷手里的server list。如果發(fā)現(xiàn)某個server被標志為bad，它會檢查skip-time，如果skip-time（默認10秒）已到，即從這個server被mark bad到現(xiàn)在已經(jīng)超過10秒，那么plugin會把這個server重新mark good（這樣如果我們接下來創(chuàng)建到這個server的連接成功，那這個server就真的可用了，plugin通過這種機制來恢復后端server）。


        接著plugin會將解析出來的primaryJVMID、secondaryJVMID后自己server list中server的JVMID做比對。如果primary匹配，就把對應的serverInfo設入請求的preferred[0]，同樣如果seconday匹配，對應的serverInfo會被設入請求的preferred[1]。注意：接下來plugin將以preferred為基礎進行分發(fā)、failover。debug信息如下：

Wed Sep 02 14:33:12 2009 <553612518731924> getPreferredFromCookie: Found Primary 172.23.4.53:8001:0
Wed Sep 02 14:33:12 2009 <553612518731924> getPreferredFromCookie: Found Secondary 172.23.4.52:8001:0
如果匹配的server數(shù)目和cookie中jvmid數(shù)一致，則還能看到如下輸出：
Wed Sep 02 14:33:12 2009 <553612518731924> getPreferredFromCookie: Found 2 servers
如果不匹配，那么輸出信息將是下面這樣：
Wed Sep 02 14:33:12 2009 <553612518731924> getPreferredFromCookie: Found atleast 1 server

        如果匹配結果發(fā)現(xiàn)沒有一致的JVMID，如下：
Thu Sep 10 08:56:36 2009 <1899912525369961> getPreferredFromCookie: Either JVMIDs not set or they are stale. Will try to get JVMIDs from WLS
那么這時候plugin就需要強制更新自己server list中server的JVMID，這個更新通過proxy.initJVMID()實現(xiàn)。initJVMID中，plugin遍歷整個server list，嘗試創(chuàng)建到每個server的連接，如果連接創(chuàng)建失敗，這個server會被mark bad。連接創(chuàng)建成功，plugin向后端server發(fā)送internal request，如下：
Thu Sep 10 08:56:36 2009 <1899912525369961> ======internal request /bea_wls_internal/ WLDummyInitJVMIDs======
如果連接能夠成功創(chuàng)建，但發(fā)送請求的時候發(fā)生HALF_OPEN_SOCKET_RETRY（這里為什么會發(fā)送HALF_OPEN_SOCKET_RETRY，后面我們會討論到），這個server也會被mark bad(這里對HALF_OPEN_SOCKET_RETRY的處理不同于應用請求)，如下：

Thu Sep 10 08:56:36 2009 <1899912525369961> readStatus: Local port of the socket 53149, connected to Remote Host/Port 172.23.4.53/8001
Thu Sep 10 08:56:36 2009 <1899912525369961> readStatus: Response contains no data - isRecycled: 0
Thu Sep 10 08:56:36 2009 <1899912525369961> *******Exception type [HALF_OPEN_SOCKET_RETRY] (Unexpected EOF reading HTTP status - request retry) raised at line 854 of ../nsapi/URL.cpp
Thu Sep 10 08:56:36 2009 <1899912525369961> initJVMID: Failed to retrieved JVMID for 172.23.4.53:8001:8001
Thu Sep 10 08:56:36 2009 <1899912525369961> initJVMID: Marked server as BAD

如果請求處理成功，將會看到類似于以下的信息：

Thu Sep 10 08:56:36 2009 <1899912525369961> ServerInfo struct for JVMID '-977705075' populated
 Server Details are:
 OrigHostInfo [172.23.4.52]
 isOrigHostInfoDNS [0]
 Host [172.23.4.52]
 Port [8001]
 SecurePort [8201]
Thu Sep 10 08:56:36 2009 <1899912525369961> Initializing lastIndex=0 for a list of length=1

initJVMID()除了更新jvmID，同時還給我們這個請求分配了preferred server list。

        獲取到請求的preferred后，程序的控制權將回到proxy.wl_proxy()，這個方法是所有http請求的入口。回到wl_proxy后，進入while循環(huán)，循環(huán)的終止條件就是我們的retry次數(shù)(默認5次)。進入循環(huán)后，debug信息如下：
Thu Sep 10 08:56:36 2009 <1899912525369961> attempt #0 out of a max of 5 

        plugin要成功發(fā)送一個http請求，首先需要拿到connection，如果我們設置了keep-alive，首先會從connection pool中獲取，如果沒有，則創(chuàng)建新的物理連接。debug信息分別如下：
Wed Sep 02 14:35:45 2009 <553612518733456> got a pooled connection to preferred server '172.23.4.53/8001for '/test_sleep/testsleep.jsp', Local port:3651
Wed Sep 02 14:33:12 2009 <553612518731924> created a new connection to preferred server '172.23.4.53/8001' for '/test_sleep/testsleep.jsp', Local port:3636

         拿到connection后，plugin會將request的header信息發(fā)送到server端，并從連接上讀取response。此時上面兩種連接都可能出現(xiàn)HALF_OPEN_SOCKET_RETRY。我們分別看看這兩種情況：

1：如果pool connection對應的后端服務器已經(jīng)被shutdown，那么我們那pool connection做操作的時候，肯定無法完成，因此很容易碰到HALF_OPEN_SOCKET_RETRY。碰到HALF_OPEN_SOCKET_RETRY，plugin會做retry，而不是直接failover。重新去getConnection，如果pool中corrupted connection足夠多，那么五次失敗后，客戶端最終會看到“No backend server available”，debug中會有如下信息：

Tue Sep  1 10:43:41 2009 <10088125176582121> request [/socs/favicon.ico] did NOT process successfully..................

2：pool中的connection不是很多，比如2個，那么我們做完兩次retry后，這是就要創(chuàng)建物理的連接，如果連接創(chuàng)建失敗，這個server會立刻mark bad，請求將被failover到secondary，debug信息如下：
Wed Sep 02 14:36:06 2009 <553612518733456> *******Exception type [CONNECTION_REFUSED] (Error connecting to host 10.182.216.198:8002) raised at line 1732 of ../nsapi/URL.cpp
如果創(chuàng)建連接成功，但sendRequestHeader的時候發(fā)生HALF_OPEN_SOCKET_RETRY，那么plugin同樣會繼續(xù)作retry，而不是failover。如果剩余幾次retry結果都一樣（創(chuàng)建連接成功，但sendRequestHeader失敗），客戶最終也會看到“No backend server available。日志通常如下：
Tue Sep  1 10:43:41 2009 <10088125176582121> attempt #5 out of a max of 5
Tue Sep  1 10:43:41 2009 <10088125176582121> created a new connection to preferred server '172.23.4.52/8001' for '/socs/favicon.ico', Local port:49416
......
Tue Sep  1 10:43:41 2009 <10088125176582121> URL::sendHeaders(): meth='GET' file='/socs/favicon.ico' protocol='HTTP/1.1'
......
Tue Sep  1 10:43:41 2009 <10088125176582121> readStatus: Local port of the socket 49416, connected to Remote Host/Port 172.23.4.52/8001
Tue Sep  1 10:43:41 2009 <10088125176582121> readStatus: Response contains no data - isRecycled: 0
Tue Sep  1 10:43:41 2009 <10088125176582121> *******Exception type [HALF_OPEN_SOCKET_RETRY] (Unexpected EOF reading HTTP status - request retry) raised at line 854 of ../nsapi/URL.cpp
Tue Sep  1 10:43:41 2009 <10088125176582121> got exception in sendRequest phase: HALF_OPEN_SOCKET_RETRY: [os error=0, line 854 of ../nsapi/URL.cpp]: Unexpected EOF reading HTTP status - request retry at line 3080

        對于1，這個可以理解，如果pool中connection被關閉（keep-alive超時）完了，客戶就不會碰到這樣的問題問題了。而對于2，更多的應該說是OS的問題，OS沒有正確釋放端口。如果端口釋放成功，plugin做url.connect()的時候，應該是收到connection refuse，而不是正常創(chuàng)建連接(實際上是無用連接，使用時出現(xiàn)Socket_Half_Open)。對于2，我們可以通過以下的方法檢查：
1：ps -ef | grep java，檢查對應的managed server時候shutdown
2：netstat -a | grep listening port，如果server已經(jīng)shutdown了，卻還能看到listening port，那么就是OS的問題了。 

      寫了這么多，覺得比較繁瑣，不知道大家能否看得明白，建議最好拿一個wl_proxy的debug log，對照著看。