Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SocketTimeoutException with OkHttp 2.0.0 + Retrofit 1.6.1 #1037

Closed
laurentiuonac opened this issue Aug 28, 2014 · 10 comments
Closed

SocketTimeoutException with OkHttp 2.0.0 + Retrofit 1.6.1 #1037

laurentiuonac opened this issue Aug 28, 2014 · 10 comments
Labels
bug Bug in existing code
Milestone

Comments

@laurentiuonac
Copy link

Hello. I've been getting SocketTimeoutException intermittently. This is not an Internet connection issue. If I access the same link from the phone's browser it will open.

It happens mostly on WiFi, but it happens on mobile data also from time to time. After a random number of calls (usually below 20), the timeout occurs and any subsequent call will have the same result. It recovers after a while and works for another 20 calls or so. I cannot get an exact pattern or reason why this happens.

The endpoint is not blocking the app, tested with the backend guys.

mOkHttpClient = new OkHttpClient();
mOkHttpClient.setCache(cache);
mOkHttpClient.setConnectTimeout(REQ_TIMEOUT, TimeUnit.SECONDS);
mOkHttpClient.setReadTimeout(REQ_TIMEOUT, TimeUnit.SECONDS);

RestAdapter restAdapter = new RestAdapter.Builder()
                .setEndpoint(sEndpoint)
                .setClient(new OkClient(mOkHttpClient))
                .setLogLevel(RestAdapter.LogLevel.HEADERS)
                .build();

Any help will be greatly appreciated.

retrofit.RetrofitError: failed to connect to api.xyz.ro/89.xx.yy.37 (port 80) after 15000ms

@laurentiuonac laurentiuonac changed the title SocketTimeoutException with OkHttp 2.0.0. + Retrofit 1.6.1 SocketTimeoutException with OkHttp 2.0.0 + Retrofit 1.6.1 Aug 28, 2014
@swankjesse
Copy link
Collaborator

Got a full stack trace? That'll help us to identify whether it's a recycled connection or a new one.

@laurentiuonac
Copy link
Author

Here is a full stack trace for 3 requests. URLs have been masked due to private API.
This is all I can get from retrofit's log level (setLogLevel(RestAdapter.LogLevel.FULL)).

08-29 12:06:06.093  19700-19720/com.app.package D/Retrofit﹕ ---> HTTP GET http://api.domain.com/api2/random/files.browse?offset=0&limit=10
08-29 12:06:06.093  19700-19720/com.app.package D/Retrofit﹕ Cache-Control: max-stale=60
08-29 12:06:06.093  19700-19720/com.app.package D/Retrofit﹕ Cookie: login=cookie
08-29 12:06:06.093  19700-19720/com.app.package D/Retrofit﹕ ---> END HTTP (no body)
08-29 12:06:06.113  19700-19721/com.app.package D/Retrofit﹕ ---> HTTP GET http://api.domain.com/api2/random/users.browse?friends=accepted&for=vlad&limit=10&offset=0
08-29 12:06:06.113  19700-19721/com.app.package D/Retrofit﹕ Cache-Control: max-stale=60
08-29 12:06:06.113  19700-19721/com.app.package D/Retrofit﹕ Cookie: login=cookie
08-29 12:06:06.113  19700-19721/com.app.package D/Retrofit﹕ ---> END HTTP (no body)
08-29 12:06:06.133  19700-19725/com.app.package D/Retrofit﹕ ---> HTTP GET http://api.domain.com/api2/random/users.details?username=vlad
08-29 12:06:06.133  19700-19725/com.app.package D/Retrofit﹕ Cache-Control: max-stale=60
08-29 12:06:06.133  19700-19725/com.app.package D/Retrofit﹕ Cookie: login=cookie
08-29 12:06:06.133  19700-19725/com.app.package D/Retrofit﹕ ---> END HTTP (no body)
08-29 12:06:06.183  19700-19700/com.app.package I/Adreno-EGL﹕ <qeglDrvAPI_eglInitialize:320>: EGL 1.4 QUALCOMM Build: I0404c4692afb8623f95c43aeb6d5e13ed4b30ddbDate: 11/06/13
08-29 12:06:06.233  19700-19700/com.app.package D/OpenGLRenderer﹕ Enabling debug mode 0
08-29 12:06:21.483  19700-19720/com.app.package D/Retrofit﹕ ---- ERROR http://api.domain.com/api2/random/files.browse?offset=0&limit=10
08-29 12:06:21.503  19700-19725/com.app.package D/Retrofit﹕ ---- ERROR http://api.domain.com/api2/random/users.details?username=vlad
08-29 12:06:21.513  19700-19721/com.app.package D/Retrofit﹕ ---- ERROR http://api.domain.com/api2/random/users.browse?friends=accepted&for=vlad&limit=10&offset=0
08-29 12:06:21.523  19700-19725/com.app.package D/Retrofit﹕ java.net.SocketTimeoutException: failed to connect to api.domain.com/89.xx.yy.37 (port 80) after 15000ms
            at libcore.io.IoBridge.connectErrno(IoBridge.java:159)
            at libcore.io.IoBridge.connect(IoBridge.java:112)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:192)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:459)
            at java.net.Socket.connect(Socket.java:843)
            at com.squareup.okhttp.internal.Platform$Android.connectSocket(Platform.java:220)
            at com.squareup.okhttp.Connection.connect(Connection.java:148)
            at com.squareup.okhttp.OkHttpClient$1.connect(OkHttpClient.java:84)
            at com.squareup.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:321)
            at com.squareup.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:241)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:420)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:371)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:466)
            at retrofit.client.UrlConnectionClient.readResponse(UrlConnectionClient.java:73)
            at retrofit.client.UrlConnectionClient.execute(UrlConnectionClient.java:38)
            at retrofit.RestAdapter$RestHandler.invokeRequest(RestAdapter.java:321)
            at retrofit.RestAdapter$RestHandler.access$100(RestAdapter.java:220)
            at retrofit.RestAdapter$RestHandler$2.obtainResponse(RestAdapter.java:278)
            at retrofit.CallbackRunnable.run(CallbackRunnable.java:42)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at retrofit.Platform$Android$2$1.run(Platform.java:142)
            at java.lang.Thread.run(Thread.java:811)
08-29 12:06:21.523  19700-19721/com.app.package D/Retrofit﹕ java.net.SocketTimeoutException: failed to connect to api.domain.com/89.xx.yy.37 (port 80) after 15000ms
            at libcore.io.IoBridge.connectErrno(IoBridge.java:159)
            at libcore.io.IoBridge.connect(IoBridge.java:112)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:192)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:459)
            at java.net.Socket.connect(Socket.java:843)
            at com.squareup.okhttp.internal.Platform$Android.connectSocket(Platform.java:220)
            at com.squareup.okhttp.Connection.connect(Connection.java:148)
            at com.squareup.okhttp.OkHttpClient$1.connect(OkHttpClient.java:84)
            at com.squareup.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:321)
            at com.squareup.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:241)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:420)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:371)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:466)
            at retrofit.client.UrlConnectionClient.readResponse(UrlConnectionClient.java:73)
            at retrofit.client.UrlConnectionClient.execute(UrlConnectionClient.java:38)
            at retrofit.RestAdapter$RestHandler.invokeRequest(RestAdapter.java:321)
            at retrofit.RestAdapter$RestHandler.access$100(RestAdapter.java:220)
            at retrofit.RestAdapter$RestHandler$2.obtainResponse(RestAdapter.java:278)
            at retrofit.CallbackRunnable.run(CallbackRunnable.java:42)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at retrofit.Platform$Android$2$1.run(Platform.java:142)
            at java.lang.Thread.run(Thread.java:811)
08-29 12:06:21.523  19700-19721/com.app.package D/Retrofit﹕ ---- END ERROR
08-29 12:06:21.523  19700-19725/com.app.package D/Retrofit﹕ ---- END ERROR
08-29 12:06:21.523  19700-19720/com.app.package D/Retrofit﹕ java.net.SocketTimeoutException: failed to connect to api.domain.com/89.xx.yy.37 (port 80) after 15000ms
            at libcore.io.IoBridge.connectErrno(IoBridge.java:159)
            at libcore.io.IoBridge.connect(IoBridge.java:112)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:192)
            at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:459)
            at java.net.Socket.connect(Socket.java:843)
            at com.squareup.okhttp.internal.Platform$Android.connectSocket(Platform.java:220)
            at com.squareup.okhttp.Connection.connect(Connection.java:148)
            at com.squareup.okhttp.OkHttpClient$1.connect(OkHttpClient.java:84)
            at com.squareup.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:321)
            at com.squareup.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:241)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:420)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:371)
            at com.squareup.okhttp.internal.huc.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:466)
            at retrofit.client.UrlConnectionClient.readResponse(UrlConnectionClient.java:73)
            at retrofit.client.UrlConnectionClient.execute(UrlConnectionClient.java:38)
            at retrofit.RestAdapter$RestHandler.invokeRequest(RestAdapter.java:321)
            at retrofit.RestAdapter$RestHandler.access$100(RestAdapter.java:220)
            at retrofit.RestAdapter$RestHandler$2.obtainResponse(RestAdapter.java:278)
            at retrofit.CallbackRunnable.run(CallbackRunnable.java:42)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at retrofit.Platform$Android$2$1.run(Platform.java:142)
            at java.lang.Thread.run(Thread.java:811)
08-29 12:06:21.523  19700-19720/com.app.package D/Retrofit﹕ ---- END ERROR

@Zhelyazko
Copy link

I'm getting the same exception with the same lib versions + okio_1.0.0 and okhttp-urlconnection_2.0.0.
The pattern for the Exception is similar on my side with the slight difference that I may make up to 40 or more requests before getting the timeout.

The stacktrace is the same. It is happening on Android 4.1, 4.2 and 4.4.
Other libs included in the project are aSmack 8-4.0.4, picasso 2.3.2, dnsJava 2.1.6.
I'm also using some tracking libs as AppSee and Crittercism.

I'm ready to help as needed because this issue is stopping me from releasing an app.

Edit: I'm sending requests over HTTPS but the Exception is thrown both on HTTP and HTTPS.

Edit2: I've removed okhttp, okhttp_urlconnection and okio from my project and made some tests on Nexus 4 running stock Android 4.4.4 and I was still getting the SocketTimeoutException. I don't know exactly which version of okhttp is built into 4.4.4 but the issue is present there as well.

@Zhelyazko
Copy link

Probably the issue is not in okhttp. I managed to get my hands on a Samsung Galaxy S2 running Android 4.0.3 and tested it with Retrofit + HttpUrlConnection like this:

UrlConnectionClient urlClient = new UrlConnectionClient();

mRestAdapter = new RestAdapter.Builder()
        .setEndpoint(BASE_URL)
        .setClient(urlClient)
        .setConverter(new GsonConverter(mGson))
        .setLogLevel(LogLevel.FULL)
        .build();

and I keep getting the SocketTimeoutException on random. I guess that the issue is not in OkHttp as the Galaxy S2 is not supported by OkHttp as far as I can see in the logs. This makes me think that the issue is either in Retrofit or some of the libraries in my project is causing all the issues.

@udbhav3000
Copy link

I am getting the same issue. with the same stack trace. I was getting the timeout exception (on wifi networks only and randomly) on the loopj library built on apache aysnc. Which was the reason I am migrating to okhttp. I am beginning to think, this is not a issue with okhttp. Attached are both stack traces.

From my older library (loopJ)

09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): org.apache.http.conn.ConnectTimeoutException: Connect to /54.254.217.139:80 timed out 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:121) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:144) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:164) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:119) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:374) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:575) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:498) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at com.loopj.android.http.AsyncHttpRequest.makeRequest(AsyncHttpRequest.java:98) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at com.loopj.android.http.AsyncHttpRequest.makeRequestWithRetries(AsyncHttpRequest.java:112) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at com.loopj.android.http.AsyncHttpRequest.run(AsyncHttpRequest.java:68) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at java.util.concurrent.FutureTask.run(FutureTask.java:237) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587) 09-25 18:04:16.070: W/CustomJsonHttpResponseHandler(18824): at java.lang.Thread.run(Thread.java:841)

and from the okhttp request

09-25 18:04:16.074: W/System.err(18824): java.net.SocketTimeoutException: failed to connect to api.domain.com/***.***.***.*** (port 80) after 30000ms 09-25 18:04:16.078: W/System.err(18824): at libcore.io.IoBridge.connectErrno(IoBridge.java:159) 09-25 18:04:16.078: W/System.err(18824): at libcore.io.IoBridge.connect(IoBridge.java:112) 09-25 18:04:16.078: W/System.err(18824): at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:192) 09-25 18:04:16.078: W/System.err(18824): at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:460) 09-25 18:04:16.078: W/System.err(18824): at java.net.Socket.connect(Socket.java:833) 09-25 18:04:16.078: W/System.err(18824): at com.squareup.okhttp.internal.Platform$Android.connectSocket(Platform.java:220) 09-25 18:04:16.079: W/System.err(18824): at com.squareup.okhttp.Connection.connect(Connection.java:148) 09-25 18:04:16.079: W/System.err(18824): at com.squareup.okhttp.OkHttpClient$1.connect(OkHttpClient.java:84) 09-25 18:04:16.079: W/System.err(18824): at com.squareup.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:321) 09-25 18:04:16.079: W/System.err(18824): at com.squareup.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:241) 09-25 18:04:16.079: W/System.err(18824): at com.squareup.okhttp.Call.getResponse(Call.java:198) 09-25 18:04:16.080: W/System.err(18824): at com.squareup.okhttp.Call.access$200(Call.java:36) 09-25 18:04:16.080: W/System.err(18824): at com.squareup.okhttp.Call$AsyncCall.execute(Call.java:143) 09-25 18:04:16.080: W/System.err(18824): at com.squareup.okhttp.internal.NamedRunnable.run(NamedRunnable.java:33) 09-25 18:04:16.080: W/System.err(18824): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112) 09-25 18:04:16.080: W/System.err(18824): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587) 09-25 18:04:16.081: W/System.err(18824): at java.lang.Thread.run(Thread.java:841)

@swankjesse
Copy link
Collaborator

Possibly due to connection reuse + networks on the device changing. For example, going from WiFi to 3G. We've got some changes coming that will detect network changes and evict connections from the pool.

@swankjesse swankjesse added the bug Bug in existing code label Sep 28, 2014
@swankjesse swankjesse added this to the 2.1 milestone Sep 28, 2014
@Zhelyazko
Copy link

It's not from connection changes, at least not in my case - the devices are connected to WiFi in the office.
However we've resolved the issue - it was server side. We had to disable tcp_timestamp on the server side and everything worked perfectly.

@swankjesse
Copy link
Collaborator

No clear action to take on this.

@apoorvparijat
Copy link

@Zhelyazko's solution worked. You need to disable tcp_timestamp by changing sysctl configuration on the API server. Also, if you have other services working over TCP on the same machine i.e. Redis etc., you should watch out for how this affects them.

@tbnzey
Copy link

tbnzey commented May 26, 2017

Solution details address:http://www.jianshu.com/p/dde236d7211d

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Bug in existing code
Projects
None yet
Development

No branches or pull requests

6 participants