330
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的調用底層阻塞在poll或epoll_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 https://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 https://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 https://localhost:7001/main
$ curl https://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秒，結束後再查看SocketProcessor和SocketWrapper的實例數:
$ 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.SocketProcessor的try-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