Re: [BUG] BLE device unpairing triggers kernel panic

[Ahmad Fatoum <a.fatoum@pengutronix.de>]

Hello Luiz,

On 16.05.22 18:37, Ahmad Fatoum wrote:
>>>> - Commit a56a1138cbd8 ("Bluetooth: hci_sync: Fix not using conn_timeout")
>>>>   fixes, despite the title, what event is waited on. First Pairing works now,
>>>>   but the second pairing times out and crashes the kernel:
>>>>
>>>>   [   84.191684] Bluetooth: hci0: Opcode 0x200d failed: -110
>>>>   [   84.230478] Bluetooth: hci0: request failed to create LE connection: err -110
>>>>   [   84.237690] Unable to handle kernel read from unreadable memory at virtual address 0000000000000ca8
>>
>> That said the error -110 mean -ETIMEDOUT
> 
> Yes, this issue remains still. I feel better about my revert
> knowing that the crash is fixed, but I'd like this regression
> here fixed upstream as well. I'll try to collect some more
> information and report back.

I've now found time to revisit this and sprinkle around some
extra logging. This is the initial pairing that works:

  Bluetooth: entered hci_le_create_conn_sync()
  Bluetooth: hci0: opcode 0x200d plen 25
  Bluetooth: hci0: event 0x0f (sent = 0x0a)
  Bluetooth: hci0: BT: opcode 0x200d (sent: 0x0a)
  Bluetooth: hci0: event 0x3e (sent = 0x0a)
  Bluetooth: hci0: BT: subevent 0x0a (sent 0x0a)
  Bluetooth: entered hci_le_meta_evt(event=0x0a) completion clause

I unpaired on device side and then retried pairing:

  Bluetooth: entered hci_le_create_conn_sync()
  Bluetooth: hci0: opcode 0x200d plen 25
  Bluetooth: hci0: event 0x0f (sent = 0x0a)
  Bluetooth: hci0: BT: opcode 0x200d (sent: 0x0a)
  Bluetooth: entered hci_abort_conn()
  Bluetooth: hci0: opcode hci_req_add_ev 0x200e
  Bluetooth: hci0: event 0x0e (sent = 0x00)
  Bluetooth: hci0: event 0x3e (sent = 0x00)
  Bluetooth: hci0: BT: subevent 0x0a (sent 0x00)
  Bluetooth: __hci_cmd_sync_sk pending (event = 0x0a status=1, err=-110)
  Bluetooth: hci0: Opcode 0x200d failed: -110
  Bluetooth: hci0: opcode 0x2006 plen 15
  Bluetooth: hci0: event 0x0e (sent = 0x00)
  Bluetooth: hci0: opcode 0x200a plen 1
  Bluetooth: hci0: event 0x0e (sent = 0x00)
  Bluetooth: hci0: request failed to create LE connection: err -110


But now it times out as reported. It looks like the
intermittent hci_abort_conn() is at fault here. My theory is
that replacing hci->sent_cmd is the problem here, as other
events can't be matched anymore.

We've been deploying the revert for a while now and I just posted
it to the mailing list[1]. There have been other reports
of this issue with different hardware too and fixing sent_cmd
would likely be too complicated/time intensive for me.

I am happy to test future patches that fix this properly though.

[1]: https://lore.kernel.org/linux-bluetooth/20220616092418.738877-1-a.fatoum@pengutronix.de/T/#t

Cheers,
Ahmad



> 
> Cheers,
> Ahmad
> 


-- 
Pengutronix e.K.                           |                             |
Steuerwalder Str. 21                       | http://www.pengutronix.de/  |
31137 Hildesheim, Germany                  | Phone: +49-5121-206917-0    |
Amtsgericht Hildesheim, HRA 2686           | Fax:   +49-5121-206917-5555 |