java.net.SocketInputStream.socketRead0 掛起執行緒
阿新 • • 發佈：2018-12-16
背景
現在的Java EE 系統通常都依賴於遠端服務，需要通過網路請求獲取遠端服務。不管是使用什麼協議（HTTP，HTTPS，JDBC 等）請求遠端服務，Java VM最終都將委託給Socket去實現。首先會通過connect方法與遠端服務建立連線，連線建立成功後就可以 write/read 與遠端服務實現資料通訊。
Socket.connect()、Socket.write()、Socket.read() 方法呼叫都被稱為阻塞IO呼叫。這些呼叫由於網路延時、伺服器響應緩慢等問題往往會導致執行緒掛起。
請看下面的客戶端和遠端服務通訊過程：
問題
公司推送服務突然出現問題，該服務需要HTTP遠端呼叫第三方的服務提供商。
問題排查
通過檢視日誌發現谷歌的FCM推送了最後一條訊息，並且沒有推送完成。然後 jps -lvm 命令超出推送服務程序號，再用jstack -l pid檢視堆疊資訊。發現有大量的java.net.SocketInputStream.socketRead0 執行緒處於掛起狀態：
"http-nio-10251-exec-1213" #86023 daemon prio=5 os_prio=0 tid=0x00007f838c0f8000 nid=0x1f9 runnable [0x00007f83693bd000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:983) - locked <0x00000000da936c90> (a java.lang.Object) at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:940) at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) - locked <0x00000000da936ca8> (a sun.security.ssl.AppInputStream) at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) - locked <0x00000000da9372b8> (a java.io.BufferedInputStream) at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735) at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678) at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569) - locked <0x00000000da180448> (a sun.net.www.protocol.https.DelegateHttpsURLConnection) at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474) - locked <0x00000000da180448> (a sun.net.www.protocol.https.DelegateHttpsURLConnection) at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480) at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338) at com.google.api.client.http.javanet.NetHttpResponse.<init>(NetHttpResponse.java:37) at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:105) at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:981) at com.google.firebase.messaging.FirebaseMessaging$1.execute(FirebaseMessaging.java:254) at com.google.firebase.messaging.FirebaseMessaging$1.execute(FirebaseMessaging.java:240) at com.google.firebase.internal.CallableOperation.call(CallableOperation.java:36) at com.google.firebase.messaging.FirebaseMessaging.send(FirebaseMessaging.java:157) at com.google.firebase.messaging.FirebaseMessaging.send(FirebaseMessaging.java:143) at com.manniu.sns.core.service.FCMPush.push(FCMPush.java:105) at com.manniu.sns.core.controller.SnsController.push(SnsController.java:99) at sun.reflect.GeneratedMethodAccessor74.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) - locked <0x00000000da70ba18> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - <0x00000000da813810> (a java.util.concurrent.ThreadPoolExecutor$Worker) "http-nio-10251-exec-1212" #85644 daemon prio=5 os_prio=0 tid=0x00007f8390473800 nid=0x7d04 runnable [0x00007f83683ac000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:983) - locked <0x00000000dacf5770> (a java.lang.Object) - ..... - .....
問題的解決
由堆疊資訊可以看出大量的執行緒阻塞到socket讀的地方，推斷可能是由於網路延遲或FCM服務連線後沒有響應造成 java.net.SocketInputStream.socketRead0一直阻塞等待讀取。當客戶端與遠端服務連接出現長時間未連線成功或讀寫出現長時間阻塞時，就應該停止連線或讀寫。HTTP連線時可以設定相關connect超時時間和Read超時時間，因此在FCM相關的客戶端程式碼中設定超時時間。
FirebaseOptions options = new FirebaseOptions.Builder() .setCredentials(GoogleCredentials.fromStream(serviceAccount)) .setDatabaseUrl(config.getApiSecret()) .setReadTimeout(10000) .setConnectTimeout(10000) .build();
結論
由上面的問題可以得出：當 java.net.SocketInputStream.socketRead0 執行緒一直處於掛起阻塞狀態時，很可能的原因是沒有設定超時時間（timeout）。在請求遠端服務時一定要注意設定timeout。