Android Emulator initial network call delayed by several seconds
In my Android project I am using Retrofit/OKHTTP to connect to several API endpoints. I am observing that the initial network call will always be delayed by several seconds. This will happen if only one API call is made or multiple at the same time, it does not matter. This could be 30-40 seconds with absolutely no activity at all.
Any subsequent requests sent to any API Endpoint will fire immediately without delay. If airplane mode is toggled, again the next network call will be delayed by several seconds.
I can replicate the issue on both Ubuntu and Windows, so I don't think its an environment or configuration issue. The issue does not occur when I test using a physical device, making me suspect the Emulator is at fault.
I found: https://square.github.io/okhttp/changelogs/upgrading_to_okhttp_4/#advanced-profiling Which I suspect might have a role to play however I cannot disable "Advanced Profiling" in my Studio versions Run Configurations (Android Studio Chipmunk | 2021.2.1 Patch 1)
I created a OKHTTP EventListener to dump out a log of all the requests:
2022-08-19 13:51:06.397 11142-11142/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** callStart https://api.trakt.tv/users/xxx/ratings/episodes?limit=50&page=1
2022-08-19 **13:51:06.397** 11142-11142/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** resetMetricData
2022-08-19 **13:51:34.094** 11142-11417/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** responseBodyStart https://api.trakt.tv/users/xxx/ratings/episodes?limit=50&page=1. URL:
2022-08-19 13:51:34.099 11142-11417/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** responseBodyEnd responseBodyStartingTime: 1660913494094 , responseBodyTimeMS: 5 , responseBodyPayload: 2369. URL: https://api.trakt.tv/users/xxx/ratings/episodes?limit=50&page=1
2022-08-19 13:51:34.101 11142-11417/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** callEnd https://api.trakt.tv/users/xxx/ratings/episodes?limit=50&page=1
2022-08-19 13:51:34.191 11142-11142/com.traktapp D/OkHttpPerformanceEventL: [RoundTrip] *** callStart https://api.trakt.tv/users/xxx/ratings/episodes?limit=50&page=2
Here is the network activity graph where the delay is evident:
As can be seen from the logging, the initial network call was started 13:51:06.397, but the response body was returned sometime later 13:51:34.094.
Issue is not replicated using Postman or using a physical device to test. Has anyone any ideas or come across this problem before? It is not a computer specification/bottlenecking issue (Ryzen 5 CPU, 32GB RAM and Nvidia 1070TI GPU).
Just an update, I took a thread dump of the point where the connection delay occurs:
"OkHttp https://api.trakt.tv/...@25189" prio=5 tid=0x45 nid=NA runnable
java.lang.Thread.State: RUNNABLE
at libcore.io.Linux.poll(Linux.java:-1)
at libcore.io.ForwardingOs.poll(ForwardingOs.java:577)
at libcore.io.BlockGuardOs.poll(BlockGuardOs.java:282)
at libcore.io.ForwardingOs.poll(ForwardingOs.java:577)
at libcore.io.IoBridge.isConnected(IoBridge.java:328)
at libcore.io.IoBridge.connectErrno(IoBridge.java:238)
at libcore.io.IoBridge.connect(IoBridge.java:180)
at java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:142)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:390)
- locked <0x62a7> (a java.net.SocksSocketImpl)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:230)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:212)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:436)
at java.net.Socket.connect(Socket.java:621)
at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:128)
at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:295)
at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:207)
at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226)
at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106)
at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74)
at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255)
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at com.uwetrottmann.trakt5.TraktV2Interceptor.handleIntercept(TraktV2Interceptor.java:60)
at com.uwetrottmann.trakt5.TraktV2Interceptor.intercept(TraktV2Interceptor.java:26)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:221)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:920)
It's not helped much in identifying the issue, however.
This seems to be an issue with the emulator 31.3.10. There's a bug opened, but doesn't have much information: https://issuetracker.google.com/issues/243053479
To fix it, revert to 31.2.10.
Download it from here: https://developer.android.com/studio/emulator_archive
And very important: You have to keep package.xml from the previous emulator installation, otherwise Android Studio can't find it.