閱讀330 返回首頁    go 阿裏雲 go 技術社區[雲棲]


Tomcat對keep-alive的實現邏輯

Tomcat的connector實現邏輯蠻複雜的,有很多種狀態總記不住,每次遇到網絡相關的問題都要翻一遍代碼,這次結合一個案例看看tomcat的三種connector的實現方式。

這個案例在畢玄的blog裏也提到了,背景是某應用上遊有個用c寫的模塊與server端tomcat進行http通訊,這個應用tomcat配置的connector是apr模式。之前一直運行的很穩定,但一次前端擴容後,導致後端的tomcat全部阻塞在下麵的堆棧上:

"http-apr-7001-exec-2" #28 daemon prio=5 os_prio=31 tid=0x00007fe1e43db800 nid=0x660b runnable [0x0000000124629000]
java.lang.Thread.State: RUNNABLE
 at org.apache.tomcat.jni.Socket.recvbb(Native Method)
 at org.apache.coyote.http11.InternalAprInputBuffer.fill(InternalAprInputBuffer.java:575)
 at org.apache.coyote.http11.InternalAprInputBuffer.parseHeader(InternalAprInputBuffer.java:464)
 at org.apache.coyote.http11.InternalAprInputBuffer.parseHeaders(InternalAprInputBuffer.java:312)
 at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:969)
 at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
 at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2442)
 at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2431)
 - locked <0x000000079581e018> (a org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
 at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
 at java.lang.Thread.run(Thread.java:745)

在我們最近這一年內推出的ali-tomcat版本裏已經不推薦apr模式了,因為它帶來的性能上的提升與運維和維護的成本比不值。一方麵在使用時tcnative這個本地庫的版本要與tomcat的版本匹配,否則不同的版本可能不工作(曾經出現過這樣的運維故障);二是我們曾遇到過apr導致jvm crash的情況;還有一個問題還是這個模塊曾經被某個大牛修改過,繼續維護的話團隊裏需要一個C/C++的人才行。

當時的情況有些緊急,看到堆棧阻塞在apr的本地調用上,通過pstack查看libapr的調用底層阻塞在pollepoll_wait上,一下子沒有思路,隻好先讓應用方升級到新版本的ali-tomcat上,采用BIO或NIO模式看看。

應用方切換到了新的版本後默認配置了BIO,線程池設置的是250,過不了一會兒大部分又阻塞在了下麵的堆棧上:

"http-bio-7001-exec-977" daemon prio=10 tid=0x00007f3e0bb96800 nid=0x6ff5 runnable [0x00007f3e054d3000]
java.lang.Thread.State: RUNNABLE
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.read(SocketInputStream.java:129)
 at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer.java:516)
 at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer.java:501)
 at org.apache.coyote.http11.Http11Processor.setRequestLineReadTimeout(Http11Processor.java:167)
 at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:948)
 at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
 at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314)
 - locked <0x00000006ed322ed8> (a org.apache.tomcat.util.net.SocketWrapper)
 at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
 at java.lang.Thread.run(Thread.java:662)

從這個堆棧來看直覺上以為在讀數據,問了以下應用方,上遊主要通過POST方式調用tomcat,每次數據大約在幾K到幾十K,當時沒有細問,誤以為真的是發送過來的數據量達,都阻塞在數據讀取上。采取了增加線程數大小的做法,先調到1000,發覺穩定在700-800之間,後應用負責人有些不放心,又調到了1500.

周末之後,應用雖然穩定,但BIO模式線程數開銷的仍較大,通過ali-tomcat內置的監控功能可以看到線程池的狀態:

$ curl http://localhost:8006/connector/threadpool
"http-bio-7001"
-----------------------------------------------------------------
| thread_count  |  thread_busy  | min_pool_size | max_pool_size |
-----------------------------------------------------------------
|     1121      |     1091      |      10       |     1500      |
-----------------------------------------------------------------

BIO模式下在使用的線程有1091個,應用方嚐試采用NIO模式,觀察了一段時間,同等壓力下,線程數有大幅度下降:

$ curl http://localhost:8006/connector/threadpool
"http-nio-7001"
-----------------------------------------------------------------
| thread_count  |  thread_busy  | min_pool_size | max_pool_size |
-----------------------------------------------------------------
|      483      |      44       |      10       |     1500      |
-----------------------------------------------------------------

對於這麼明顯的下降,一方麵懷疑BIO模式的瓶頸在哪兒,另一方麵也覺得與業務的場景有關,正巧這個場景適用NIO模式。了解到他們使用了keep-alive,之前對於keep-alive的實現僅在NIO模式下有跟蹤過,對於BIO和APR模式下如何實現的keep-alive沒有很深入的了解,正好借這次問題排查詳細的跟蹤了一下另外兩種模式下對keep-alive的實現。

在說keep-alive的實現之前,先貼張之前分享ali-tomcat的ppt的一張圖:

這張表格引用自apache-tomcat官方網站,對於connector的三種模式有很好的對比,上次分享時著重講NIO模式的實現,所以對NIO也不是完全非阻塞(讀body和寫response是模擬阻塞行為)的地方用紅色突出了一下。這次我們先著重關注一下表格裏的 “Wait for next Request” 這一項。它表示的是當開啟keep-alive的情況下三種模式對等待下一次請求是否阻塞。

1) BIO模式下的keep-alive實現:

首先在BIO的專門負責socket建立的Acceptor線程的邏輯裏,將socket封裝成一個task(對應的是JIoEndpoint.SocketProcessor這個類)提交給線程池處理。而這個task(即SocketProcessor)的run方法邏輯大致是:

try{

    ...
    state = handler.process(...); // 這裏是具體的處理邏輯
    ...

    if (state == SocketState.OPEN){
        socket.setKeptAlive(true);
        socket.access();
        launch = true;
    }
    ...

}finally{
    if(launch) {
        executor.execute(new SocketProcessor(...)); // 再次封裝為同類型的task,並再次提交給線程池
    }
}

注意上麵的邏輯,如果請求是開啟keep-alive的話,socket在請求結束後仍處於OPEN狀態,下一次請求仍可以複用當前socket而不必重新創建,在 finally 塊裏會判斷連接狀況如果是keep-alive會再次封裝為同樣的任務提交給線程池,重複這段邏輯,相當於一個循環,隻不過每次執行的線程不一定相同。如果socket上已經沒有請求了,最終socket會因超時或客戶端close造成的EOFException而關閉。

有一個簡單的方法來判斷keep-alive是否被有效利用,如果socket被複用得當的話,socket(對應的是SocketWrapper這個類)的實例數應該是大大小於請求task(對應的是SocketProcessor這個類)實例數。比如我們先模擬不複用scoket的情況:

$ curl http://localhost:7001/main
$ curl http://localhost:7001/main

$ jmap -histo `pidof java` | sed -n -e '1,3p' -e '/SocketWrapper/p' -e '/SocketProcessor/p'

 num     #instances         #bytes  class name
----------------------------------------------
 516:             2            128  org.apache.tomcat.util.net.SocketWrapper
 587:             4             96  org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor

上麵執行了2次curl,建立了2次連接,因為http1.1默認就開啟了keep-alive,所以根據前麵try-finally裏邏輯,一次連接的過程被創建的SocketProcessor實例數會比它實際的請求數多1個。所以這2次curl命令(每次的請求為1),沒有複用socket,共創建了2個SocketWrapper實例和4個SocketProcessor實例。正好是2倍關係。

如果複用socket,則SocketProcessor實例數應該比SocketWrapper的實例數多不止一倍,比如下麵用zsh模擬10次請求:

n=0; 
while (( n < 10 ));do  
    n=$((n+1)); 
    echo -ne "GET /main HTTP/1.1\nhost: localhost:7001\n\n";
    sleep 1;
done | telnet localhost 7001

這10次請求是複用的同一個socket,在每次請求中間間隔了1秒,結束後再查看SocketProcessorSocketWrapper的實例數:

$ jmap -histo `pidof java` | sed -n -e '1,3p' -e '/SocketWrapper/p' -e '/SocketProcessor/p'

 num     #instances         #bytes  class name
----------------------------------------------
348:            11            264  org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor
669:             1             64  org.apache.tomcat.util.net.SocketWrapper

這次就一個socket的實例,task的實例數則是請求數+1,即11個。現實情況種這兩個實例數差出1~2個數量級也常見(說明socket被複用的比較多)。

BIO模式下keep-alive為什麼線程利用率不高?

再回到這次應用的例子中,為什麼切換到BIO模式的情況下,被使用的線程數有1091個左右,而NIO的則隻有44個,差距這麼大的原因是什麼?

其實上麵給出的官方對比的表格裏已經有答案了,BIO在處理下一次請求的時候是阻塞的,而NIO是非阻塞的。所謂阻塞是線程會一直掛在這個連接上等待新的數據到來。

正好這個應用的情況是開啟keep-alive保持長連接,然後每隔1秒鍾向tomcat發送一次數據。

如果要模擬他們的情況,可以用下麵的腳本:

while :; do 
    echo -ne "POST /main HTTP/1.1\nhost: localhost:7001\nContent-length:4\n\nData\n";
    sleep 1;
done | telnet localhost 7001

按說幾K到幾十K的數據最多不超過幾十毫秒,也就是說socket在90%以上的時間是空閑狀態,而BIO卻一直有一個線程會阻塞在上麵,白白浪費。

這裏有個細節,其實根據前邊的JIoEndpoint.SocketProcessortry-finally代碼段,它不一定是阻塞在同一個線程上,取決於線程池的實現,但總會占用一個線程資源。現在看一下在等待下一次請求時的線程是怎麼阻塞的:

$ { echo -e "GET /main HTTP/1.1\nhost: localhost:7001\n"; sleep 10 }  | telnet localhost 7001

上麵模擬了一次連接,請求結束後先不釋放,保持10秒鍾,以便我們執行jstack來看此時的線程情況:

$ jstack `pidof java` | grep "socketRead0" -B2 -A10

"http-bio-7001-exec-4" #28 daemon prio=5 os_prio=31 tid=0x00007f8a742c4000 nid=0x7d03 runnable [0x0000000128ceb000]
java.lang.Thread.State: RUNNABLE
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.read(SocketInputStream.java:150)
 at java.net.SocketInputStream.read(SocketInputStream.java:121)
 at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer.java:516)
 at org.apache.coyote.http11.InternalInputBuffer.fill(InternalInputBuffer.java:501)
 at org.apache.coyote.http11.Http11Processor.setRequestLineReadTimeout(Http11Processor.java:167)
 at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:946)
 at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
 at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
 - locked <0x00000007973b0298> (a org.apache.tomcat.util.net.SocketWrapper)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

看到這個堆棧信息和之前應用切換到BIO之後的情況一模一樣,之前以為客戶端發來的數據很多,這裏是正在讀取數據中,實際這裏是沒有請求數據過來,線程阻塞在這裏等待數據。

正是因為BIO的實現方式讓線程一直阻塞在長連接上,而這應用的長連接在絕大部分時間內又是沒有數據的,造成了線程的浪費,而APR和NIO則不會讓線程一直阻塞在長連接上,提高了線程的利用率。

2) APR模式下的keep-alive實現:

APR有點類似NIO,也有Poller線程的角色。在處理下一次請求的時候,不會像BIO那樣阻塞。下麵看一下在處理socket時的大致邏輯,摘自AbstractHttp11Processor.process方法做了簡化,這個類是BIO/NIO/APR三種模式處理socket邏輯時的基類,在開啟keep-alive的情況下會一直循環:

while ( keepAlive && !error && otherConditions ) {

    // Parsing the request header
    try {
        setRequestLineReadTimeout();

        if (!getInputBuffer().parseRequestLine(keptAlive)) {
            if (handleIncompleteRequestLineRead()) {
                break; //第一個break
            }
        }
        ...
    } catch (IOException e) {
        error = true;
    }

    ...
    prepareRequest();
    adapter.service(request, response); // 提交到後邊的servlet容器
    endRequest();
    ...        

    if (breakKeepAliveLoop(socketWrapper)) {
        break; //第二個break
    }
}        

APR模式在處理完一次請求後,再次進入循環時會在第一個break點跳出(得不到下次請求),把線程讓出來,後續socket再有請求時poller線程會再封裝一個任務(對應SocketProcessor類),不過APR模式下acceptor在收到socket之後會先封裝成一個SocketWithOptionsProcessor的task,它的作用隻是把socket跟poller關聯起來,真正處理請求時是靠poller。

下麵模擬3次請求:

$ n=0; 
$ while (( n < 3 ));do  
    n=$((n+1)); 
    echo -ne "GET /main HTTP/1.1\nhost: localhost:7001\n\n";
    sleep 1;
  done | telnet localhost 7001

觀察相關幾個類的實例數:

$ jmap -histo `pidof java` | sed -n -e '1,3p' -e '/SocketWrapper/p' -e '/Endpoint.*Processor/p'

 num     #instances         #bytes  class name
----------------------------------------------
 619:             1             72  org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper
 620:             3             72  org.apache.tomcat.util.net.AprEndpoint$SocketProcessor
 975:             1             24  org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor   

socket所對應AprSocketWrapper實例為1,說明隻有一個連接;SocketWithOptionsProcessor實例也為1,poller真正處理請求邏輯時還是用SocketProcessor封裝的邏輯,這裏3次請求對應3個實例數。注意有時候可能因為young-gc幹擾你看到的實例數,可以把heap設置大一些避免。

既然APR模式對下一次請求並不是阻塞,線程會釋放出來,為何應用方還是出現了阻塞呢?因為當時的環境已經不能複現了,無法準確判斷當時的網絡情況,但APR模式在處理header和body的時候都是阻塞的,所以一種很大的可能是當時client發送數據時,沒有發送完全,造成connector阻塞在jni.Socket.recvbb方法上。可以模擬一下這個情況:

$ { echo -ne "POST /main HTTP/1.1\nhost: localhost:7001"; sleep 15 } | telnet localhost 7001

上麵模擬的POST請求沒有發送完整,header部分還沒有結束,這時通過jstack來看線程的情況:

$ jstack `pidof java` | grep "recvbb" -B2 -A7

"http-apr-7001-exec-6" #33 daemon prio=5 os_prio=31 tid=0x00007fc8b2044000 nid=0x7e07 runnable [0x0000000120a20000]
java.lang.Thread.State: RUNNABLE
 at org.apache.tomcat.jni.Socket.recvbb(Native Method)
 at org.apache.coyote.http11.InternalAprInputBuffer.fill(InternalAprInputBuffer.java:575)
 at org.apache.coyote.http11.InternalAprInputBuffer.parseHeader(InternalAprInputBuffer.java:464)
 at org.apache.coyote.http11.InternalAprInputBuffer.parseHeaders(InternalAprInputBuffer.java:312)
 at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:969)
 at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
 at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2442)
 at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2431)

跟應用當時的情況是吻合的,當然如果client發送過程中如果body部分數據沒有發送完整也會讓tomcat阻塞在recvbb這個方法上。

3) NIO模式下的keep-alive實現:

NIO的大致結構也可以參考之前分享ali-tomcat的ppt裏的圖

對於keep-alive情況下處理下一次請求,NIO跟APR類似,線程不會一直阻塞在socket上。對於header的處理,NIO也同樣不會阻塞,隻有在body的讀取時,NIO采取模擬阻塞的方式。可以模擬一下,在一個servlet裏對post過來的數據回寫過去:

public void doPost(HttpServletRequest request, HttpServletResponse resp) throws IOException {
    PrintWriter wr = resp.getWriter();
    BufferedReader br = new BufferedReader(new InputStreamReader(request.getInputStream()));
    String line = null;
    while ((line = br.readLine()) != null) {
        wr.write(line);
    }
    wr.write("done");
}

模擬請求:

$ { 
    echo -ne "POST /main HTTP/1.1\nhost: localhost:7001\nContent-length:5\n\na";
    sleep 15
  } | telnet localhost 7001

請求裏描述的數據長度是5,但隻給出了一個字符,出於數據未發送完的狀態,這時來看服務器端線程狀況:

"http-nio-7001-exec-1" #26 daemon prio=5 os_prio=31 tid=0x00007f8693c52800 nid=0x7a07 waiting on condition [0x00000001268f6000]
java.lang.Thread.State: TIMED_WAITING (parking)
 at sun.misc.Unsafe.park(Native Method)
 - parking to wait for  <0x0000000795ca3b50> (a java.util.concurrent.CountDownLatch$Sync)
 at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
 at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
 at org.apache.tomcat.util.net.NioEndpoint$KeyAttachment.awaitLatch(NioEndpoint.java:1566)
 at org.apache.tomcat.util.net.NioEndpoint$KeyAttachment.awaitReadLatch(NioEndpoint.java:1568)
 at org.apache.tomcat.util.net.NioBlockingSelector.read(NioBlockingSelector.java:185)
 at org.apache.tomcat.util.net.NioSelectorPool.read(NioSelectorPool.java:246)
 at org.apache.tomcat.util.net.NioSelectorPool.read(NioSelectorPool.java:227)
 at org.apache.coyote.http11.InternalNioInputBuffer.readSocket(InternalNioInputBuffer.java:422)
 at org.apache.coyote.http11.InternalNioInputBuffer.fill(InternalNioInputBuffer.java:794)
 at org.apache.coyote.http11.InternalNioInputBuffer$SocketInputBuffer.doRead(InternalNioInputBuffer.java:819)
 at org.apache.coyote.http11.filters.IdentityInputFilter.doRead(IdentityInputFilter.java:124)
 at org.apache.coyote.http11.AbstractInputBuffer.doRead(AbstractInputBuffer.java:346)
 at org.apache.coyote.Request.doRead(Request.java:422)
 at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:290)
 at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:449)
 at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:315)
 at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:200)
 at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
 at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
 at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
 - locked <0x0000000795c96f28> (a java.io.InputStreamReader)
 at java.io.InputStreamReader.read(InputStreamReader.java:184)
 at java.io.BufferedReader.fill(BufferedReader.java:161)
 at java.io.BufferedReader.readLine(BufferedReader.java:324)
 - locked <0x0000000795c96f28> (a java.io.InputStreamReader)
 at java.io.BufferedReader.readLine(BufferedReader.java:389)
 at org.r113.servlet3.MainServlet.doPost(MainServlet.java:37)

線程並不是阻塞在原生的IO方法上,而是NioBlockingSelector.read方法上,這個方法從名字就可以看出它用NIO實現的阻塞式selector(裏麵的read和write方法注釋也有明確說明);相當於通過鎖的方式來模擬阻塞方式,正如之前表格裏紅色字體突出的。

為什麼NIO在讀取body時要模擬阻塞?

tomcat的NIO完全可以以非阻塞方式處理IO,為什麼在讀取body部分時要模擬阻塞呢?這是因為servlet規範裏定義了ServletInputStream在讀數據時是阻塞模式,這裏相關的爭論可以google。

在servlet3.0裏引入了異步,但僅針對傳統IO,對應用來說仍有很多限製,所以servlet3.1又引入了非阻塞IO,但這要tomcat8才提供了。

最後更新:2017-05-23 17:32:06

  上一篇:go  Quartz教程二:API,Job和Trigger
  下一篇:go  分享一個HP EVA4400/6400/8400/P6000通用的數據恢複方法