java.io.IOException 斷開的管道 解決方法 ClientAbortException: java.io.IOException: Broken pipe
今天公司技術支援的童鞋報告一個客戶的服務不工作了,緊急求助,於是遠端登陸上伺服器排查問題。
檢視採集資料的tomcat日誌,習慣性的先翻到日誌的最後去檢視有沒有異常的列印,果然發現了好幾種異常資訊,但是最多還是這個:
24-Nov-2016 09:54:21.116 SEVERE [http-nio-8081-Acceptor-0] org.apache.tomcat.util.net.NioEndpoint$Acceptor.run Socket accept failed java.io.IOException: Too many open files at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241) at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:688) at java.lang.Thread.run(Thread.java:745)
“Too manay open files” 問題很明顯啊,檔案描述符超出限制導致無法開啟檔案或建立網路連線,這個問題又會導致一些其它問題的產生,肯定是ulimit沒有優化,於是檢查ulimit的設定;
[[email protected] logs]# 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) 62819 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 65535 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 62819 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited
open files竟然是65535,已經做過了優化,是不是先啟動的tomcat等服務,然後才對ulimit做的優化?有可能,這樣的話重啟一下服務就ok了,於是將全部服務重啟了一遍,執行正常了,不一會報表就顯示資料了,然後告訴技術支援,問題已經解決了,然後就去處理別的case了;
結果還不到20分鐘,技術支援說,報表又沒有資料了,於是又打資料採集的應用的tomcat日誌檢視,發現了一堆異常,全都是一個錯:
24-Nov-2016 09:54:24.574 WARNING [http-nio-18088-exec-699] org.apache.catalina.core.StandardHostValve.throwable Exception Processing ErrorPage[exceptionType=java.lang.Throwable, location=/views/error/500.jsp] org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:393) at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:426) at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:342) at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:295) at org.apache.catalina.connector.Response.finishResponse(Response.java:453) at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:378) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:537) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:658) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1556) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1513) 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)
這個異常非常多,看報錯資訊,是tomcat的connector在執行寫操作的時候發生了Broken pipe異常,connector是tomcat處理網路請求的,難道是網路出問題了,但是為什麼發生異常的都是寫,讀就沒問題呢?為了判斷是不是網路問題,於是用wget命令在本地訪問了一下伺服器的一個介面,結果發現等了好久都沒有響應,正常情況下應該是馬上就有響應的,這說明不是網路的原因,是伺服器的問題,又用命令查看了下當前tcpip連線的狀態:
[[email protected] logs]# netstat -n | awk '/^tcp/ {++state[$NF]} END {for(key in state) print key,"\t",state[key]}'
CLOSE_WAIT 3853
TIME_WAIT 40
ESTABLISHED 285
LAST_ACT 6
CLOSE_WAIT 狀態的連線竟然有3853個,這太不正常了,這說明是客戶端先關閉了連線,伺服器端沒有執行關閉連線的操作,導致伺服器端一直維持在CLOSE_WAIT的狀態,如果不對作業系統的keepalive做優化,這個狀態預設會維持兩個小時,查看了下系統的設定:
[[email protected] logs]# sysctl -a |grep keepalive
net.ipv4.tcp_keepalive_time = 7200
net.ipv4.tcp_keepalive_probes = 9
net.ipv4.tcp_keepalive_intvl = 75
果然是7200秒,這就解釋通了,為什麼第一次檢視tomcat日誌最後報錯都是“Too manay open files”異常,一定是在兩個小時內,close_wait狀態暴增,導致檔案描述符超過了65535的最大限制; 而這個狀態應該就是broken pipe 異常導致的,是什麼導致的broken pipe異常呢?為什麼探針關閉了連線,但是資料採集伺服器卻沒有關閉連線?報異常的是tomcat的connector,tomcat不可能會忘記呼叫close方法去關閉連線,排除了程式的問題,也想不出來是什麼導致的了;
於是去拿了往採集伺服器上傳資料的探針的日誌檢視,竟然有大量的一個異常:
2016-11-24 16:27:36,217 [TingYun Harvest Service 1] 166 WARN - Error occurred sending metric data to TingYun. There can be intermittent connection failures. Please wait for a short period of time: java.net.SocketTimeoutException: Read timed out
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_60]
at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_60]
at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_60]
at com.tingyun.agent.libs.org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SourceFile:136) ~[tingyun-agent-java.jar:2.1.3]
.................
都是read time out異常,那麼問題就明確了, 是探針端讀取超時了,斷開了連線,而這時候資料採集伺服器還在處理請求,它並不知道探針端已經斷開了連線,處理完請求後再將處理結果發給探針,就broken pipe了;原來這個異常是客戶端讀取超時關閉了連線,這時候伺服器端再向客戶端已經斷開的連線寫資料時就發生了broken pipe異常!
探針讀超時的時間是2分鐘,伺服器為什麼這麼長的時間都沒有響應呢?於是使用jstack命令匯出了tomcat的執行緒棧資訊進行分析,最後發現程式碼中有耗時的操作加了鎖,導致執行緒阻塞(保密原因,在這裡就不貼程式碼了);
這裡總結一下,給我發私信的有些朋友沒有get到Broken piple問題的重點,並不是只有超時才會導致這個問題,只要是連線斷開,再往這個斷開的連線上去執行寫操作,都會出現這個異常,客戶端超時斷開只是其中的一種情況:
另外,當看到“Too manay open files”異常的時候,通常做法除了檢查ulimit系統限制外,還應該看一下程序開啟的檔案控制代碼數,cat /proc/sys/fs/file-nr命令檢視系統總控制代碼數,當前應用開啟的檔案控制代碼數使用ls -l /proc/<pid>/fd | wc -l命令,這裡還好忽略了這一步,否則可能又要花費一些時間來查詢系統真正的問題;
通過這個案例可知,排查問題時,在有些情況下,你第一眼看到的異常資訊未必就是問題的根源所在,而是後續一些連鎖反應,尤其是當大量出現同一個異常的情況下,不要看最後一條異常日誌,應該先去日誌裡面查詢第一齣現該異常的位置,看看這個異常發生之前系統的狀況;
java tcp/ip異常
- 1 java.net.SocketTimeoutException .
- 2 java.net.BindException:Address already in use: JVM_Bind
該 異 常 發 生 在 服 務 器 端 進 行 new ServerSocket(port) 或者 socket.bind(SocketAddress bindpoint)操作時。
原因:與 port 一樣的一個埠已經被啟動,並進行監聽。此時用 netstat –an 命令,可以看到一個 Listending 狀態的埠。只需要找一個沒有被佔用的埠就能解決這個問題。
- 3 java.net.ConnectException: Connection refused: connect
該異常發生在客戶端進行 new Socket(ip, port)或者 socket.connect(address,timeout)操作時,原 因:指定 ip 地址的機器不能找到(也就是說從當前機器不存在到指定 ip 路由),或者是該 ip 存在,但找不到指定的埠進行監聽。應該首先檢查客戶端的 ip 和 port是否寫錯了,假如正確則從客戶端 ping 一下伺服器看是否能 ping 通,假如能 ping 通(服務伺服器端把 ping 禁掉則需要另外的辦法),則 看在伺服器端的監聽指定埠的程式是否啟動。
- 4 java.net.SocketException: Socket is closed
該異常在客戶端和伺服器均可能發生。異常的原因是己方主動關閉了連線後(呼叫了 Socket 的 close 方法)再對網路連線進行讀寫操作。
- 5 java.net.SocketException: Connection reset 或者Connect reset by peer:Socket write error
該異常在客戶端和伺服器端均有可能發生,引起該異常的原因有兩個,第一個就是假如一端的 Socket 被關閉(或主動關閉或者因為異常退出而引起的關閉), 另一端仍傳送資料,傳送的第一個資料包引發該異常(Connect reset by peer)。另一個是一端退出,但退出時並未關閉該連線,另 一 端 假 如 在 從 連 接 中 讀 數 據 則 拋 出 該 異 常(Connection reset)。簡單的說就是在連線斷開後的讀和寫操作引起的。
還有一種情況,如果一端傳送RST資料包中斷了TCP連線,另外一端也會出現這個異常,如果是tomcat,異常如下:
org.apache.catalina.connector.ClientAbortException: java.io.IOException: Connection reset by peer
阿里的tcp方式的健康檢查為了提高效能,省去揮手互動,直接傳送一個RST來終斷連線,就會導致伺服器端出現這個異常;
對於伺服器,一般的原因可以認為:
a)伺服器的併發連線數超過了其承載量,伺服器會將其中一些連線主動 Down 掉.
b)在資料傳輸的過程中,瀏覽器或者接收客戶端關閉了,而服務端還在向客戶端傳送資料。
- 6 java.net.SocketException: Broken pipe
該異常在客戶端和伺服器均有可能發生。在丟擲SocketExcepton:Connect reset by peer:Socket write error 後,假如再繼續寫資料則丟擲該異常。前兩個異常的解決方法是首先確保程式退出前關閉所有的網路連線,其次是要檢測對方的關閉連線操作,發現對方 關閉連線後自己也要關閉該連線。
對於 4 和 5 這兩種情況的異常,需要特別注意連線的維護。在短連線情況下還好,如果是長連線情況,對於連線狀態的維護不當,則非常容易出現異常。基本上對長連線需要做的就是:
a)檢測對方的主動斷連(對方呼叫了 Socket 的 close 方法)。因為對方主動斷連,另一方如果在進行讀操作,則此時的返回值是-1。所以一旦檢測到對方斷連,則主動關閉己方的連線(呼叫 Socket 的 close 方法)。
b)檢測對方的宕機、異常退出及網路不通,一般做法都是心跳檢測。雙方週期性的傳送資料給對方,同時也從對方接收“心跳資料”,如果連續幾個週期都沒有收到 對方心跳,則可以判斷對方或者宕機或者異常退出或者網路不通,此時也需要主動關閉己方連線;如果是客戶端可在延遲一定時間後重新發起連線。雖然 Socket 有一個keep alive 選項來維護連線,如果用該選項,一般需要兩個小時才能發現對方的宕機、異常退出及網路不通。
- 7 java.net.SocketException: Too many open files
原因: 作業系統的中開啟檔案的最大控制代碼數受限所致,常常發生在很多個併發使用者訪問伺服器的時候。因為為了執行每個使用者的應用伺服器都要載入很多檔案(new 一個socket 就需要一個檔案控制代碼),這就會導致開啟檔案的控制代碼的缺乏。
解決方式:
a)儘量把類打成 jar 包,因為一個 jar 包只消耗一個檔案控制代碼,如果不打包,一個類就消耗一個檔案控制代碼。
b)java 的 GC 不能關閉網路連線開啟的檔案控制代碼,如果沒有執行 close()則檔案控制代碼將一直存在,而不能被關閉。
也可以考慮設定 socket 的最大開啟 數來控制這個問題。對作業系統做相關的設定,增加最大檔案控制代碼數量。
ulimit -a 可以檢視系統目前資源限制,ulimit -n 10240 則可以修改,這個修改只對當前視窗有效。
- 8 Cannot assign requested address
1. 埠號被佔用,導致地址無法繫結:
java.net.BindException: Cannot assign requested address: bind:是由於IP地址變化導致的;
2. 伺服器網路配置異常:
/etc/hosts 中配置的地址錯誤;
3.還有一種情況是執行ipconfig 發現沒有環路地址,這是因為環路地址配置檔案丟失了;