Hi Ahmad,
On Thu, Jun 16, 2022 at 3:38 AM Ahmad Fatoum <a.fatoum@xxxxxxxxxxxxxx> wrote:
>
> 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.
Yep, unpair command uses hci_abort_conn when it should really be using
hci_abort_conn_sync, the problem is if we do that then it probably no
longer work because it would have to wait for sync queue to complete
so it would only be able to disconnect after the connect command
completes, well perhaps that is acceptable otherwise we need a
different queue to handle command that abort/cancel other already in
the queue.
> 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@xxxxxxxxxxxxxx/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 |
--
Luiz Augusto von Dentz
