Reputation: 6019
For some reason the monitoring doesn't seem to work well on my device. That's a Pixel 2 with Android O. Sometimes it works. Sometimes it doesn't. It seems really random. I've been waiting for much longer than 15 minutes - hours and it would still not detect anything. I'm using the RegionBootstrap for background monitoring.
Maybe the below is the reason for it not working? I don't have any other apps using BT that I know of running in the background.
03-13 20:36:39.817 32272-32293/? E/BtGatt.GattService: Advertise app or callback is null
03-13 20:36:40.233 32272-10072/? E/BtGatt.GattService: App 'com.xxxxxxxxx.xxx' is scanning too frequently
I also get a ton of these in general:
03-13 20:33:49.358 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
... and these are all errors that occurred in that period:
03-13 20:33:49.356 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:33:49.356 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:33:49.356 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:33:49.356 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:33:49.358 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
03-13 20:33:49.736 21268-21268/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:33:52.573 21286-21286/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:33:55.976 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:33:55.976 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:33:55.976 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:33:55.976 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:33:55.977 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
03-13 20:33:59.644 21308-21308/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:34:00.005 1130-1153/? E/zygote64: Error encountered killing process cgroup uid 99686 pid 18067: No such file or directory
03-13 20:34:02.601 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:02.601 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:02.601 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:02.601 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:02.609 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
03-13 20:34:07.644 21330-21330/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:34:09.216 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:09.216 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:09.216 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:09.216 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:09.217 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
03-13 20:34:09.361 2251-2259/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [2, 0]
03-13 20:34:14.935 2251-2259/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [2, 0]
03-13 20:34:15.121 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:15.121 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:15.121 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:15.121 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:15.162 20525-20534/com.xxxxxxx.app E/SpellCheckerSession: ignoring processOrEnqueueTask due to unexpected mState=TASK_CLOSE scp.mWhat=TASK_CLOSE
03-13 20:34:15.511 21372-21372/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:34:15.912 21085-21085/? E/ctxmgr: [PlaceFenceHelper]NearbyBuffer is null!
03-13 20:34:16.898 28698-28698/? E/FullInputEventModel: onStartInput event aborted: com.touchtype.keyboard.h.q: could not obtain extracted text (class com.touchtype.keyboard.h.q)
03-13 20:34:18.581 775-3070/? E/NxpTml: _i2c_write() errno : 5
03-13 20:34:18.581 775-3070/? E/NxpTml: PN54X - Error in I2C Write.....
03-13 20:34:18.581 775-3072/? E/NxpHal: write error status = 0x1ff
03-13 20:34:18.581 775-775/? E/NxpHal: write_unlocked failed - PN54X Maybe in Standby Mode - Retry
03-13 20:34:18.741 21085-21112/? E/ctxmgr: [WorkInfo]Attribution was already enqueued pkg=com.google.android.gms, lbl=PlacesProducer_receive, start=2018-03-13 20:34:15.380-0400, stop=2018-03-13 20:34:15.380-0400, durtn=0ms.
03-13 20:34:18.742 21085-21367/? E/ctxmgr: [WorkManager]Ongoing task not found: PlacesProducer_receive
03-13 20:34:24.219 21398-21398/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:34:25.534 775-3070/? E/NxpTml: _i2c_write() errno : 5
03-13 20:34:25.534 775-3070/? E/NxpTml: PN54X - Error in I2C Write.....
03-13 20:34:25.534 775-3072/? E/NxpHal: write error status = 0x1ff
03-13 20:34:25.534 775-775/? E/NxpHal: write_unlocked failed - PN54X Maybe in Standby Mode - Retry
03-13 20:34:25.582 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.582 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.582 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.582 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.584 21085-21085/? E/NearbyDirect: MPScanner: onScanFailed, error code=2
03-13 20:34:25.589 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.589 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.589 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.589 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.618 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.618 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.618 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:25.618 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:25.793 21085-20506/? E/ctxmgr: [AppIntervalImpl]closeInterval: ongoing
03-13 20:34:25.794 21085-20506/? E/ctxmgr: [AppIntervalImpl]closeInterval: ongoing
03-13 20:34:26.173 21085-21085/? E/ctxmgr: [PlaceFenceHelper]NearbyBuffer is null!
03-13 20:34:30.854 2251-2259/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [2, 0]
03-13 20:34:35.089 1130-1154/? E/BatteryExternalStatsWorker: no controller energy info supplied for wifi
03-13 20:34:35.199 778-778/? E/QCOM PowerHAL: extract_stats: failed to open: /d/system_stats Error = Permission denied
03-13 20:34:35.202 778-778/? E/QCOM PowerHAL: extract_stats: failed to open: /d/wlan0/power_stats Error = Permission denied
03-13 20:34:35.638 19651-21408/? E/Ssdp: Socket closed
03-13 20:34:35.895 2251-2259/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [2, 0]
03-13 20:34:36.639 32272-32293/? E/BtGatt.GattService: Exception: android.os.DeadObjectException
03-13 20:34:36.649 32272-10070/? E/BtGatt.ContextMap: Context not found for ID 9
03-13 20:34:36.650 32272-32293/? E/BtGatt.ContextMap: Context not found for ID 9
03-13 20:34:36.651 32272-32293/? E/BtGatt.ContextMap: Context not found for ID 9
03-13 20:34:38.566 21085-21085/? E/ctxmgr: [PlaceFenceHelper]NearbyBuffer is null!
03-13 20:34:41.557 2251-2259/? E/ANDR-PERF-RESOURCEQS: Failed to apply optimization [2, 0]
03-13 20:34:41.803 32272-32311/? E/bt_btif: bta_gattc_deregister: Deregister Failed unknown client cif
03-13 20:34:43.229 1876-1876/? E/QtiImsExtUtils: getConfigForPhoneId phoneId is invalid
03-13 20:34:43.229 1876-1876/? E/QtiImsExtUtils: isCarrierConfigEnabled bundle is null
03-13 20:34:45.828 21503-21503/? E/cutils-trace: Error opening trace file: No such file or directory (2)
03-13 20:34:46.000 32272-32293/? E/BtGatt.GattService: Advertise app or callback is null
03-13 20:34:46.360 32272-32311/? E/bt_btif: bta_gattc_deregister: Deregister Failed unknown client cif
03-13 20:34:46.364 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:46.364 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:46.364 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:46.364 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:46.365 20525-20525/com.xxxxxxx.app E/CycledLeScannerForLollipop: Scan failed: app cannot be registered
03-13 20:34:46.370 32272-32272/? E/BluetoothMapService: mSessionStatusHandler.sendMessage() dispatched shutdown message
03-13 20:34:46.378 20525-20525/com.xxxxxxx.app E/App: Unable to start beacon monitoring: Bluetooth not enabled.
03-13 20:34:46.380 32272-32315/? E/bt_btif: SOCK_LIST: free(id = 2) - NO app_fd!
03-13 20:34:46.380 32272-32315/? E/bt_btif: SOCK_LIST: free(id = 1) - NO app_fd!
03-13 20:34:46.380 32272-32315/? E/bt_btif: SOCK_LIST: free(id = 3) - NO app_fd!
03-13 20:34:46.405 32272-32293/? E/bt_btif: btif_hf_upstreams_evt: Invalid index -1
03-13 20:34:46.446 32272-32293/? E/bt_btif: btif_in_execute_service_request: Unknown service 27 being disabled
03-13 20:34:46.491 20525-20525/com.xxxxxxx.app E/App: Unable to start beacon monitoring: Bluetooth not enabled.
03-13 20:34:46.496 20525-20525/com.xxxxxxx.app E/App: Unable to start beacon monitoring: Bluetooth not enabled.
03-13 20:34:47.376 20525-20525/com.xxxxxxx.app E/App: Unable to start beacon monitoring: Bluetooth not enabled.
03-13 20:34:47.380 20525-20525/com.xxxxxxx.app E/App: Unable to start beacon monitoring: Bluetooth not enabled.
03-13 20:34:47.389 32272-32293/? E/bt_btif: btif_hf_upstreams_evt: Invalid index -1
03-13 20:34:47.412 32272-32272/? E/Avrcp: play status change -1➡0 mPlayStatusChangedNT: 1
03-13 20:34:47.412 32272-32272/? E/bt_btif: register_notification_rsp: Avrcp device is not connected, handle: 0x0
03-13 20:34:47.413 32272-32272/? E/Avrcp: play status change 0➡0 mPlayStatusChangedNT: 1
03-13 20:34:47.421 32272-32293/? E/bt_btif: btif_sm_dispatch : Invalid handle
03-13 20:34:47.421 32272-32293/? E/bt_btif: btif_sm_dispatch : Invalid handle
03-13 20:34:47.426 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.426 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.426 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.426 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.537 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.537 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.537 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.537 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.541 21085-21085/? E/NearbyDirect: MPScanner: onScanFailed, error code=2
03-13 20:34:47.608 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.608 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.608 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.608 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.611 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.611 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:47.611 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:47.611 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:48.022 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:48.022 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:48.022 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:48.023 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:48.026 21085-21085/? E/ProximityAuth: [BleCentralService] Failed to initiate BLE scanning; killing service. Error code: 2
03-13 20:34:48.112 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:48.112 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:48.112 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
03-13 20:34:48.112 32272-32311/? E/bt_btif: Register with GATT stack failed.
03-13 20:34:48.112 21085-21085/? E/NearbyDirect: MPScanner: onScanFailed, error code=2
I also added the Bluetooth Medic but it doesn't seem to be doing anything. It was running in parallel here. Debug filtered on 'medic':
03-13 20:29:43.483 20196-20255/com.xxxxxxxxx.xxx I/BluetoothMedic: Starting scan test
03-13 20:29:43.792 20196-20196/com.xxxxxxxxx.xxx W/BluetoothMedic: Scan test failed in a way we consider a failure
03-13 20:29:54.496 20196-20255/com.xxxxxxxxx.xxx I/BluetoothMedic: Starting transmitter test
03-13 20:29:54.539 20196-20196/com.xxxxxxxxx.xxx I/BluetoothMedic: Transmitter test succeeded
03-13 20:30:31.144 20525-20557/? I/BluetoothMedic: Starting scan test
03-13 20:30:31.453 20525-20525/? W/BluetoothMedic: Scan test failed in a way we consider a failure
03-13 20:30:42.153 20525-20557/com.xxxxxxxxx.xxx I/BluetoothMedic: Starting transmitter test
03-13 20:30:42.184 20525-20525/com.xxxxxxxxx.xxx I/BluetoothMedic: Transmitter test succeeded
03-13 20:34:53.727 21581-21608/com.xxxxxxxxx.xxx I/BluetoothMedic: Starting scan test
03-13 20:34:53.829 21581-21581/com.xxxxxxxxx.xxx W/BluetoothMedic: Scan test failed in a way we consider a failure
03-13 20:35:04.750 21581-21608/com.xxxxxxxxx.xxx I/BluetoothMedic: Starting transmitter test
03-13 20:35:04.784 21581-21581/com.xxxxxxxxx.xxx I/BluetoothMedic: Transmitter test succeeded
So what exactly is happening here? I can post code later, but the post is already hitting the limit and maybe the logs might already give an idea.
Thank you!
EDIT:
I also just got this:
04-10 01:04:42.179 5703 8356 E AndroidRuntime: FATAL EXCEPTION: BluetoothTestThread
04-10 01:04:42.179 5703 8356 E AndroidRuntime: Process: com.xxxxxxx.app, PID: 5703
04-10 01:04:42.179 5703 8356 E AndroidRuntime: java.lang.IllegalStateException: BT Adapter is not turned ON
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.bluetooth.le.BluetoothLeUtils.checkAdapterStateOn(BluetoothLeUtils.java:136)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.bluetooth.le.BluetoothLeScanner.startScan(BluetoothLeScanner.java:204)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.bluetooth.le.BluetoothLeScanner.startScan(BluetoothLeScanner.java:132)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.bluetooth.le.BluetoothLeScanner.startScan(BluetoothLeScanner.java:113)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at org.altbeacon.bluetooth.BluetoothMedic.runScanTest(BluetoothMedic.java:261)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at org.altbeacon.bluetooth.BluetoothTestJob$1.run(BluetoothTestJob.java:104)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.os.Handler.handleCallback(Handler.java:790)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.os.Handler.dispatchMessage(Handler.java:99)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.os.Looper.loop(Looper.java:164)
04-10 01:04:42.179 5703 8356 E AndroidRuntime: at android.os.HandlerThread.run(HandlerThread.java:65)
Upvotes: 1
Views: 1066
Reputation: 64916
The log lines like below indicate that the Android bluetooth stack has exhausted the ability of new apps to start bluetooth scans for beacons:
03-13 20:34:48.112 32272-32311/? E/bt_stack: [ERROR:gatt_api.cc(1032)] can't Register GATT client, MAX client reached: 32
This might mean that 32 apps on the phone have already used all the bluetooth clients, but more likely it is caused by an OS-level bug that has exhausted all the client slots prematurely, potentially by leaving some orphaned.
This is one of the problems that the Android Beacon Library's Bluetooth Medic is designed to be able to detect and fix by cycling power to bluetooth, which releases all the client slots. In order to do this, you must configure the medic to cycle power on failures. Based on the logs shown, it does not appear this is happening, which may mean the medic is not configured to do so.
You can configure the BluetoothMedic to cycle power to attempt recovery like this:
BluetoothMedic medic = BluetoothMedic.getInstance();
medic.enablePowerCycleOnFailures(context);
medic.enablePeriodicTests(context, BluetoothMedic.SCAN_TEST |
BluetoothMedic.TRANSMIT_TEST);
Upvotes: 4