Requests delayed, first app-usage after connecting to VPN

[AlmogBaku]

Steps to reproduce:

1. I have a Retrofit API that using OkHTTP
2. After connecting to the VPN, I'm opening my app, and on launch doing a GET request.

Results:

1. The request is delayed
2. logs:

07-11 14:17:12.355  26754-26778/net.rimoto.android W/art﹕ Suspending all threads took: 11.591ms
07-11 14:17:12.643  26754-26978/net.rimoto.android D/Retrofit﹕ ---> HTTP GET http://api.com/api/subscriber/me/policy?access_token=MjJkY2MwYjYzOWI5MzJmYTM3MGI4MzYxNTY4Y2M0NjZkZjdmYjRmNzk1OTY2MWQ1NjkwMmRiZWEwNTQ4MjFjMQ
07-11 14:17:12.643  26754-26978/net.rimoto.android D/Retrofit﹕ ---> END HTTP (no body)
07-11 14:17:12.725  26754-26754/net.rimoto.android E/RecyclerView﹕ No adapter attached; skipping layout
07-11 14:17:12.827  26754-26754/net.rimoto.android E/RecyclerView﹕ No adapter attached; skipping layout
07-11 14:17:13.294  26754-26754/net.rimoto.android I/art﹕ Explicit concurrent mark sweep GC freed 29191(1625KB) AllocSpace objects, 48(1783KB) LOS objects, 39% free, 10MB/17MB, paused 1.085ms total 82.351ms
07-11 14:17:18.354  26754-26778/net.rimoto.android W/art﹕ Suspending all threads took: 10.864ms
07-11 14:17:18.366  26754-26790/net.rimoto.android I/art﹕ Explicit concurrent mark sweep GC freed 8672(455KB) AllocSpace objects, 2(165KB) LOS objects, 40% free, 9MB/16MB, paused 1.258ms total 55.734ms
07-11 14:17:18.372  26754-26790/net.rimoto.android W/art﹕ Suspending all threads took: 5.978ms
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ <--- HTTP 200 http://api.com/api/subscriber/me/policy?access_token=MjJkY2MwYjYzOWI5MzJmYTM3MGI4MzYxNTY4Y2M0NjZkZjdmYjRmNzk1OTY2MWQ1NjkwMmRiZWEwNTQ4MjFjMQ (22125ms)
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Server: nginx/1.6.2
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Content-Type: application/json
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Transfer-Encoding: chunked
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Connection: keep-alive
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Cache-Control: max-age=900, private
07-11 14:17:34.770  26754-26978/net.rimoto.android D/Retrofit﹕ Date: Sat, 11 Jul 2015 11:17:35 GMT
07-11 14:17:34.771  26754-26978/net.rimoto.android D/Retrofit﹕ Allow: POST, GET, DELETE
07-11 14:17:34.771  26754-26978/net.rimoto.android D/Retrofit﹕ OkHttp-Selected-Protocol: http/1.1
07-11 14:17:34.771  26754-26978/net.rimoto.android D/Retrofit﹕ OkHttp-Sent-Millis: 1436613454422
07-11 14:17:34.771  26754-26978/net.rimoto.android D/Retrofit﹕ OkHttp-Received-Millis: 1436613454769
07-11 14:17:34.791  26754-26978/net.rimoto.android D/Retrofit﹕ [{"id":555,"name":"appPolicy","max_bandwidth":100,"expires_in":129600,"start_time":"2015-07-11T14:17:12+0300","end_time":"2015-10-09T14:17:12+0300","services":[{"id":4,"name":"whatsapp","slug":"whatsapp","description":"WhatsApp messages-only","android_bundle_id":"com.whatsapp","tags":[{"id":3,"name":"messaging","slug":"messaging"}]},{"id":7,"name":"Uber","slug":"uber","android_bundle_id":"com.ubercab","web_app":"https:\/\/m.uber.com","tags":[{"id":4,"name":"transportation","slug":"transportation"}]},{"id":8,"name":"Waze","slug":"waze","android_bundle_id":"com.waze","tags":[{"id":4,"name":"transportation","slug":"transportation"}]},{"id":11,"name":"booking","slug":"booking_com","description":"Booking.com","android_bundle_id":"com.booking","web_app":"https:\/\/m.booking.com","tags":[{"id":6,"name":"booking","slug":"booking"}]},{"id":12,"name":"tripadvisor","slug":"tripadvisor","android_bundle_id":"com.tripadvisor.tripadvisor","web_app":"https:\/\/www.tripadvisor.com","tags":[{"id":6,"name":"booking","slug":"booking"}]}]}]
07-11 14:17:34.791  26754-26978/net.rimoto.android D/Retrofit﹕ <--- END HTTP (1035-byte body)

Additional info:

1. I tried to do a GET request in parallel to the OkHTTP, the Volley response came immediately
2. After removing the OkHTTP, the Retrofit fallback to use the native android networking- which was fast as expected.

[swankjesse]

It's likely that the connection pool is stale. We need to detect the network change and automatically evict those connections.

If you'd like a workaround, if you can detect the VPN change then you should clear the connection pool.

[AlmogBaku]

Thanks for the quick response.
What does it mean "clear the connection pool"? And what is this pool?

For the time being, I just disabled the usage of okhttp with retrofit. But
I'd like to try "clearing the pool" in order to verify this bug.

On Sunday, July 12, 2015, Jesse Wilson notifications@github.com wrote:

It's likely that the connection pool is stale. We need to detect the
network change and automatically evict those connections.

If you'd like a workaround, if you can detect the VPN change then you
should clear the connection pool.

—
Reply to this email directly or view it on GitHub
#1747 (comment).

---

Q: Why is this email five sentences or less?
A: http://five.sentenc.es

[swankjesse]

@AlmogBaku

    OkHttpClient client = ...;
    client.getConnectionPool().evictAll();

[AlmogBaku]

my connection pool is null

[AlmogBaku]

Okay, I initialize the ConnectionPool to the default at start.. then cleared it after every connection, disconnection.. and it worked:

okHttpClient.setConnectionPool(ConnectionPool.getDefault());

        okHttpClient.getConnectionPool().evictAll();

[dotgc]

There is no point of keeping the connection pool if you are going to simply evict it every time. If you don't want the pool, you're better off just setting the system property.

System.setProperty("http.keepAlive", "false");

You can add this to the onCreate of your application class.

[swankjesse]

Tracking as #1747

[AlmogBaku]

Jesse, 1747 is the current issue.

On Saturday, August 1, 2015, Jesse Wilson notifications@github.com wrote:

Tracking as #1747 #1747

—
Reply to this email directly or view it on GitHub
#1747 (comment).

---

Q: Why is this email five sentences or less?
A: http://five.sentenc.es

[swankjesse]

Ha! thanks @AlmogBaku. Meant to say tracking as #1780.