时间戳

首页 > 解决方案 > Android 网络调用有时会卡在 IOException ：java.net.SocketTimeoutException: timeout

java - Android 网络调用有时会卡在 IOException ：java.net.SocketTimeoutException: timeout

问题描述

我有一个应用程序可以上传一些文件（png、mp4）。完整的堆栈是它背后的 Nginx + Node 服务器。有时，当互联网出现问题时，似乎一些用户在生产中遇到了奇怪的行为，然后 Android 应用程序无法发送进一步的上传请求，因为他们都得到 : IOException : java.net.SocketTimeoutException: timeout。

然而，最奇怪的是我们看到服务器确实发送了响应（409 冲突，意味着正在上传的文件已经存在并完成上传），但 Android 应用程序根本没有收到这些响应，只是继续尝试上传那些文件，但连接不断失败，因为 SocketTimeoutException 一次又一次，而不是收到 409 响应。

然后，一段时间后，它恢复正常，突然可以收到 409 响应并继续，好像一切都很好。

我尝试使用最基本的 HttpUrlConnection 以及 Square 的 OkHttp 库，但结果相同。

当我使用 Okhttp + HTTP/2 + 代理对其进行调试以监视请求时，在帧日志记录中我看到（启用了代理）：

02-16 13:30:16.047  2719  6597 D okhttp.Http2: << 0x00000003     4 RST_STREAM    
02-16 13:30:16.049  2719  3758 D okhttp.TaskRunner: Q10117 canceled              : OkHttp ConnectionPool
02-16 13:30:16.051  2719  6597 D okhttp.Http2: >> 0x00000000     8 GOAWAY        
02-16 13:30:16.051  2719  6597 D okhttp.TaskRunner: Q10121 finished run in  60 s : <our server>

此时我的代码已经收到来自我的服务器实现的错误。然后我看到：

02-16 13:30:20.129  2719  3758 D okhttp.Http2: >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
02-16 13:30:20.131  2719  3758 D okhttp.Http2: >> 0x00000000     6 SETTINGS      
02-16 13:30:20.132  2719  3758 D okhttp.Http2: >> 0x00000000     4 WINDOW_UPDATE 
02-16 13:30:20.133  2719  3758 D okhttp.TaskRunner: Q10157 scheduled after   0 µs: OkHttp <our server>
02-16 13:30:20.135  2719  3758 D okhttp.TaskRunner: Q10153 scheduled after   0 µs: OkHttp ConnectionPool
02-16 13:30:20.135  2719  7381 D okhttp.TaskRunner: Q10157 starting              : OkHttp <our server>
02-16 13:30:20.136  2719  7365 D okhttp.TaskRunner: Q10153 starting              : OkHttp ConnectionPool
02-16 13:30:20.137  2719  7365 D okhttp.TaskRunner: Q10153 run again after 300 s : OkHttp ConnectionPool
02-16 13:30:20.137  2719  7365 D okhttp.TaskRunner: Q10153 finished run in   1 ms: OkHttp ConnectionPool
02-16 13:30:20.138  2719  3758 D okhttp.Http2: >> 0x00000003  1063 HEADERS       END_HEADERS
02-16 13:30:20.145  2719  7381 D okhttp.Http2: << 0x00000000    18 SETTINGS      
02-16 13:30:20.146  2719  7381 D okhttp.TaskRunner: Q10154 scheduled after   0 µs: OkHttp <our server> applyAndAckSettings
02-16 13:30:20.147  2719  7381 D okhttp.Http2: << 0x00000000     4 WINDOW_UPDATE 
02-16 13:30:20.147  2719  7365 D okhttp.TaskRunner: Q10154 starting              : OkHttp <our server> applyAndAckSettings
02-16 13:30:20.149  2719  7365 D okhttp.TaskRunner: Q10156 scheduled after   0 µs: OkHttp <our server> onSettings
02-16 13:30:20.151  2719  6597 D okhttp.TaskRunner: Q10156 starting              : OkHttp <our server> onSettings
02-16 13:30:20.151  2719  6597 D okhttp.TaskRunner: Q10156 finished run in   1 ms: OkHttp <our server> onSettings
02-16 13:30:20.152  2719  7365 D okhttp.Http2: >> 0x00000000     0 SETTINGS      ACK
02-16 13:30:20.153  2719  3758 D okhttp.Http2: >> 0x00000003 65535 DATA          
02-16 13:30:20.153  2719  7365 D okhttp.TaskRunner: Q10154 finished run in   6 ms: OkHttp <our server> applyAndAckSettings
02-16 13:30:20.156  2719  3758 D okhttp.Http2: >> 0x00000003     1 DATA          
02-16 13:30:20.231  2719  7381 D okhttp.Http2: << 0x00000000     0 SETTINGS      ACK

按照@Yuri Schimke 的建议，我添加了 PrintingEventListener，这就是我得到的：

2021-02-17 09:18:50.056 28203-28286/<package name> I/System.out: (HTTPLog)-Static: isSBSettingEnabled false
2021-02-17 09:18:53.378 28203-28286/<package name>  I/System.out: 0.000 callStart
2021-02-17 09:18:53.460 28203-28286/<package name>  I/System.out: 0.081 proxySelectStart
2021-02-17 09:18:53.462 28203-28286/<package name>  I/System.out: 0.084 proxySelectEnd
2021-02-17 09:18:53.462 28203-28286/<package name>  I/System.out: 0.084 dnsStart
2021-02-17 09:18:53.463 28203-28286/<package name>  I/System.out: 0.085 dnsEnd
2021-02-17 09:18:53.475 28203-28286/<package name>  I/System.out: 0.096 connectStart
2021-02-17 09:18:53.650 28203-28286/<package name>  I/System.out: 0.271 secureConnectStart
2021-02-17 09:18:53.796 28203-28286/<package name>  I/System.out: 0.418 secureConnectEnd
2021-02-17 09:18:53.834 28203-28286/<package name>  I/System.out: 0.456 connectEnd
2021-02-17 09:18:53.839 28203-28286/<package name>  I/System.out: 0.461 connectionAcquired
2021-02-17 09:18:53.870 28203-28286/<package name>  I/System.out: 0.492 requestHeadersStart
2021-02-17 09:18:53.891 28203-28286/<package name>  I/System.out: 0.513 requestHeadersEnd
2021-02-17 09:18:53.891 28203-28286/<package name>  I/System.out: 0.513 requestBodyStart
2021-02-17 09:19:03.382 28203-28286/<package name>  I/System.out: 10.003 requestFailed
2021-02-17 09:19:03.391 28203-28311/<package name>  I/System.out: 10.012 canceled
2021-02-17 09:19:03.399 28203-28286/<package name>  I/System.out: 10.021 connectionReleased
2021-02-17 09:19:03.400 28203-28286/<package name>  I/System.out: 10.022 callFailed

标签： javaandroidnetworkingokhttp

解决方案

暂时忽略您的具体问题。第一个挑战是提出一个 Stackoverflow 响应者可以轻松帮助您取得进展的问题。这里的每个人都想帮助你的问题。

阅读https://stackoverflow.com/help/how-to-ask和http://sscce.org

对于 OkHttp，使用它提供的调试工具来获取解释正在发生的事情的额外数据，即使它不是立即清楚。您是否要返回多条路线，而第一条路线很慢，然后被标记为坏路线？

事件记录 - https://square.github.io/okhttp/events/

HTTP/2 帧日志记录（如果可以启用）- https://square.github.io/okhttp/debug_logging/#http2-frame-logging

运行调试器并捕获正在发生的事情的堆栈跟踪？IO 线程是否仍在读取和阻塞网络？

推荐阅读