I have a fairly simple application running on an nRF52832 exposing a few services over Bluetooth LE. I received a report of a Lenovo M10 (TB328FU) that was unable to connect. I imported one to test with and was able to reproduce the issue, even with the tablet fully patched. I haven't seen this issue with any other Android or iOS devices. As a (hopefully temporary) workaround, I disabled the 2 Mbps PHY which avoids the issue and the M10 can then connect and communicate successfully.
I found that the nRF is reporting an error when the M10 tries to change the PHY from 1 Mbps to 2 Mbps during the connection. Based on the error, I assume it is coming from the SoftDevice, but I'm new to this and don't understand exactly what is going on or what I may be able to adjust to resolve it.
Here's what appears to me to be the problematic packet in the sniffer (full sniffer pcap also attached of to M10 failing to connect). The Expert error is "Initiating a new incompatible control procedure after having sent a response to an incompatible control procedure"
In the nRF's log I see the following line right before disconnection:
bt_hci_core: hci_disconn_complete: status 0x00 handle 0 reason 0x2a
I'm not sure what reason 2a implies, but traced it to a name "BT_HCI_ERR_DIFF_TRANS_COLLISION".
Thanks for looking and I appreciate any guidance you can offer!
[00:00:19.141,296] <dbg> bt_conn: conn_prepare_events: Adding conn 0x20001ed8 to poll list [00:00:19.141,326] <dbg> bt_conn: conn_prepare_events: wait on host fifo [00:00:19.141,326] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events [00:00:19.141,387] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20007b74 opcode 0x2016 len 0 [00:00:19.141,418] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2032 param_len 7 [00:00:19.141,448] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20007b74 [00:00:19.141,479] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20007b74 opcode 0x2032 len 10 [00:00:19.141,510] <dbg> bt_hci_core: process_events: count 3 [00:00:19.141,540] <dbg> bt_hci_core: process_events: ev->state 4 [00:00:19.141,571] <dbg> bt_hci_core: send_cmd: calling net_buf_get [00:00:19.141,571] <dbg> bt_hci_core: send_cmd: calling sem_take_wait [00:00:19.141,601] <dbg> bt_hci_core: send_cmd: Sending command 0x2032 (buf 0x20007b74) to driver [00:00:19.141,632] <dbg> bt_hci_core: bt_send: buf 0x20007b74 len 10 type 0 [00:00:19.141,662] <dbg> bt_sdc_hci_driver: hci_driver_send: [00:00:19.141,662] <dbg> bt_sdc_hci_driver: cmd_handle: [00:00:19.141,723] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0 [00:00:19.141,754] <dbg> bt_hci_core: process_events: ev->state 0 [00:00:19.141,784] <dbg> bt_hci_core: process_events: ev->state 0 [00:00:19.141,815] <dbg> bt_sdc_hci_driver: event_packet_process: Command Status (0x2032) status: 0x00 [00:00:19.141,845] <dbg> bt_hci_core: bt_recv: buf 0x20007b74 len 6 [00:00:19.141,876] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2032 [00:00:19.141,876] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2032 status 0x00 buf 0x20007b74 [00:00:19.141,967] <dbg> bt_conn: bt_conn_prepare_events: [00:00:19.141,998] <dbg> bt_conn: conn_prepare_events: Adding conn 0x20001ed8 to poll list [00:00:19.141,998] <dbg> bt_conn: conn_prepare_events: wait on host fifo [00:00:19.142,028] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events [00:00:19.142,089] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20007b74 opcode 0x2032 len 0 [00:00:19.142,120] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1 [00:00:19.266,235] <dbg> bt_sdc_hci_driver: event_packet_process: LE Meta Event (0x04), len (12) [00:00:19.266,265] <dbg> bt_hci_core: bt_recv: buf 0x20007890 len 14 [00:00:19.266,357] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue [00:00:19.266,357] <dbg> bt_hci_core: rx_work_handler: buf 0x20007890 type 1 len 14 [00:00:19.266,387] <dbg> bt_hci_core: hci_event: event 0x3e [00:00:19.266,387] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x04 [00:00:19.266,418] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2 [00:00:19.266,448] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1 [00:00:19.536,132] <dbg> bt_sdc_hci_driver: event_packet_process: LE Meta Event (0x07), len (11) [00:00:19.536,163] <dbg> bt_hci_core: bt_recv: buf 0x20007890 len 13 [00:00:19.536,224] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue [00:00:19.536,254] <dbg> bt_hci_core: rx_work_handler: buf 0x20007890 type 1 len 13 [00:00:19.536,285] <dbg> bt_hci_core: hci_event: event 0x3e [00:00:19.536,285] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x07 [00:00:19.536,315] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2 [00:00:19.536,346] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1 [00:00:19.806,243] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2 --- 3 messages dropped --- [00:00:19.806,274] <dbg> bt_conn: bt_conn_set_state: connected -> disconnect-complete [00:00:19.806,304] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1 [00:00:19.806,365] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue [00:00:19.806,396] <dbg> bt_hci_core: rx_work_handler: buf 0x20007890 type 1 len 6 [00:00:19.806,427] <dbg> bt_hci_core: hci_event: event 0x05 [00:00:19.806,427] <dbg> bt_hci_core: hci_disconn_complete: status 0x00 handle 0 reason 0x2a [00:00:19.806,457] <dbg> bt_conn: bt_conn_ref: handle 0 ref 1 -> 2 [00:00:19.806,518] <dbg> bt_conn: bt_conn_set_state: disconnect-complete -> disconnected [00:00:19.806,518] <dbg> bt_conn: tx_notify: conn 0x20001ed8 [00:00:19.806,549] <dbg> bt_conn: bt_conn_unref: handle 0 ref 2 -> 1 [00:00:19.806,610] <dbg> bt_hci_core: process_events: count 3 [00:00:19.806,610] <dbg> bt_hci_core: process_events: ev->state 0 [00:00:19.806,640] <dbg> bt_hci_core: process_events: ev->state 1 [00:00:19.806,640] <dbg> bt_hci_core: process_events: ev->state 0 [00:00:19.806,671] <dbg> bt_conn: bt_conn_prepare_events: [00:00:19.806,701] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events [00:00:19.806,732] <dbg> bt_conn: deferred_work: conn 0x20001ed8 [00:00:19.806,762] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001ed8 chan 0x20003b5c [00:00:19.806,762] <dbg> bt_l2cap: l2cap_disconnected: ch 0x20003b5c cid 0x0005 [00:00:19.806,793] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001ed8 chan 0x20003cf0 [00:00:19.806,823] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20001ed8 chan 0x2000585c [00:00:19.806,823] <dbg> bt_att: bt_att_disconnected: chan 0x2000585c cid 0x0004 [00:00:19.806,854] <dbg> bt_att: att_chan_detach: chan 0x20005858 [00:00:19.806,884] <dbg> bt_gatt: bt_gatt_disconnected: conn 0x20001ed8 [00:00:19.806,976] <dbg> bt_att: bt_att_released: chan 0x20005858 [00:00:19.807,006] <dbg> bt_conn: bt_conn_unref: handle 0 ref 1 -> 0
