Network latency spikes every 20 seconds


Question

On my LG G3 running Android 5.0 I have a problem that I started to notice while playing Clash Royale (a real time multiplayer game). My actions would sometimes have a delay of up to 2 seconds. Other players wouldn't have that problem. So I started investigating.



Here are the facts:




  • I'm always on my home Wi-Fi.


  • When I ping my router from my G3 I can see a spike in the latency exactly every 20 seconds.


  • It is not location dependent, reception is good.


  • Other devices don't experience this using the same Wi-Fi.




Hence I think this must really have to do with my G3. It is not rooted and I haven't been playing with any internal settings. Displaying the CPU usage from the developer settings doesn't show anything suspicious during the spikes.



Has anybody experienced anything similar? Any ideas how to further track down the root of this issue?


Answer

I've been living with this for a while now. Somehow restarting the device twice in a row seemed to fix the issue for some days.



But now I've finally come around to connect the device to Android Studio and in the logcat I've found some interesting stuff. I'm still not sure why this happens but the workaround is to disable Location. Enabling it again leads to an instant 2 second ping and then again periodically every 20 seconds.



The wifi service polls the location every 20 seconds and for that it seems to use a lock. It takes it over 2 seconds to release it again. Here is the log of this occurrence if anybody whose also affected wants to investigate further:



11-26 20:03:00.743 1045-1328/? V/AlarmManager: ELAPSED_WAKEUP set : Alarm{
3182c1c9 type 2 when 108939554 com.google.android.gms
}
 when 108939554
11-26 20:03:00.752 1045-2096/? D/WifiService: acquireWifiLockLocked: WifiLock{ NlpWifiLock type=2 binder=android.os.BinderProxy@45a441e }
11-26 20:03:00.754 1045-1692/? D/WifiService: startScan pid=2911, uid=10005, packageName=com.google.uid.shared:10005
11-26 20:03:00.758 1045-1346/? E/WifiStateMachine: ConnectedState !CMD_START_SCAN 10005 1580 ic=1 proc(ms):2 dur:2185 rssi=-54 f=2437 sc=60 link=54 tx=4.1, 0.0, 0.0 rx=4.4 fiv=20000 [on:0 tx:0 rx:0 period:808] from screen [on:0 period:-1576736363]
11-26 20:03:00.759 1045-1346/? E/WifiStateMachine: L2ConnectedState !CMD_START_SCAN 10005 1580 ic=1 proc(ms):4 dur:2185 rssi=-54 f=2437 sc=60 link=54 tx=4.1, 0.0, 0.0 rx=4.4 fiv=20000 [on:0 tx:0 rx:0 period:2] from screen [on:0 period:-1576736361]
11-26 20:03:00.761 1045-1346/? E/WifiStateMachine: WifiStateMachine CMD_START_SCAN source 10005 txSuccessRate=4.08 rxSuccessRate=4.42 targetRoamBSSID=any RSSI=-54
11-26 20:03:00.761 1045-1346/? D/WifiNative-wlan0: doBoolean: SCAN TYPE=ONLY
11-26 20:03:00.762 1413-1413/? I/wpa_supplicant: wlan0: CTRL-EVENT-SCAN-STARTED
11-26 20:03:00.762 1045-1505/? D/WifiMonitor: Event [IFNAME=wlan0 CTRL-EVENT-SCAN-STARTED ]
11-26 20:03:00.762 1045-1505/? E/WifiMonitor: WifiMonitor:wlan0 cnt=3840 dispatchEvent: CTRL-EVENT-SCAN-STARTED
11-26 20:03:00.762 1045-1505/? E/WifiMonitor: handleEvent 14 CTRL-EVENT-SCAN-STARTED
11-26 20:03:00.763 1045-1505/? E/WifiMonitor: handleEvent unknown: 14 CTRL-EVENT-SCAN-STARTED
11-26 20:03:00.763 1045-1346/? D/WifiNative-wlan0: SCAN TYPE=ONLY: returned true
11-26 20:03:00.772 1918-1918/? D/PhoneInterfaceManager: [PhoneIntfMgr] handleMessage : 2
11-26 20:03:00.779 1918-1918/? D/PhoneInterfaceManager: [PhoneIntfMgr] handleMessage : 3
11-26 20:03:00.839 1045-1692/? W/ActivityManager: getRecentTasks: caller 10003 is using old GET_TASKS but privileged; allowing
11-26 20:03:01.480 1415-1415/? I/[SystemUI]StatusBar.NetworkController: onSignalStrengthsChanged signalStrength=SignalStrength: 14 0 -120 -227401 -85 -1 -1 99 2147483647 2147483647 2147483647 2147483647 2147483647 gsm|lte 2 level=5
11-26 20:03:01.481 1415-1415/? D/TelephonyIcons: updateDataType sub=0, type=2, inetCondition=1 showAtLeast3G=false show4GforLte=true hspaDistinguishable=false
11-26 20:03:01.481 1415-1415/? D/TelephonyIcons: data type item name: array/telephony_data_type_sim1
11-26 20:03:01.481 1415-1415/? D/TelephonyIcons: data type item id: 2131623942
11-26 20:03:01.485 1918-1918/? D/PhoneInterfaceManager: [PhoneIntfMgr] mSigLevel = 5
11-26 20:03:01.485 1415-1415/? D/TelephonyIcons: updateDataType mSelectedDataTypeIcon[0]=2130839171, mSelectedDataActivityIndex=2
11-26 20:03:01.493 1415-1415/? D/StatusBar.NetworkController: refreshViews: Data not connected!! Set no data type icon / Roaming
11-26 20:03:01.952 1415-1415/? I/[SystemUI]StatusBar.NetworkController: onSignalStrengthsChanged signalStrength=SignalStrength: 14 0 -120 -227401 -85 -1 -1 99 2147483647 2147483647 2147483647 2147483647 2147483647 gsm|lte 2 level=5
11-26 20:03:01.952 1415-1415/? D/TelephonyIcons: updateDataType sub=0, type=2, inetCondition=1 showAtLeast3G=false show4GforLte=true hspaDistinguishable=false
11-26 20:03:01.952 1415-1415/? D/TelephonyIcons: data type item name: array/telephony_data_type_sim1
11-26 20:03:01.953 1415-1415/? D/TelephonyIcons: data type item id: 2131623942
11-26 20:03:01.957 1415-1415/? D/TelephonyIcons: updateDataType mSelectedDataTypeIcon[0]=2130839171, mSelectedDataActivityIndex=2
11-26 20:03:01.958 1918-1918/? D/PhoneInterfaceManager: [PhoneIntfMgr] mSigLevel = 5
11-26 20:03:01.966 1415-1415/? D/StatusBar.NetworkController: refreshViews: Data not connected!! Set no data type icon / Roaming
11-26 20:03:02.203 1415-1415/? D/StatusBar.NetworkController: refreshViews: Data not connected!! Set no data type icon / Roaming
11-26 20:03:02.224 338-428/? E/ThermalEngine: [GPU_MON] 0 percent. Current Sampling Time is 1 sec
11-26 20:03:02.839 1045-1389/? W/ActivityManager: getRecentTasks: caller 10003 is using old GET_TASKS but privileged; allowing
11-26 20:03:02.954 1045-1346/? E/WifiStateMachine: ConnectedState !CMD_RSSI_POLL 125 0 "Private WLAN" 00:25:9c:cf:5f:e6 rssi=-54 f=2437 sc=60 link=54 tx=4.1, 0.0, 0.0 rx=4.4 bcn=0 [on:0 tx:0 rx:0 period:2189] from screen [on:0 period:-1576734167] gl rssi=-54 ag=0 hr ls-=0 [56,56,56,56,61] brc=0 lrc=0
11-26 20:03:02.958 1045-1346/? E/WifiStateMachine: L2ConnectedState !CMD_RSSI_POLL 125 0 "Private WLAN" 00:25:9c:cf:5f:e6 rssi=-54 f=2437 sc=60 link=54 tx=4.1, 0.0, 0.0 rx=4.4 bcn=0 [on:0 tx:0 rx:0 period:4] from screen [on:0 period:-1576734163] gl rssi=-54 ag=0 hr ls-=0 [56,56,56,56,61] brc=0 lrc=0
11-26 20:03:02.958 1045-1346/? D/WifiNative-wlan0: doString: [SIGNAL_POLL]
11-26 20:03:03.037 1045-1505/? E/WifiMonitor: WifiMonitor:wlan0 cnt=3841 dispatchEvent: CTRL-EVENT-SCAN-RESULTS
11-26 20:03:03.037 1045-1505/? E/WifiMonitor: handleEvent 4 CTRL-EVENT-SCAN-RESULTS
11-26 20:03:03.044 1045-1346/? E/WifiStateMachine: ConnectedState !SCAN_RESULTS_EVENT 0 0 found=5 known=0 got=5 bcn=0
11-26 20:03:03.045 1045-1346/? E/WifiStateMachine: L2ConnectedState !SCAN_RESULTS_EVENT 0 0 found=5 known=0 got=5 bcn=0
11-26 20:03:03.047 1045-1346/? E/WifiStateMachine: ConnectModeState !SCAN_RESULTS_EVENT 0 0 found=5 known=0 got=5 bcn=0
11-26 20:03:03.048 1045-1346/? E/WifiStateMachine: DriverStartedState !SCAN_RESULTS_EVENT 0 0 found=5 known=0 got=5 bcn=0
11-26 20:03:03.050 1045-1346/? E/WifiStateMachine: SupplicantStartedState !SCAN_RESULTS_EVENT 0 0 found=5 known=0 got=5 bcn=0
11-26 20:03:03.050 1045-1346/? D/WifiNative-wlan0: doString: [BSS RANGE=0- MASK=0x21987]
11-26 20:03:03.065 26890-26890/? V/WiFiOffLoadBroadcast: WiFiOffLoadBroadcast: android.net.wifi.SCAN_RESULTS
11-26 20:03:03.084 1045-1132/? D/LocationManagerService: incoming location: Location[network [removed],[removed] acc=20 et=+1d6h15m41s881ms { Bundle[mParcelledData.dataSize=596] } ]
11-26 20:03:03.102 1045-1045/? V/UlpEngine: handleNetworkLocationUpdate. lat[removed]lon[removed]accurancy 19.732
11-26 20:03:03.102 1045-1045/? D/Ulp_jni: send_network_location.
11-26 20:03:03.105 1045-2262/? E/LocSvc_libulp: E/int ulp_brain_transition_all_providers(), no QUIPC/GNSS transition logic run due to both engines are OFF
11-26 20:03:03.107 1045-1132/? D/LocationManagerService: incoming location: Location[network [removed],[removed] acc=20 et=+1d6h15m41s881ms { Bundle[{ networkLocationType=wifi, travelState=stationary, noGPSLocation=Location[network 46.599326,14.313926 acc=20 et=+1d6h15m41s881ms { Bundle[mParcelledData.dataSize=240] } ], nlpVersion=2023 } ] } ]
11-26 20:03:03.109 26890-26890/? D/WiFiOffLoadBroadcast: Not supported operator for automatic switch
11-26 20:03:03.118 2911-25111/? W/ctxmgr: [ContextSpecificAclFactory]LocationConsent failed, ULR opt-in status is: false, account#-2116008859#
11-26 20:03:03.118 2911-25111/? W/ctxmgr: [AclManager]No 2 for (accnt=account#-2116008859#, com.google.android.gms(10005):UserLocationProducer, vrsn=10084000, 0, 3pPkg = null , 3pMdlId = null). Was: 2 for 1, account#-2116008859#
11-26 20:03:03.144 2911-25111/? W/ctxmgr: [ContextSpecificAclFactory]LocationConsent failed, ULR opt-in status is: false, account#1995265525#
11-26 20:03:03.144 2911-25111/? W/ctxmgr: [AclManager]No 2 for (accnt=account#1995265525#, com.google.android.gms(10005):UserLocationProducer, vrsn=10084000, 0, 3pPkg = null , 3pMdlId = null). Was: 2 for 1, account#1995265525#
11-26 20:03:03.167 1045-2006/? D/WifiService: releaseWifiLockLocked: WifiLock{ NlpWifiLock type=2 binder=android.os.BinderProxy@45a441e }

Topics


2D Engines   3D Engines   9-Patch   Action Bars   Activities   ADB   Advertisements   Analytics   Animations   ANR   AOP   API   APK   APT   Architecture   Audio   Autocomplete   Background Processing   Backward Compatibility   Badges   Bar Codes   Benchmarking   Bitmaps   Bluetooth   Blur Effects   Bread Crumbs   BRMS   Browser Extensions   Build Systems   Bundles   Buttons   Caching   Camera   Canvas   Cards   Carousels   Changelog   Checkboxes   Cloud Storages   Color Analysis   Color Pickers   Colors   Comet/Push   Compass Sensors   Conferences   Content Providers   Continuous Integration   Crash Reports   Credit Cards   Credits   CSV   Curl/Flip   Data Binding   Data Generators   Data Structures   Database   Database Browsers   Date &   Debugging   Decompilers   Deep Links   Dependency Injections   Design   Design Patterns   Dex   Dialogs   Distributed Computing   Distribution Platforms   Download Managers   Drawables   Emoji   Emulators   EPUB   Equalizers &   Event Buses   Exception Handling   Face Recognition   Feedback &   File System   File/Directory   Fingerprint   Floating Action   Fonts   Forms   Fragments   FRP   FSM   Functional Programming   Gamepads   Games   Geocaching   Gestures   GIF   Glow Pad   Gradle Plugins   Graphics   Grid Views   Highlighting   HTML   HTTP Mocking   Icons   IDE   IDE Plugins   Image Croppers   Image Loaders   Image Pickers   Image Processing   Image Views   Instrumentation   Intents   Job Schedulers   JSON   Keyboard   Kotlin   Layouts   Library Demos   List View   List Views   Localization   Location   Lock Patterns   Logcat   Logging   Mails   Maps   Markdown   Mathematics   Maven Plugins   MBaaS   Media   Menus   Messaging   MIME   Mobile Web   Native Image   Navigation   NDK   Networking   NFC   NoSQL   Number Pickers   OAuth   Object Mocking   OCR Engines   OpenGL   ORM   Other Pickers   Parallax List   Parcelables   Particle Systems   Password Inputs   PDF   Permissions   Physics Engines   Platforms   Plugin Frameworks   Preferences   Progress Indicators   ProGuard   Properties   Protocol Buffer   Pull To   Purchases   Push/Pull   QR Codes   Quick Return   Radio Buttons   Range Bars   Ratings   Recycler Views   Resources   REST   Ripple Effects   RSS   Screenshots   Scripting   Scroll Views   SDK   Search Inputs   Security   Sensors   Services   Showcase Views   Signatures   Sliding Panels   Snackbars   SOAP   Social Networks   Spannable   Spinners   Splash Screens   SSH   Static Analysis   Status Bars   Styling   SVG   System   Tags   Task Managers   TDD &   Template Engines   Testing   Testing Tools   Text Formatting   Text Views   Text Watchers   Text-to   Toasts   Toolkits For   Tools   Tooltips   Trainings   TV   Twitter   Updaters   USB   User Stories   Utils   Validation   Video   View Adapters   View Pagers   Views   Watch Face   Wearable Data   Wearables   Weather   Web Tools   Web Views   WebRTC   WebSockets   Wheel Widgets   Wi-Fi   Widgets   Windows   Wizards   XML   XMPP   YAML   ZIP Codes