microg / microg/GmsCore

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

Open
#1,685 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Java
Stars
14.6k
Forks
3.2k
Avg merge
12d 11h
Merged PRs (30d)
4

Description

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.

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Reproduce the issue on Android 11 using the listed Chipolo setup and the adb logcat steps. Start by comparing the repeated location request, success, and removal messages in the log output; done means a successful location result no longer triggers repeated requests, excessive logging, or the reported battery drain.

Written by the indexing model from the issue text.

Assessment

Tech stack
android, java
Domain
mobile-dev
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
28/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.