Picos de latencia de red cada 20 segundos

En mi LG G3 con Android 5.0, tengo un problema que comencé a notar mientras jugaba a Clash Royale (un juego multijugador en tiempo real). Mis acciones a veces tenían un retraso de hasta 2 segundos. Otros jugadores no tendrían ese problema. Entonces comencé a investigar.

Aquí están los hechos:

  • Siempre estoy conectado al Wi-Fi de mi casa.

  • Cuando hago ping a mi enrutador desde mi G3, puedo ver un pico en la latencia exactamente cada 20 segundos.

  • No depende de la ubicación, la recepción es buena.

  • Otros dispositivos no experimentan esto usando el mismo Wi-Fi.

Por lo tanto, creo que esto realmente debe tener que ver con mi G3. No está rooteado y no he estado jugando con ninguna configuración interna. Mostrar el uso de la CPU desde la configuración del desarrollador no muestra nada sospechoso durante los picos.

¿Alguien ha experimentado algo similar? ¿Alguna idea de cómo rastrear más la raíz de este problema?

Respuestas (1)

He estado viviendo con esto por un tiempo ahora. De alguna manera, reiniciar el dispositivo dos veces seguidas pareció solucionar el problema durante algunos días.

Pero ahora finalmente vine a conectar el dispositivo a Android Studio y en el logcat encontré algunas cosas interesantes. Todavía no estoy seguro de por qué sucede esto, pero la solución es deshabilitar la ubicación. Habilitarlo nuevamente conduce a un ping instantáneo de 2 segundos y luego nuevamente periódicamente cada 20 segundos.

El servicio wifi sondea la ubicación cada 20 segundos y para eso parece usar un candado. Tarda más de 2 segundos en soltarlo de nuevo. Aquí está el registro de esta ocurrencia si alguien también afectado quiere investigar más a fondo:

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}