1

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?

0

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}

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.