Looping 133 status in BluetoothGattCallback onConnectionStateChange

5

So I haven't been able to figure out what's causing this issue or how to work around it. I'm developing an app that stays connected to a BLE peripheral all day and collects data from sensors on the device. At times, the device will disconnect, and when I look at the logcat, I just see the reconnection failing and the BluetoothGattCallback onConnectionStateChange callback gets a 133 status, and this will just loop. Killing the app, toggling the phone bluetooth off and on, clearing bluetooth cache are all things we try to get the device to reconnect. I connect to the device on the main thread like so:

    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 the peripheral address), and I reuse the object if I still have an instance to connect again. I'm currently trying to use BluetoothAdapter.getRemoteDevice to get a new BluetoothDevice instance to create a new custom Device object and call the above code. The onConnectionStateChange looks like this:

    @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 {
                // https://code.google.com/p/android/issues/detail?id=183108
                gatt.close();
                disconnect();
             } catch (Exception e) {
                Logger.d("close ignoring: " + e);
             }
             broadcastDisconnected();
        }
    }

Then disconnect method calls the hidden refresh method on the bluetoothGatt object, then calls mBluetoothGatt.disconnect(), and then mBluetoothGatt.close(). With this code, the phones I test on generally do pretty well, but there are times when the phone will initially disconnect because of a timeout, and then it's just 133. Sometimes the phone reconnects to the device, but other times it takes a lot of finessing(toggle bt, clear Bluetooth Share app's data/cache, kill the app, etc) to get the device to reconnect, and on rare occasions the device won't reconnect no matter what I try. Another thing that I find odd is that on Samsung S6 and S7, if the device is connected to my app, and I turn the phone's bluetooth off, and then turn it on, the device is unable to reconnect and I just see the 133 status. Similar behavior on the Nexus 5 when I reboot the phone and my boot receiver starts my service to connect to the peripheral device. The logs from the peripheral device haven't provided any insight, and when the 133 status is being returned, it's not even communicating to the device at all. Here is a snippet of logcat logs when trying to reconnect and failing:

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 just loop and loop. So looking for why this is happening. The 133 means GATT error, but how should I deal with this programmatically? I've seen some of the bug reports to google about similar issue, but this problem is happening on all versions of android that my app supports, which is 5.0 and up. I'm really at a lose on what to do about this issue. Sometimes having another app just scan for Bluetooth devices will get my app to reconnect. Having the Samsung phones get stuck with this 133 error just by turning Bluetooth off and on is really unfortunate and annoying. I've been trying everything I can think of to fix or work around this issue but it persists. Hopefully someone can give me some insight. Thanks for your time.

-EDIT-

I've changed the Bluetooth config file on my rooted phone to print out all the bluetooth log messages, and this is from when the phone was looping with the 133 status. However, the phone eventually connected to the device after a min or so of just looping with this error. But here are the bluetooth logs if anyone can help make sense of these. I'm been slowing trying to look at the code where the logs are coming from to see if I can figure out what's happening, but definitely could use another 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 logs of when the device successfully connects, and the differences that I think might be 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 is 1 above 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 the ch_state changes to 2, which = GATT_CH_CONN. So does this mean that the BluetoothGatt isn't closed, that it's in the process of closing? Only when it's close can it connect to the device? BluetoothGatt.close() gets called twice when the disconnect happens. I'm going to try and make it only call close once to see if that changes anything. Maybe I don't wait long enough before calling connect again?

On a separate note, the S6 and S7 now reconnect with the device after rebooting when I added mBluetoothAdapter.startDiscovery() before calling mBluetoothAdapter.getRemoteDevice(address) and then cancel discovery before calling connectGatt on the device. The S6 connects pretty quick, but the S7 takes a few attempts before it finally reconnects. Not exactly sure why this works.

android
bluetooth
bluetooth-lowenergy
gatt
bluetooth-gatt
asked on Stack Overflow Mar 29, 2017 by salbury • edited Nov 6, 2017 by salbury

0 Answers

Nobody has answered this question yet.


User contributions licensed under CC BY-SA 3.0