So, I could not figure out what causes this problem or how to get around it. I am developing an application that connects to a BLE peripheral device all day and collects data from sensors on the device. From time to time, the device turns off, and when I look at the logarithm, I just see that the reconnection does not work, and the Bluetooth callback GattCallback onConnectionStateChange gets the status 133, and this will only be a loop. By killing the application, turning off and turning off the bluetooth of the phone, clearing the Bluetooth cache is all that we are trying to restore. I connect to the device on the main thread like this:
if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.M) { mBluetoothGatt = mBluetoothDevice.connectGatt(mContext, autoConnect, mBleGattCallback, TRANSPORT_LE); } else { mBluetoothGatt = mBluetoothDevice.connectGatt(mContext, autoConnect, mBleGattCallback); }
This code is in a custom device object (basically a wrapper for a peripheral address), and I will reuse the object if I still have an instance to connect again. I'm currently trying to use BluetoothAdapter.getRemoteDevice to get a new instance of BluetoothDevice to create a new user device object and call the above code. OnConnectionStateChange is as follows:
@Override public void onConnectionStateChange(BluetoothGatt gatt, int status, int newState) { if (status == BluetoothGatt.GATT_SUCCESS && newState == BluetoothGatt.STATE_CONNECTED) { final boolean success = gatt.discoverServices(); if (!success) { disconnect(); broadcastDisconnected(); } } else { try {
The disconnect method then calls the hidden update method on the bluetoothGatt object, then calls mBluetoothGatt.disconnect() and then mBluetoothGatt.close() . With this code, the phones I'm testing on usually work very well, but there are times when the phone initially disconnects due to a timeout, and then it's just 133. Sometimes the phone reconnects to the device, but in other cases it takes a lot ( toggle bt, clear Bluetooth app / cache data, disconnect the app, etc.) to restore the deviceโs connection, and in rare cases, the device will not reconnect no matter what I try to do. Another thing that I find strange is that on the Samsung S6 and S7, if the device is connected to my application and I turned off the Bluetooth phone and then turned it on, the device cannot reconnect and I just see the status 133, Similar behavior on Nexus 5 when the phone reboots, and my boot receiver starts my service to connect to a peripheral device. Logs from the peripheral device do not provide any information, and when status 133 returns, it does not even report this to the device. Here is a snippet of logcat logs when trying to reconnect and fail:
03-28 18:59:27.381 8530-8530/myapp.android.dev D/CustomDevice.connect: thread: main, message: connect 03-28 18:59:27.383 8530-8530/myapp.android.dev D/BluetoothGatt: connect() - device: D8:6D:C8:C2:05:CE, auto: false 03-28 18:59:27.384 8530-8530/myapp.android.dev D/BluetoothGatt: registerApp() 03-28 18:59:27.384 8530-8530/myapp.android.dev D/BluetoothGatt: registerApp() - UUID=bd4590d1-a2d9-496c-b3c3-f1393c4a1c9b 03-28 18:59:27.388 8530-8542/myapp.android.dev D/BluetoothGatt: onClientRegistered() - status=0 clientIf=5 03-28 18:59:27.833 8530-8645/myapp.android.dev D/BluetoothGatt: onClientConnectionState() - status=133 clientIf=5 device=D8:6D:C8:C2:05:CE 03-28 18:59:27.835 8530-8645/myapp.android.dev I/CustomDevice$BleGattCallback.onConnectionStateChange: thread: Binder_3 message: GATT status :133 03-28 18:59:27.835 8530-8645/myapp.android.dev D/BluetoothGatt: close() 03-28 18:59:27.836 8530-8645/myapp.android.dev D/BluetoothGatt: unregisterApp() - mClientIf=5 03-28 18:59:27.838 8530-8645/myapp.android.dev D/CustomDevice.disconnect: thread: Binder_3 message: disconnect 03-28 18:59:27.840 8530-8645/myapp.android.dev D/BluetoothGatt: refresh() - device: D8:6D:C8:C2:05:CE 03-28 18:59:27.840 8530-8645/myapp.android.dev D/BluetoothGatt: cancelOpen() - device: D8:6D:C8:C2:05:CE 03-28 18:59:27.841 8530-8645/myapp.android.dev D/CustomDevice.close: thread: Binder_3 message: close 03-28 18:59:27.841 8530-8645/myapp.android.dev D/BluetoothGatt: close() 03-28 18:59:27.842 8530-8645/myapp.android.dev D/BluetoothGatt: unregisterApp() - mClientIf=0
These logs will only be loops and loops. So look for why this is happening. 133 means GATT error, but how should I deal with this programmatically? I saw some error messages in google about a similar problem, but this problem occurs in all versions of Android supported by my application, which is 5.0 and higher. I am really losing what to do with this problem. Sometimes, when another application simply scans for Bluetooth devices, my application will reconnect. Having Samsung phones stuck with this error 133, just turning the Bluetooth off and on is really unfortunate and annoying. I'm trying everything I can think of to fix or work around this problem, but it persists. Hope someone can give me some idea. Thank you for your time.
-Edit -
I changed the Bluetooth configuration file on my root phone to print all the Bluetooth log messages, and this happens when the phone is looping with status 133. However, the phone eventually connected to the device in a minute or so, just looped with this error . But here are the bluetooth logs, if someone can help understand them. I slowed down, trying to look at the code where the logs came from to find out if I could understand what was going on, but could definitely use a different set of eyes.
03-29 22:11:42.112 2802-2989/com.android.bluetooth I/bt_btm: btm_ble_set_connectability mode=0x0 combined_mode=0x1 03-29 22:11:42.120 2802-3001/com.android.bluetooth I/bt_btif: btif_dm_cancel_discovery 03-29 22:11:42.120 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x201 03-29 22:11:42.120 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_search_sm_execute state:0, event:0x201 03-29 22:11:42.121 2802-2989/com.android.bluetooth I/bt_btm: btif_dm_search_services_evt: 03-29 22:11:42.121 2802-2930/com.android.bluetooth I/bt_btif: btif_dm_search_services_evt: event = 6 03-29 22:11:42.122 2802-2930/com.android.bluetooth E/bt_btif_dm: ### ASSERT : system/bt/main/../btif/src/btif_dm.c line 1748 unhandled search services event (6) ### 03-29 22:11:42.138 2802-2829/com.android.bluetooth D/BtGatt.GattService: registerClient() - UUID=5330faee-9ba5-4656-aee4-fab95861ebd4 03-29 22:11:42.138 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f17 03-29 22:11:42.139 2802-2989/com.android.bluetooth D/bt_btif: bta_gattc_register state 2 03-29 22:11:42.139 2802-2989/com.android.bluetooth I/bt_att: GATT_Register 03-29 22:11:42.140 2802-2989/com.android.bluetooth D/bt_att: UUID=[0x5330faee9ba54656aee4fab95861ebd4] 03-29 22:11:42.140 2802-2989/com.android.bluetooth I/bt_att: allocated gatt_if=5 03-29 22:11:42.141 2802-2989/com.android.bluetooth I/bt_btif: HAL bt_gatt_callback 03-29 22:11:42.141 2802-2989/com.android.bluetooth I/bt_att: GATT_StartIf gatt_if=5 03-29 22:11:42.141 2802-2930/com.android.bluetooth I/bt_btif: gatt_find_the_connected_bda start_idx=0 03-29 22:11:42.142 2802-2989/com.android.bluetooth D/bt_att: gatt_find_the_connected_bda start_idx=0 03-29 22:11:42.142 2802-2930/com.android.bluetooth D/BtGatt.GattService: onClientRegistered() - UUID=5330faee-9ba5-4656-aee4-fab95861ebd4, clientIf=5 03-29 22:11:42.143 2802-2989/com.android.bluetooth D/bt_att: gatt_find_the_connected_bda found=0 found_idx=20 03-29 22:11:42.144 2802-12858/com.android.bluetooth D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@d471cca 03-29 22:11:42.145 2802-12858/com.android.bluetooth I/A2dpService: audio isMusicActive is false 03-29 22:11:42.146 2802-12858/com.android.bluetooth D/BtGatt.GattService: clientConnect() - address=D8:6D:C8:C2:05:CE, isDirect=true 03-29 22:11:42.147 2802-2930/com.android.bluetooth D/bt_btif_config: btif_get_address_type: Device [d8:6d:c8:c2:05:ce] address type 1 03-29 22:11:42.148 2802-2930/com.android.bluetooth D/bt_btif_config: btif_get_device_type: Device [d8:6d:c8:c2:05:ce] type 2 03-29 22:11:42.148 2802-2930/com.android.bluetooth D/bt_btif: BTA got event 0x112 03-29 22:11:42.148 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x112 03-29 22:11:42.149 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_sm_execute event:0x12 03-29 22:11:42.149 2802-2989/com.android.bluetooth D/bt_btm: BTM_SecAddBleDevice dev_type=0x2 03-29 22:11:42.149 2802-2989/com.android.bluetooth D/bt_btm: Device already exist 03-29 22:11:42.150 2802-2989/com.android.bluetooth I/bt_btm: BTM_InqDbRead: bd addr [d86dc8c205ce] 03-29 22:11:42.150 2802-2989/com.android.bluetooth D/bt_btm: InqDb device_type =0x2 addr_type=0x1 03-29 22:11:42.151 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f00 03-29 22:11:42.152 2802-2989/com.android.bluetooth I/bt_att: GATT_Connect gatt_if=5 03-29 22:11:42.152 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=1 03-29 22:11:42.153 2802-2989/com.android.bluetooth E/bt_btif: Connection open failure 03-29 22:11:42.153 2802-2930/com.android.bluetooth I/bt_btif: HAL bt_gatt_callbacks->client->open_cb 03-29 22:11:42.154 2802-2930/com.android.bluetooth D/BtGatt.GattService: onConnected() - clientIf=5, connId=0, address=D8:6D:C8:C2:05:CE 03-29 22:11:42.159 2802-3080/com.android.bluetooth D/BtGatt.GattService: unregisterClient() - clientIf=5 03-29 22:11:42.160 2802-2930/com.android.bluetooth D/bt_btif: btif_obtain_multi_adv_data_cb, Count:16 03-29 22:11:42.160 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f18 03-29 22:11:42.161 2802-2989/com.android.bluetooth I/bt_att: GATT_Deregister gatt_if=5 03-29 22:11:42.162 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=1 03-29 22:11:42.162 2802-2989/com.android.bluetooth D/bt_att: gatt_update_app_use_link_flag is_add=0 chk_link=0 03-29 22:11:42.163 2802-2989/com.android.bluetooth D/bt_att: gatt_update_app_hold_link_status found=0[1-found] idx=32 gatt_if=5 is_add=0 03-29 22:11:42.163 2802-2989/com.android.bluetooth D/bt_att: gatt_num_apps_hold_link num=0 03-29 22:11:42.164 2802-2989/com.android.bluetooth D/bt_att: gatt_disconnect 03-29 22:11:42.165 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=1 03-29 22:11:42.166 2802-2989/com.android.bluetooth D/bt_att: gatt_disconnect already in closing state 03-29 22:11:42.167 2802-2989/com.android.bluetooth I/bt_att: GATT_Listen gatt_if=5 03-29 22:11:42.167 2802-2989/com.android.bluetooth I/bt_btm: BTM_BleUpdateAdvFilterPolicy 03-29 22:11:42.168 2802-2989/com.android.bluetooth I/bt_btm: BTM_ReadConnectability
Here are the logs of when the device successfully connects, and the differences that I think are important have stars in front of the lines.
03-29 22:12:07.278 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x104 03-29 22:12:07.279 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_sm_execute event:0x4 03-29 22:12:07.279 2802-2989/com.android.bluetooth D/bt_btm: btm_get_acl_disc_reason_code 03-29 22:12:07.280 2802-2989/com.android.bluetooth W/bt_l2cap: btif_dm_upstreams_cback ev: BTA_DM_LINK_DOWN_ 03-29 22:12:07.280 2802-2930/com.android.bluetooth I/bt_btif: BTA got event 0x104 03-29 22:12:07.281 2802-2989/com.android.bluetooth I/bt_btif: BTA_DM_LINK_DOWN_EV 03-29 22:12:07.281 2802-2930/com.android.bluetooth D/bt_btif: bta_dm_sm_execute event:0x4 03-29 22:12:07.281 2802-2989/com.android.bluetooth I/bt_btif: num_active_le_links is 0 03-29 22:12:07.281 2802-2930/com.android.bluetooth D/bt_btif: BTA got event 0x1f17 03-29 22:12:07.282 2802-2989/com.android.bluetooth I/bt_btif: btif_av_move_idle: A 03-29 22:12:07.283 2802-2989/com.android.bluetooth D/bt_btif: bta_gattc_register state 2 03-29 22:12:07.282 2802-2930/com.android.bluetooth D/bt_btif: GATT_Register 03-29 22:12:07.284 2802-2989/com.android.bluetooth I/bt_att: BTA_DM_LINK_D 03-29 22:12:07.285 2802-2930/com.android.bluetooth D/bt_btif: UUID=[0xa701255809b941c99db97751dcd19f58] 03-29 22:12:07.285 2802-2989/com.android.bluetooth D/bt_att: HAL bt_hal_cbacks->acl_state_changed_cb 03-29 22:12:07.286 2802-2930/com.android.bluetooth I/bt_btif: allocated gatt_if=6 03-29 22:12:07.286 2802-2989/com.android.bluetooth I/bt_att: allocated gatt_if=6 03-29 22:12:07.286 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f16 03-29 22:12:07.287 2802-2989/com.android.bluetooth I/bt_att: GATT_StartIf gatt_if=6 03-29 22:12:07.287 2802-2989/com.android.bluetooth D/bt_att: gatt_find_the_connected_bda start_idx=0 03-29 22:12:07.288 2802-2989/com.android.bluetooth D/bt_att: gatt_find_the_connected_bda found=0 found_idx=20 03-29 22:12:07.298 2802-2930/com.android.bluetooth E/BluetoothRemoteDevices: state12newState1 03-29 22:12:07.298 2802-2930/com.android.bluetooth D/BluetoothRemoteDevices: aclStateChangeCallback: sending ACL disconnected intent 03-29 22:12:07.299 2802-2930/com.android.bluetooth D/BluetoothRemoteDevices: aclStateChangeCallback: State:DisConnected to Device:D8:6D:C8:C2:05:CE 03-29 22:12:07.301 2802-2930/com.android.bluetooth I/bt_btif: btif_dm_upstreams_cback ev: BTA_DM_BUSY_LEVEL_EVT 03-29 22:12:07.301 2802-2930/com.android.bluetooth I/bt_btif: HAL bt_gatt_callbacks->client->register_client_cb 03-29 22:12:07.301 2802-2930/com.android.bluetooth D/BtGatt.GattService: onClientRegistered() - UUID=a7012558-09b9-41c9-9db9-7751dcd19f58, clientIf=6 03-29 22:12:07.304 2802-2802/com.android.bluetooth D/BluetoothMapService: onReceive 03-29 22:12:07.304 2802-2802/com.android.bluetooth D/BluetoothMapService: onReceive: android.bluetooth.device.action.ACL_DISCONNECTED 03-29 22:12:07.303 2802-2830/com.android.bluetooth D/A2dpService: getA2DPService(): returning com.android.bluetooth.a2dp.A2dpService@d471cca 03-29 22:12:07.306 2802-2830/com.android.bluetooth I/A2dpService: audio isMusicActive is false 03-29 22:12:07.309 2802-2830/com.android.bluetooth D/BtGatt.GattService: clientConnect() - address=D8:6D:C8:C2:05:CE, isDirect=true 03-29 22:12:07.310 2802-2930/com.android.bluetooth D/bt_btif_config: btif_get_address_type: Device [d8:6d:c8:c2:05:ce] address type 1 03-29 22:12:07.310 2802-2930/com.android.bluetooth D/bt_btif_config: btif_get_device_type: Device [d8:6d:c8:c2:05:ce] type 2 03-29 22:12:07.311 2802-2802/com.android.bluetooth V/BluetoothPbapService: action: android.bluetooth.device.action.ACL_DISCONNECTED 03-29 22:12:07.311 2802-2930/com.android.bluetooth D/bt_btif: BTA_GATTC_Open Transport = 2, dev type = 2 03-29 22:12:07.312 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x112 03-29 22:12:07.312 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_sm_execute event:0x12 03-29 22:12:07.313 2802-2989/com.android.bluetooth D/bt_btm: BTM_SecAddBleDevice dev_type=0x2 03-29 22:12:07.313 2802-2989/com.android.bluetooth D/bt_btm: Device already exist 03-29 22:12:07.313 2802-2989/com.android.bluetooth I/bt_btm: BTM_InqDbRead: bd addr [d86dc8c205ce] 03-29 22:12:07.314 2802-2989/com.android.bluetooth D/bt_btm: InqDb device_type =0x2 addr_type=0x1 03-29 22:12:07.314 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f00 **03-29 22:12:07.315 2802-2989/com.android.bluetooth I/bt_att: GATT_Connect gatt_if=6 **03-29 22:12:07.315 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=0 **03-29 22:12:07.316 2802-2989/com.android.bluetooth D/bt_att: gatt_set_ch_state: old=0 new=2 03-29 22:12:07.316 2802-2989/com.android.bluetooth I/bt_l2cap: L2CA_ConnectFixedChnl() CID: 0x0004 BDA: d86dc8c205ce 03-29 22:12:07.316 2802-2989/com.android.bluetooth I/bt_l2cap: l2c_ble_link_adjust_allocation num_hipri: 0 num_lowpri: 1 low_quota: 16 round_robin_quota: 0 qq: 16 03-29 22:12:07.317 2802-2989/com.android.bluetooth I/bt_l2cap: l2c_ble_link_adjust_allocation LCB 0 Priority: 0 XmitQuota: 16 03-29 22:12:07.317 2802-2989/com.android.bluetooth I/bt_l2cap: SentNotAcked: 0 RRUnacked: 0 03-29 22:12:07.317 2802-2989/com.android.bluetooth D/bt_l2cap: l2cu_allocate_ccb: cid 0x0000 03-29 22:12:07.318 2802-2989/com.android.bluetooth D/bt_l2cap: l2c_link_adjust_chnl_allocation 03-29 22:12:07.318 2802-2989/com.android.bluetooth D/bt_l2cap: POOL ID:3, GKI_poolcount = 400, reserved_buff = 0, weighted_chnls = 2, quota_per_weighted_chnls = 201 03-29 22:12:07.319 2802-2989/com.android.bluetooth I/bt_l2cap: CID:0x0047 Priority:2 TxDataRate:1 Quota:201 03-29 22:12:07.319 2802-2989/com.android.bluetooth I/bt_btm: BTM_InqDbRead: bd addr [d86dc8c205ce] 03-29 22:12:07.320 2802-2989/com.android.bluetooth D/bt_btm: btm_find_dev_type - device_type = 2 addr_type = 1 03-29 22:12:07.320 2802-2989/com.android.bluetooth I/bt_btm: btm_find_or_alloc_dev 03-29 22:12:07.323 2802-2989/com.android.bluetooth D/bt_att: gatt_update_app_use_link_flag is_add=1 chk_link=0 03-29 22:12:07.324 2802-2989/com.android.bluetooth D/bt_att: gatt_update_app_hold_link_status found=1[1-found] idx=0 gatt_if=6 is_add=1 03-29 22:12:07.324 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=2 03-29 22:12:07.325 2802-2989/com.android.bluetooth I/bt_att: GATT_GetConnIdIfConnected status=0 03-29 22:12:07.346 2802-3001/com.android.bluetooth I/bt_btif: btif_dm_get_remote_services: remote_addr=d8:6d:c8:c2:05:ce 03-29 22:12:07.346 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x202 03-29 22:12:07.346 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_search_sm_execute state:0, event:0x202 03-29 22:12:07.347 2802-2989/com.android.bluetooth I/bt_btif: bta_dm_discover services_to_search=0x7FFFFFFF, sdp_search=1 03-29 22:12:07.348 2802-2989/com.android.bluetooth I/bt_btm: BTM_InqDbRead: bd addr [d86dc8c205ce] 03-29 22:12:07.348 2802-2989/com.android.bluetooth I/bt_btm: BTM_InqDbRead: bd addr [d86dc8c205ce] 03-29 22:12:07.348 2802-2989/com.android.bluetooth D/bt_btm: btm_find_dev_type - device_type = 2 addr_type = 1 03-29 22:12:07.349 2802-2989/com.android.bluetooth D/bt_btif: bta_dm_discover_device BDA:0xD86DC8C205CE 03-29 22:12:07.349 2802-2989/com.android.bluetooth D/bt_btif: bta_dm_discover_device name_discover_done = 0 p_btm_inq_info 0xf3def708 state = 3, transport=2 03-29 22:12:07.349 2802-2989/com.android.bluetooth D/bt_btif: bta_dm_discover_device appl_knows_rem_name 1 03-29 22:12:07.350 2802-2989/com.android.bluetooth I/bt_btm: BTM_IsAclConnectionUp: RemBdAddr: d86dc8c205ce 03-29 22:12:07.350 2802-2989/com.android.bluetooth D/bt_btif: bta_dm_discover_device p_btm_inq_info 0xf3def708 results.device_type 0x2 services_to_search 0x7fffffff 03-29 22:12:07.351 2802-2989/com.android.bluetooth I/bt_btif: BTA got event 0x1f00 03-29 22:12:07.351 2802-2989/com.android.bluetooth I/bt_att: GATT_Connect gatt_if=3 03-29 22:12:07.351 2802-2989/com.android.bluetooth D/bt_att: gatt_get_ch_state: ch_state=2
The ch_state parameter is 1 when it fails, and ch_state = 1 = GATT_CH_CLOSING, and below when the device connects, ch_state = 0 = GATT_CH_CLOSE. Then the next line shows that ch_state changes to 2, which is = GATT_CH_CONN. Does this mean that BluetoothGatt is not closed, that it is in the process of closing? Only when it closes, can it connect to the device? BluetoothGatt.close () is called twice when disconnected. I'm going to try to make him call only once to see that this will change something. Maybe I donโt wait long enough before calling Connect again?
In a separate note, S6 and S7 now reconnect to the device after rebooting, when I added mBluetoothAdapter.startDiscovery() before calling mBluetoothAdapter.getRemoteDevice(address) and then canceled the discovery before calling connectGatt on the device. The S6 connects pretty quickly, but the S7 makes several attempts before it connects again. It is not entirely clear why this works.