问题现象
去掉蓝牙鼠标“输入设备”功能后,重新勾选“输入设备”后,蓝牙一直处于“正在连接”状态
复现概率
必现
复现步骤
- 开机
- 打开蓝牙
- 搜索蓝牙鼠标
- 连接蓝牙鼠标
- 连接成功后,正常使用鼠标
- 取消“输入设备”功能
- 移动鼠标多次
- 打开“输入设备”功能
- 观察
测试现象
- 执行第七步时,移动鼠标,还可以看见鼠标指针在屏幕上闪动,闪动几秒后鼠标不动或消失
- 执行第八步时,鼠标一直处于“正在连接”状态,不恢复。
- 如果取消第七步,第八步效果正常。
问题分析
- 第一次连接蓝牙鼠标后,GATT发起SDP扫描,Android建立gatt_conn_id = 1的channel。完成discovery后,该channel一直存在,没有关闭
- 取消“输入设备”功能,GATT断开conn_id=4后,判断当前app是否有hold更多的channel,发现conn_id=1仍在使用,故不disconnect整个链路。
- 移动鼠标,由于链路没有断开,协议栈收到鼠标发送的gatt notification。协议栈自动处理,发现该设备依然存在,状态为disconnect。协议栈自动open并init connection。GATT状态正常后,上报至Framework。上层通过判断,发现用户手动取消输入设备功能,所以拒绝本次请求,发送reject。此时输入设备驱动已经add,所以在reject完成之前所收到的GATT包就正常传递到驱动处理。所以屏幕还上能看到鼠标移动或晃动。
- Reject完成后,设备再次进入close状态。这时又收到gatt notification,又将重复之前自动重连的操作,由于驱动多次add和remove,协议栈hid设备状态将异常停止在Connected,并不再处理数据上报。此时上层认为设备未连接,驱动认为节点未生成,协议栈认为设备状态已连接。
- 重新打开“输入设备”功能,Framework发起connect请求,协议栈接受到init conn请求,但由于协议栈正处于connected状态,对init connect操作为空(ignore)。所以忽略本次请求。
- 上层界面邮局发送了connect,变处于connection状态,没有收到stack的回复,便一直处于connection,不能回复。
问题解决方案
该问题再商用7.0上有做对比,依然存在。如果需要修改,可以参照Android M设计。AndroidM在搜索完成后,或异常情况下,都会主动释放掉对应的channel。如果本次测试中,连接完成后就释放掉conn_id=1的channel。那么取消“输入设备”后,APP就不再hold住任何channel,stack便会主动disconnect掉链路。链路disconnect后便不再接受notification,也就没有后面协议栈状态异常问题。
问题思考
本次问题的根本原因还是协议栈状态异常,解决方案只是一种workaround。但是就算解决了协议栈状态异常问题,根据Android N的策略,不让链路断开,那么就会出现,取消“输入设备”功能后,移动鼠标,界面一样有反应,反应为鼠标晃动,停止,晃动不停的重复。因为协议栈一直会不停的重连,应用不停的拒绝。
Log记录
取消“输入设备”:
01-02 06:15:56.352 3489 3489 D BluetoothInputDevice: disconnect(E6:71:40:79:75:FD)
01-02 06:15:56.364 4729 4729 I bt_btif : BTHH: disconnect
01-02 06:15:56.364 4729 4750 I bt_btif : btif_hh_handle_evt: event=1
01-02 06:15:56.364 4729 4750 I bt_btif : btif_hh_handle_evt: event=1
01-02 06:15:56.364 4729 4761 I bt_btif : BTA got event 0x1701
01-02 06:15:56.364 4729 4761 D bt_btif : bta_hh_dev_handle_to_cb_idx dev_handle = 16 index = 0
01-02 06:15:56.364 4729 4761 D bt_btif : bta_hh_hdl_event:: handle = 16 dev_cb[0]
01-02 06:15:56.364 4729 4761 I bt_btif : bta_hh_sm_execute: State 0x03 [BTA_HH_CONN_ST], Event [BTA_HH_API_CLOSE_EVT]
01-02 06:15:56.364 4729 4761 I bt_btif : BTA got event 0x1f08
01-02 06:15:56.364 4729 4761 D bt_btif : bta_gattc_hdl_event: Event [BTA_GATTC_API_CLOSE_EVT]
01-02 06:15:56.364 4729 4761 D bt_btif : bta_gattc_sm_execute: State 0x02 [GATTC_CONN_ST], Event 0x1f08[BTA_GATTC_API_CLOSE_EVT]
01-02 06:15:56.364 4729 4761 D bt_btif : bta_gattc_close conn_id=4
01-02 06:15:56.364 4729 4761 I bt_att : GATT_Disconnect conn_id=4
01-02 06:15:56.364 4729 4761 D bt_att : gatt_update_app_use_link_flag is_add=0 chk_link=1
01-02 06:15:56.364 4729 4761 D bt_att : gatt_update_app_hold_link_status found=1[1-found] idx=2 gatt_if=4 is_add=0
01-02 06:15:56.364 4729 4761 D bt_btm : BTM_GetHCIConnHandle
01-02 06:15:56.364 4729 4761 D bt_btm : btm_bda_to_acl found
01-02 06:15:56.364 4729 4761 D bt_att : gatt_num_apps_hold_link num=1
01-02 06:15:56.364 4729 4761 D bt_btif : bta_hh_gattc_callback event = 5
01-02 06:15:56.364 4729 4761 D bt_btif : GATTC State Change: [GATTC_CONN_ST] -> [GATTC_IDLE_ST] after Event [BTA_GATTC_API_CLOSE_EVT]
01-02 06:15:56.365 4729 4761 I bt_btif : BTA got event 0x1f02
01-02 06:15:56.365 4729 4761 D bt_btif : bta_gattc_hdl_event: Event [BTA_GATTC_API_CANCEL_OPEN_EVT]
移动鼠标,自动重连:
01-02 06:15:57.159 4729 4755 D bt_snoop_sprd: 22:15:57:159018 kAclPacket
01-02 06:15:57.159 4729 4755 D bt_snoop_sprd: record diff: 193
01-02 06:15:57.159 4729 4761 D bt_btm : btm_bda_to_acl found
01-02 06:15:57.159 4729 4761 I bt_btm : btm_find_or_alloc_dev
01-02 06:15:57.159 4729 4761 D bt_att : gatt_get_ch_state: ch_state=4
01-02 06:15:57.159 4729 4761 D bt_att : gatt_process_notification
01-02 06:15:57.159 4729 4761 D bt_att : gatt_get_link_encrypt_status status=0x8d
01-02 06:15:57.159 4729 4761 I bt_gap : gap_ble_c_cmpl_cback() - op_code: 0x06 status: 0x8d read_type: 0x0000
01-02 06:15:57.159 4729 4761 D bt_btif : bta_gattc_cmpl_cback: conn_id = 3 op = 6 status = 141
01-02 06:15:57.159 4729 4761 I bt_att : GATT_GetConnectionInfor conn_id=3
01-02 06:15:57.159 4729 4761 D bt_btif : bta_gattc_cmpl_cback: conn_id = 4 op = 6 status = 141
01-02 06:15:57.159 4729 4761 I bt_att : GATT_GetConnectionInfor conn_id=4
01-02 06:15:57.159 4729 4761 D bt_btif : Notification registered!
01-02 06:15:57.159 4729 4761 D bt_btif : bta_gattc_clcb_alloc: found clcb[0] available
01-02 06:15:57.159 4729 4761 D bt_btif : bta_gattc_sm_execute: State 0x00 [GATTC_IDLE_ST], Event 0x1f0d[BTA_GATTC_INT_CONN_EVT]
01-02 06:15:57.159 4729 4761 D bt_btif : bta_gattc_conn server cache state=0
01-02 06:15:57.159 4729 4761 D bt_btif : bta_hh_gattc_callback event = 2
01-02 06:15:57.159 4729 4761 I bt_btif : bta_hh_sm_execute: State 0x01 [BTA_HH_IDLE_ST], Event [BTA_HH_GATT_OPEN_EVT]
01-02 06:15:57.159 4729 4761 D bt_btif : bta_hh_gatt_open BTA_GATTC_OPEN_EVT bda= [e671407975fd] status =0
01-02 06:15:57.159 4729 4761 D bt_btif : hid_handle = 10 conn_id = 0004 cb_index = 0
01-02 06:15:57.159 4729 4761 I bt_btif : bta_hh_sm_execute: State 0x02 [BTA_HH_W4_CONN_ST], Event [BTA_HH_START_ENC_EVT]
01-02 06:15:57.159 4729 4761 I bt_btif : bta_hh_sm_execute: State 0x04 [BTA_HH_W4_SEC], Event [BTA_HH_ENC_CMPL_EVT]
01-02 06:15:57.160 4729 4761 I bt_btif : bta_hh_sm_execute: State 0x02 [BTA_HH_W4_CONN_ST], Event [BTA_HH_OPEN_CMPL_EVT]
01-02 06:15:57.160 4729 4761 W bt_btif : bta_hh_co_open: Found an existing device with the same handle dev_status = 2
01-02 06:15:57.160 4729 4761 W bt_btif : bta_hh_co_open: bd_addr = [E6:71:40:79:75:]
01-02 06:15:57.160 4729 4761 W bt_btif : bta_hh_co_open: attr_mask = 0x0000, sub_class = 0x00, app_id = 255
01-02 06:15:57.160 4729 4761 D bt_btif : bta_hh_co_open: uhid fd = 95
APP拒绝本次请求
01-02 06:15:57.165 4729 4729 D HidService: Incoming HID connection rejected
01-02 06:15:57.166 4729 4729 I bt_btif : BTHH: disconnect
01-02 06:15:57.313 4729 4750 I bt_btif : btif_hh_handle_evt: event=1
01-02 06:15:57.313 4729 4750 I bt_btif : btif_hh_handle_evt: event=1
01-02 06:15:57.313 4729 4761 I bt_btif : BTA got event 0x1701
正常情况下,应该不停的上报已连接,APP不停拒绝,但是协议栈出现异常,出现啥异常,不情况,太乱了。
就当一次总结吧,也不枉费这么多时间。