search

microg / GmsCore

Free implementation of Play Services
https://microg.org
Apache License 2.0
8.7k stars 1.74k forks source link

[chipolo.net.v3] Constant request for location is seemingly successful, but keeps on running #1685

Open fraukej opened 2 years ago

fraukej commented 2 years ago

Describe the bug I've noticed a higher battery drain with microG than in a previous version. Opening logcat, I can see that a lot of logging is happening, especially big chunks of logs which are repeated every minute or so.

To Reproduce Steps to reproduce the behavior:

  1. Install chipolo.net.v3
  2. log into a user account
  3. allow all requested permissions
  4. connect phone to computer
  5. adb logcat

Expected behavior After a succesful result, I don't expect this much extra information. Why is it repeatedly doing something that reportedly was successful?

Screenshots

System Android Version: 11 Custom ROM: LineageOS-18.1-20220220-UNOFFICIAL-lilac

Additional context Some logcat output:

03-07 20:59:41.794 21271 26430 D LocationManager: Using source package: chipolo.net.v3
03-07 20:59:41.795  1471  1838 D ConnectivityService: releasing NetworkRequest [ REQUEST id=67995, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] (release request)
03-07 20:59:41.795 21271 26430 D LocationManager: Registering request with high accuracy location provider
03-07 20:59:41.796 21271 26430 D GmsLocProviderReal: gps: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29996ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.796 21271 26430 D GmsLocProviderReal: gps: requesting location updates with interval 0ms (chipolo.net.v3:0ms), minDistance=0.0
03-07 20:59:41.796  1919  1919 V KeyguardUpdateMonitor: onSubscriptionInfoChanged()
03-07 20:59:41.797  1919  1919 V KeyguardUpdateMonitor: SubInfo:{id=2 iccId=894902400[****] simSlotIndex=0 carrierId=2395 displayName=Telekom carrierName=Telekom nameSource=3 iconTint=-16746133 number=[****] dataRoaming=0 iconBitmap=android.graphics.Bitmap@4ab63f2 mcc=262 mnc=01 countryIso=de isEmbedded=false nativeAccessRules=null cardString=XXXXXX[****] cardId=-1 isOpportunistic=false groupUUID=null isGroupDisabled=false profileClass=-1 ehplmns=[] hplmns=[26201, 26201] subscriptionType=0 groupOwner=null carrierConfigAccessRules=null areUiccApplicationsEnabled=true}
03-07 20:59:41.797   873   923 E LocSvc_APIClientBase: onResponseCb:894] ERROR: 5 ID: 276359
03-07 20:59:41.798 21271 26430 D LocationManager: Registering request with low accuracy location provider
03-07 20:59:41.799 21271 26430 D GmsLocProviderU: unified network: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29993ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.799 21271 26430 D LocationManager: Updated current requests, verifying
03-07 20:59:41.800 21271 26430 D LocationManager: Send success result to chipolo.net.v3
03-07 20:59:41.804 21271 21271 D GmsLocRequestHelper: sending Location: Location[network XX,XXXX,Y,YYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}] to chipolo.net.v3
03-07 20:59:41.804  2245  2245 D Telephony: isEmergencyPreferredAccount: subId=2, activeData=2
03-07 20:59:41.804  2245  2245 D Telephony: isEmergencyPreferredAccount: Device does not require preference.
03-07 20:59:41.805 21271 26430 D GmsLocManagerSvcImpl: updateLocationRequest: LocationRequestUpdateData{opCode=2, request=null, listener=null, pendingIntent=null, callback=android.os.BinderProxy@72e8d18, fusedLocationProviderCallback=android.os.BinderProxy@8f980e2}
03-07 20:59:41.805 21271 26430 D LocationManager: updateLocationRequest: LocationRequestUpdateData{opCode=2, request=null, listener=null, pendingIntent=null, callback=android.os.BinderProxy@72e8d18, fusedLocationProviderCallback=android.os.BinderProxy@8f980e2}
03-07 20:59:41.806 21271 26430 D LocationManager: Using source package: chipolo.net.v3
03-07 20:59:41.807 21271 26430 D GmsLocProviderReal: gps: removeRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29985ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=Location[fused XX,XXXX,Y,YYYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}]}
03-07 20:59:41.807 21271 26430 D GmsLocProviderReal: gps: no longer requesting location update
03-07 20:59:41.809 21271 26430 D GmsLocProviderU: unified network: removeRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29984ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=Location[fused XX,XXXX,Y,YYYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}]}
03-07 20:59:41.809 21271 26430 D LocationManager: Updated current requests, verifying
03-07 20:59:41.809 21271 21271 D GmsLocProviderU: unified network: no longer requesting location update
03-07 20:59:41.809 21271 26430 D LocationManager: Send success result to chipolo.net.v3
03-07 20:59:41.810  1471  1531 D ConnectivityService: requestNetwork for uid/pid:1000/1471 NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ]
03-07 20:59:41.811  1471  1838 D ConnectivityService: NetReassign [67996 : null → 101]
03-07 20:59:41.811  1471  1832 D UntrustedWifiNetworkFactory: got request NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 50 and providerId 3
03-07 20:59:41.811  1471  1832 D WifiNetworkFactory: got request NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 50 and providerId 3
03-07 20:59:41.811  1471  1880 D Ethernet: got request NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 50 and providerId 3
03-07 20:59:41.812  2245  2245 D PhoneSwitcherNetworkRequstListener: got request NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 50 and providerId 3
03-07 20:59:41.812  1471  1531 W ConnectivityManager.CallbackHandler: callback not found for CALLBACK_AVAILABLE message
03-07 20:59:41.813 21271 26430 D GmsLocManagerSvcImpl: getLastLocation
03-07 20:59:41.813  1919  1919 V KeyguardUpdateMonitor: onSubscriptionInfoChanged()
03-07 20:59:41.813  1919  1919 V KeyguardUpdateMonitor: SubInfo:{id=2 iccId=894902400[****] simSlotIndex=0 carrierId=2395 displayName=Telekom carrierName=Telekom nameSource=3 iconTint=-16746133 number=[****] dataRoaming=0 iconBitmap=android.graphics.Bitmap@4997a43 mcc=262 mnc=01 countryIso=de isEmbedded=false nativeAccessRules=null cardString=XXXXX[****] cardId=-1 isOpportunistic=false groupUUID=null isGroupDisabled=false profileClass=-1 ehplmns=[] hplmns=[26201, 26201] subscriptionType=0 groupOwner=null carrierConfigAccessRules=null areUiccApplicationsEnabled=true}
03-07 20:59:41.815  2245  2245 D Telephony: isEmergencyPreferredAccount: subId=2, activeData=2
03-07 20:59:41.815  2245  2245 D Telephony: isEmergencyPreferredAccount: Device does not require preference.
03-07 20:59:41.817  1471  1531 W ConnectivityManager.CallbackHandler: callback not found for CALLBACK_CAP_CHANGED message
03-07 20:59:41.817  1471  1838 D ConnectivityService: releasing NetworkRequest [ REQUEST id=67996, [ Transports: CELLULAR Capabilities: SUPL&NOT_RESTRICTED&TRUSTED&NOT_VPN Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] (release request)
03-07 20:59:41.819 21271 26430 D SafeParcel: Unknown field id 14 in com.google.android.gms.location.internal.LocationRequestInternal, skipping.
03-07 20:59:41.820 21271 26430 D GmsLocManagerSvcImpl: updateLocationRequest: LocationRequestUpdateData{opCode=1, request=LocationRequestInternal{request=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29997ms], requestNlpDebugInfo=false, restorePendingIntentListeners=false, triggerUpdate=false, clients=[], tag='null', hideFromAppOps=false, forceCoarseLocation=false, exemptFromThrottle=false, moduleId=null, locationSettingsIgnored=false, inaccurateLocationsDelayed=true, contextAttributeTag=null}, listener=null, pendingIntent=null, callback=android.os.BinderProxy@86c3fa9, fusedLocationProviderCallback=android.os.BinderProxy@732c92e}
03-07 20:59:41.820 21271 26430 D LocationManager: updateLocationRequest: LocationRequestUpdateData{opCode=1, request=LocationRequestInternal{request=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29997ms], requestNlpDebugInfo=false, restorePendingIntentListeners=false, triggerUpdate=false, clients=[], tag='null', hideFromAppOps=false, forceCoarseLocation=false, exemptFromThrottle=false, moduleId=null, locationSettingsIgnored=false, inaccurateLocationsDelayed=true, contextAttributeTag=null}, listener=null, pendingIntent=null, callback=android.os.BinderProxy@86c3fa9, fusedLocationProviderCallback=android.os.BinderProxy@732c92e}
03-07 20:59:41.820 21271 26430 D LocationManager: Using source package: chipolo.net.v3
03-07 20:59:41.820 21271 26430 D LocationManager: Registering request with high accuracy location provider
03-07 20:59:41.822 21271 26430 D GmsLocProviderReal: gps: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29996ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.822 21271 26430 D GmsLocProviderReal: gps: requesting location updates with interval 0ms (chipolo.net.v3:0ms), minDistance=0.0
03-07 20:59:41.823   873   923 E LocSvc_APIClientBase: onResponseCb:894] ERROR: 5 ID: 276360
03-07 20:59:41.824 21271 26430 D LocationManager: Registering request with low accuracy location provider
03-07 20:59:41.825 21271 26430 D GmsLocProviderU: unified network: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29992ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.826  2245  2245 D Telephony: isEmergencyPreferredAccount: subId=2, activeData=2
03-07 20:59:41.826 21271 26430 D LocationManager: Updated current requests, verifying
03-07 20:59:41.826  2245  2245 D Telephony: isEmergencyPreferredAccount: Device does not require preference.
03-07 20:59:41.826 21271 26430 D LocationManager: Send success result to chipolo.net.v3
03-07 20:59:41.828 21271 21271 D GmsLocRequestHelper: sending Location: Location[network XX,XXXX,Y,YYYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}] to chipolo.net.v3
03-07 20:59:41.830 21271 26430 D GmsLocManagerSvcImpl: updateLocationRequest: LocationRequestUpdateData{opCode=2, request=null, listener=null, pendingIntent=null, callback=android.os.BinderProxy@86c3fa9, fusedLocationProviderCallback=android.os.BinderProxy@d4776eb}
03-07 20:59:41.830 21271 26430 D LocationManager: updateLocationRequest: LocationRequestUpdateData{opCode=2, request=null, listener=null, pendingIntent=null, callback=android.os.BinderProxy@86c3fa9, fusedLocationProviderCallback=android.os.BinderProxy@d4776eb}
03-07 20:59:41.830 21271 26430 D LocationManager: Using source package: chipolo.net.v3
03-07 20:59:41.831 21271 26430 D GmsLocProviderReal: gps: removeRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29986ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=Location[fused XX,XXXX,Y,YYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}]}
03-07 20:59:41.831 21271 26430 D GmsLocProviderReal: gps: no longer requesting location update
03-07 20:59:41.832  1919  1919 V KeyguardUpdateMonitor: onSubscriptionInfoChanged()
03-07 20:59:41.832  1919  1919 V KeyguardUpdateMonitor: SubInfo:{id=2 iccId=894902400[****] simSlotIndex=0 carrierId=2395 displayName=Telekom carrierName=Telekom nameSource=3 iconTint=-16746133 number=[****] dataRoaming=0 iconBitmap=android.graphics.Bitmap@b6ba8c0 mcc=262 mnc=01 countryIso=de isEmbedded=false nativeAccessRules=null cardString=XXXXXX[****] cardId=-1 isOpportunistic=false groupUUID=null isGroupDisabled=false profileClass=-1 ehplmns=[] hplmns=[26201, 26201] subscriptionType=0 groupOwner=null carrierConfigAccessRules=null areUiccApplicationsEnabled=true}
03-07 20:59:41.833 21271 26430 D GmsLocProviderU: unified network: removeRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29984ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=Location[fused XX,XXXX,Y,YYYYY hAcc=72 et=+2d1h46m54s236ms vAcc=??? sAcc=??? bAcc=??? {Bundle[{org.microg.nlp.extra.SERVICE_BACKEND_COMPONENT=org.microg.nlp.backend.ichnaea/.BackendService, org.microg.nlp.extra.SERVICE_BACKEND_PROVIDER=ichnaea}]}]}
03-07 20:59:41.833 21271 26430 D LocationManager: Updated current requests, verifying
03-07 20:59:41.833 21271 21271 D GmsLocProviderU: unified network: no longer requesting location update
03-07 20:59:41.835 21271 26430 D LocationManager: Send success result to chipolo.net.v3
03-07 20:59:41.835 21271 23594 D GmsLocManagerSvcImpl: getLastLocation
03-07 20:59:41.835  1919  1919 V KeyguardUpdateMonitor: onSubscriptionInfoChanged()
03-07 20:59:41.836  1919  1919 V KeyguardUpdateMonitor: SubInfo:{id=2 iccId=894902400[****] simSlotIndex=0 carrierId=2395 displayName=Telekom carrierName=Telekom nameSource=3 iconTint=-16746133 number=[****] dataRoaming=0 iconBitmap=android.graphics.Bitmap@ec189f9 mcc=262 mnc=01 countryIso=de isEmbedded=false nativeAccessRules=null cardString=894902400[****] cardId=-1 isOpportunistic=false groupUUID=null isGroupDisabled=false profileClass=-1 ehplmns=[] hplmns=[26201, 26201] subscriptionType=0 groupOwner=null carrierConfigAccessRules=null areUiccApplicationsEnabled=true}
03-07 20:59:41.838 21271 26430 D SafeParcel: Unknown field id 14 in com.google.android.gms.location.internal.LocationRequestInternal, skipping.
03-07 20:59:41.838 21271 26430 D GmsLocManagerSvcImpl: updateLocationRequest: LocationRequestUpdateData{opCode=1, request=LocationRequestInternal{request=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29999ms], requestNlpDebugInfo=false, restorePendingIntentListeners=false, triggerUpdate=false, clients=[], tag='null', hideFromAppOps=false, forceCoarseLocation=false, exemptFromThrottle=false, moduleId=null, locationSettingsIgnored=false, inaccurateLocationsDelayed=true, contextAttributeTag=null}, listener=null, pendingIntent=null, callback=android.os.BinderProxy@69ed006, fusedLocationProviderCallback=android.os.BinderProxy@fa496c7}
03-07 20:59:41.838 21271 26430 D LocationManager: updateLocationRequest: LocationRequestUpdateData{opCode=1, request=LocationRequestInternal{request=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29999ms], requestNlpDebugInfo=false, restorePendingIntentListeners=false, triggerUpdate=false, clients=[], tag='null', hideFromAppOps=false, forceCoarseLocation=false, exemptFromThrottle=false, moduleId=null, locationSettingsIgnored=false, inaccurateLocationsDelayed=true, contextAttributeTag=null}, listener=null, pendingIntent=null, callback=android.os.BinderProxy@69ed006, fusedLocationProviderCallback=android.os.BinderProxy@fa496c7}
03-07 20:59:41.839 21271 26430 D LocationManager: Using source package: chipolo.net.v3
03-07 20:59:41.839 21271 26430 D LocationManager: Registering request with high accuracy location provider
03-07 20:59:41.840 21271 26430 D GmsLocProviderReal: gps: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29998ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.840 21271 26430 D GmsLocProviderReal: gps: requesting location updates with interval 0ms (chipolo.net.v3:0ms), minDistance=0.0
03-07 20:59:41.842 21271 26430 D LocationManager: Registering request with low accuracy location provider
03-07 20:59:41.842   873   923 E LocSvc_APIClientBase: onResponseCb:894] ERROR: 5 ID: 276361
03-07 20:59:41.843 21271 26430 D GmsLocProviderU: unified network: addRequest LocationRequestHelper{locationRequest=Request[PRIORITY_HIGH_ACCURACY requested=0ms fastest=0ms expireIn=-29995ms], hasFinePermission=true, hasCoarsePermission=true, packageName='chipolo.net.v3', lastReport=null}
03-07 20:59:41.843 21271 26430 D LocationManager: Updated current requests, verifying
03-07 20:59:41.844 21271 26430 D LocationManager: Send success result to chipolo.net.v3

My location could be determined succesfully (I've censored it to XX,XXXX and YY,YYYY due to privacy reasons). The log even states "LocationManager: Send success result to chipolo.net.v3". But messages of these types keep on repeating multiple times a second every minute or so. It seems that LocSvc_APIClientBase reports an error, but I couldn't find the source file or find out what error nr. 5 means.

ale5000-git commented 2 years ago

This is probably already fixed in the latest nightly build of microG GmsCore. Could you please try and report back?