Closed hubertbanas closed 4 years ago
Apart from not finding anything, the behavior (showing a dialog with progress circle, and finish scanning and hiding progress circle after 20 seconds) is expected.
Since it does not show any device in the log, it seems as if the app does not have the necessary permissions to get scan results. Can you check if the location permission is granted and the location service is started?
I just confirmed location permission is granted.
I'm not sure how to verify location service is started other than making sure it is enabled. Please advise.
If the location service is enabled, then it is also started. Well this is awkward. Can you try with the Debug build version, it should show additional log entries? app-debug.zip
Presence Publisher v2.0.1 (debug build)
Here is the log
2020-01-09T10:42:22.983Z [VERBOSE/ModelSpecificDistanceCalculator]: Finding best distance calculator for 10, QQ1A.191205.008, Pixel 2, Google
2020-01-09T10:42:22.984Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 4;KOT49H;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.985Z [VERBOSE/AndroidModel]: Score is 0 for XT1115;Moto X Pro;LXG22.67-7.1;5.0.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.986Z [VERBOSE/AndroidModel]: Score is 0 for Motorola;XT1092;MPE24.49-18;6.0 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.987Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 5;LPV79;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.987Z [WARN/ModelSpecificDistanceCalculator]: Cannot find match for this device. Using default
2020-01-09T10:42:22.988Z [VERBOSE/ModelSpecificDistanceCalculator]: Finding best distance calculator for 10, QQ1A.191205.008, Pixel 2, Google
2020-01-09T10:42:22.989Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 4;KOT49H;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.989Z [VERBOSE/AndroidModel]: Score is 0 for XT1115;Moto X Pro;LXG22.67-7.1;5.0.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.990Z [VERBOSE/AndroidModel]: Score is 0 for Motorola;XT1092;MPE24.49-18;6.0 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.991Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 5;LPV79;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:22.991Z [WARN/ModelSpecificDistanceCalculator]: Cannot find match for this device. Using default
2020-01-09T10:42:22.993Z [INFO/BeaconManager]: BeaconManager started up on pid 25007 named 'org.ostrya.presencepublisher.debug' for application package 'org.ostrya.presencepublisher.debug'. isMainProcess=true
2020-01-09T10:42:23.034Z [VERBOSE/MainActivity]: Creating activity
2020-01-09T10:42:23.071Z [VERBOSE/MainActivity]: Location permission not yet granted, asking user ...
2020-01-09T10:42:23.077Z [VERBOSE/MainActivity]: Creating activity finished
2020-01-09T10:42:23.118Z [VERBOSE/DistanceConfigFetcher]: response code is 200
2020-01-09T10:42:23.119Z [VERBOSE/ModelSpecificDistanceCalculator]: Successfully downloaded distance models from online database
2020-01-09T10:42:23.121Z [INFO/ModelSpecificDistanceCalculator]: Successfully saved new distance model file
2020-01-09T10:42:23.124Z [VERBOSE/ModelSpecificDistanceCalculator]: Finding best distance calculator for 10, QQ1A.191205.008, Pixel 2, Google
2020-01-09T10:42:23.124Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 5;LPV79;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:23.125Z [VERBOSE/AndroidModel]: Score is 0 for LGE;Nexus 4;KOT49H;4.4.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:23.126Z [VERBOSE/AndroidModel]: Score is 0 for XT1115;Moto X Pro;LXG22.67-7.1;5.0.2 compared to Google;Pixel 2;QQ1A.191205.008;10
2020-01-09T10:42:23.126Z [WARN/ModelSpecificDistanceCalculator]: Cannot find match for this device. Using default
2020-01-09T10:42:23.127Z [INFO/ModelSpecificDistanceCalculator]: Successfully updated distance model with latest from online database
2020-01-09T10:42:23.167Z [VERBOSE/BackgroundPowerSaver]: activity resumed: org.ostrya.presencepublisher.MainActivity@acb9070 active activities: 1
2020-01-09T10:42:23.292Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:23.314Z [INFO/SystemBroadcastReceiver]: Reacting to network change
2020-01-09T10:42:23.344Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:23.529Z [INFO/MainActivity]: Changed parameter ping
2020-01-09T10:42:23.559Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:28.603Z [INFO/AlarmReceiver]: Alarm broadcast received
2020-01-09T10:42:28.675Z [WARN/WifiMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:28.676Z [WARN/BeaconMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:28.678Z [INFO/Publisher]: Next run at 1/9/20 05:57
2020-01-09T10:42:29.359Z [VERBOSE/BackgroundPowerSaver]: activity paused: org.ostrya.presencepublisher.MainActivity@acb9070 active activities: 0
2020-01-09T10:42:29.359Z [VERBOSE/BackgroundPowerSaver]: setting background mode
2020-01-09T10:42:29.361Z [VERBOSE/BeaconManager]: updating background flag to true
2020-01-09T10:42:29.361Z [VERBOSE/BeaconManager]: updating scan period to 10000, 300000
2020-01-09T10:42:29.362Z [WARN/BeaconManager]: The BeaconManager is not bound to the service. Call beaconManager.bind(BeaconConsumer consumer) and wait for a callback to onBeaconServiceConnect()
2020-01-09T10:42:31.764Z [INFO/MainActivity]: Successfully granted location permission
2020-01-09T10:42:31.770Z [VERBOSE/MainActivity]: Battery optimization not yet disabled, asking user ...
2020-01-09T10:42:31.773Z [VERBOSE/BeaconManager]: updating background flag to false
2020-01-09T10:42:31.774Z [VERBOSE/BeaconManager]: updating scan period to 1100, 0
2020-01-09T10:42:31.775Z [WARN/BeaconManager]: The BeaconManager is not bound to the service. Call beaconManager.bind(BeaconConsumer consumer) and wait for a callback to onBeaconServiceConnect()
2020-01-09T10:42:31.776Z [VERBOSE/BackgroundPowerSaver]: activity resumed: org.ostrya.presencepublisher.MainActivity@acb9070 active activities: 1
2020-01-09T10:42:31.887Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:32.922Z [VERBOSE/BackgroundPowerSaver]: activity paused: org.ostrya.presencepublisher.MainActivity@acb9070 active activities: 0
2020-01-09T10:42:32.923Z [VERBOSE/BackgroundPowerSaver]: setting background mode
2020-01-09T10:42:32.924Z [VERBOSE/BeaconManager]: updating background flag to true
2020-01-09T10:42:32.925Z [VERBOSE/BeaconManager]: updating scan period to 10000, 300000
2020-01-09T10:42:32.925Z [WARN/BeaconManager]: The BeaconManager is not bound to the service. Call beaconManager.bind(BeaconConsumer consumer) and wait for a callback to onBeaconServiceConnect()
2020-01-09T10:42:33.589Z [INFO/AlarmReceiver]: Alarm broadcast received
2020-01-09T10:42:33.648Z [WARN/WifiMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:33.649Z [WARN/BeaconMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:33.653Z [INFO/Publisher]: Next run at 1/9/20 05:57
2020-01-09T10:42:33.902Z [VERBOSE/MainActivity]: Returning from battery optimization with result -1
2020-01-09T10:42:33.944Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:33.954Z [VERBOSE/BeaconManager]: updating background flag to false
2020-01-09T10:42:33.955Z [VERBOSE/BeaconManager]: updating scan period to 1100, 0
2020-01-09T10:42:33.956Z [WARN/BeaconManager]: The BeaconManager is not bound to the service. Call beaconManager.bind(BeaconConsumer consumer) and wait for a callback to onBeaconServiceConnect()
2020-01-09T10:42:33.956Z [VERBOSE/BackgroundPowerSaver]: activity resumed: org.ostrya.presencepublisher.MainActivity@acb9070 active activities: 1
2020-01-09T10:42:33.990Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:37.035Z [WARN/SsidUtil]: No known networks found
2020-01-09T10:42:37.042Z [INFO/MainActivity]: Changed parameter offlineContent
2020-01-09T10:42:37.076Z [INFO/Publisher]: Next run at 1/9/20 05:42
2020-01-09T10:42:38.678Z [INFO/AlarmReceiver]: Alarm broadcast received
2020-01-09T10:42:38.717Z [WARN/WifiMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:38.718Z [WARN/BeaconMessageProvider]: No topic defined, not generating any messages
2020-01-09T10:42:38.721Z [INFO/Publisher]: Next run at 1/9/20 05:57
2020-01-09T10:43:11.298Z [INFO/CycledLeScanner]: Using Android O scanner
2020-01-09T10:43:11.300Z [VERBOSE/CycledLeScanner]: start called
2020-01-09T10:43:11.301Z [VERBOSE/CycledLeScanner]: starting a new scan cycle
2020-01-09T10:43:11.302Z [VERBOSE/CycledLeScanner]: starting a new bluetooth le scan
2020-01-09T10:43:11.303Z [VERBOSE/CycledLeScannerForLollipop]: starting a scan in SCAN_MODE_LOW_LATENCY
2020-01-09T10:43:11.303Z [VERBOSE/CycledLeScannerForLollipop]: Using an empty scan filter since this is 8.1+ on Non-Samsung
2020-01-09T10:43:11.304Z [VERBOSE/CycledLeScannerForLollipop]: Making new Android L scanner
2020-01-09T10:43:11.305Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 20000 milliseconds
2020-01-09T10:43:11.306Z [VERBOSE/CycledLeScanner]: Scan started
2020-01-09T10:43:12.316Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 18990 milliseconds
2020-01-09T10:43:13.319Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 17988 milliseconds
2020-01-09T10:43:14.322Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 16985 milliseconds
2020-01-09T10:43:15.325Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 15982 milliseconds
2020-01-09T10:43:16.329Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 14978 milliseconds
2020-01-09T10:43:17.334Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 13973 milliseconds
2020-01-09T10:43:18.338Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 12970 milliseconds
2020-01-09T10:43:19.344Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 11964 milliseconds
2020-01-09T10:43:20.348Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 10959 milliseconds
2020-01-09T10:43:21.353Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 9954 milliseconds
2020-01-09T10:43:22.357Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 8949 milliseconds
2020-01-09T10:43:23.360Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 7947 milliseconds
2020-01-09T10:43:24.364Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 6943 milliseconds
2020-01-09T10:43:25.369Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 5939 milliseconds
2020-01-09T10:43:26.373Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 4933 milliseconds
2020-01-09T10:43:27.377Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 3930 milliseconds
2020-01-09T10:43:28.381Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 2926 milliseconds
2020-01-09T10:43:29.385Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 1922 milliseconds
2020-01-09T10:43:30.388Z [VERBOSE/CycledLeScanner]: Waiting to stop scan cycle for another 919 milliseconds
2020-01-09T10:43:31.310Z [VERBOSE/CycledLeScanner]: Done with scan cycle
2020-01-09T10:43:31.313Z [VERBOSE/CycledLeScanner]: stop called
2020-01-09T10:43:31.315Z [VERBOSE/CycledLeScanner]: disabling scan
2020-01-09T10:43:31.322Z [VERBOSE/CycledLeScannerForLollipop]: Stopping LE scan on scan handler
2020-01-09T10:43:31.321Z [VERBOSE/CycledLeScanner]: Done with scan cycle
2020-01-09T10:43:31.326Z [VERBOSE/CycledLeScanner]: stop called
2020-01-09T10:43:31.328Z [VERBOSE/CycledLeScanner]: scanning already stopped
2020-01-09T10:43:31.332Z [VERBOSE/CycledLeScanner]: Scanning disabled.
2020-01-09T10:43:31.335Z [VERBOSE/CycledLeScanner]: cancel wakeup alarm: null
2020-01-09T10:43:31.343Z [VERBOSE/CycledLeScanner]: Set a wakeup alarm to go off in 9223372033781193122 ms: PendingIntent{fb9ec3f: android.os.BinderProxy@fdef90c}
2020-01-09T10:43:31.345Z [VERBOSE/CycledLeScanner]: Scanning disabled.
2020-01-09T10:43:31.346Z [VERBOSE/CycledLeScanner]: cancel wakeup alarm: PendingIntent{fb9ec3f: android.os.BinderProxy@fdef90c}
2020-01-09T10:43:31.351Z [VERBOSE/CycledLeScanner]: Set a wakeup alarm to go off in 9223372033781193115 ms: PendingIntent{fb9ec3f: android.os.BinderProxy@fdef90c}
@ostrya did you have a chance to look into it yet?
Please let me know if there is any other debug you would like me to provide.
I'm very sorry, but I currently have no idea what might be the problem. BeaconLocator uses the same library that I do. And as the logs do not indicate that anything has been detected at all (which could be filtered due to some misconfiguration), I feel there must be some other problem. I tested it on an Android 7, 8.1 and Android 10 phone, and it works on each of them.
So just to re-iterate: you have location services enabled?
As far as I remember, BeaconLocator is not yet compiled against the Android 10 API, so some permission limitations introduced in Android 10 do not yet apply (see https://developer.android.com/about/versions/10/privacy/changes?hl=en#location-telephony-bluetooth-wifi).
Yes, I just confirmed location services are enabled.
I'm seeing identical behaviour on my Galaxy Tab S2 (SM-T813) running LineageOS 16.0 (Android 9) February 11, 2020 build.
Could you maybe provide full logs of scanning with PresencePublisher and with BeaconLocator? E.g. using https://github.com/darshanparajuli/LogcatReader ? Just to pinpoint why one app works and the other does not. Or if you don't want to provide the full log, maybe you can check for differences yourself and just tell me the result?
I'm very sorry for the delay. Attached logs are from Galaxy Tab S2 (SM-T813) running LineageOS 16.0 (Android 9) April 4, 2020 build.
Thanks for the logs, and no worries about the time delay. While I have not seen any unusual differences (seems the relevant debug log is not available for non-debug builds), I will try to use the library in a different way to see if this will improve the behavior on your end. Please bear with me here, I will try to get this done as soon as I find some time.
Did you have a chance to look into it yet?
Hi, sorry for taking so long. I replaced the way beacons are scanned for to be more similar to how BeaconLocator does it: app-debug.zip
Can you please try if it works now?
No worries about the delay.
Unfortunately that version is also not detecting my beacon. Log is located at https://easyupload.io/ah2dt1
I did a small modification and also improved log detail, could you try again? app-debug.zip
I appreciate a quick build. Still not detecting my beacon. New logs are at https://easyupload.io/qgr2w7
This looks promising
2020-09-06T13:39:17.624Z [VERBOSE/altbeacon/ScanHelper]: Beacon packet detected for: id1: e07d0c40-6ef6-4eed-a3a7-89129fe0ca1d id2: 3104 id3: 1 type iBeacon with rssi -91
Yes, this feels like playing cat and mouse. I have another build for you to try, again probably just to narrow down the cause of the bug: app-debug.zip
I appreciate you spending time on this. New logs are at https://easyupload.io/eexd74
Ok, now I see the issue. It seems Android does not fill in the name of the device, and I assumed the name would be present, so I ignored devices with missing names. I'll see that I can adapt the logic.
Presence Publisher v2.0.0 Pixel 2 - Android 10 iBeacon - NodeMCU-32S running ESPHome
Here is what follows
"Add beacon" brings up the following popup window
After about 20 seconds the scan progress circle goes away but the window remains open as follow![presence_publisher_v2 0 0-02](https://user-images.githubusercontent.com/2602582/71942493-6d2b7080-318b-11ea-80ba-0b3554cfbbc0.png)
Log shows the following:
Here is what Beacon Locator shows![beacon_locator_v1 2 2-01](https://user-images.githubusercontent.com/2602582/71942565-a532b380-318b-11ea-853c-ce8595001722.png)
Please let me know if there is any other debug data you would like me to collect.