Received-SPF: pass (google.com: domain of linux-bluetooth-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
From:   Raul Cheleguini <raul.cheleguini@gmail.com>
Date:   Fri, 24 Mar 2023 00:17:51 -0300
Message-ID: <CACk7upyDgd8kCY+8j+RMJz35GXrF=bwRzDNH76Oh8q4nB8i0KQ@mail.gmail.com>
Subject: unexpected SMP command errors with controller ATS2851
To:     linux-bluetooth@vger.kernel.org
Cc:     marcel@holtmann.org, johan.hedberg@gmail.com, luiz.dentz@gmail.com
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

Hi everyone,

I'm trying to understand and narrow down a pairing problem with this
controller that I'm trying to make it work in Linux.

When pairing, the negotiation does not complete and the system logs
the following messages:

Bluetooth: hci0: unexpected SMP command 0x08 from dd:5e:b9:fe:49:3f
Bluetooth: hci0: unexpected SMP command 0x09 from dd:5e:b9:fe:49:3f
Bluetooth: hci0: Opcode 0x200d failed: -110
Bluetooth: hci0: request failed to create LE connection: err -110

(dd:5e:b9:fe:49:3f is my bluetooth mouse)

After some debug I found the condition that refuses the SMP commands and
drops them:

net/bluetooth/smp.c in smp_sig_channel()

if (smp && !test_and_clear_bit(code, &smp->allow_cmd))
    goto drop;

The interesting part is that if I disable this condition with comments,
the pairing process manages to complete and my bluetooth mouse starts to work
(even with some errors in logs):

Bluetooth: hci0: Opcode 0x200d failed: -110
Bluetooth: hci0: request failed to create LE connection: err -110
hid: raw HID events driver (C) Jiri Kosina
input: Logi M650 L Mouse as /devices/virtual/misc/uhid/0005:046D:B02A.0001/
input/input6
hid-generic 0005:046D:B02A.0001: input,hidraw0: BLUETOOTH HID v0.09 Mouse
[Logi M650 L] on f4:4e:fc:c0:de:5e
Bluetooth: hci0: Opcode 0x200d failed: -110
Bluetooth: hci0: request failed to create LE connection: err -110

Logs from bluetoothd receiving the mouse data events:

bluetoothd[576]: src/shared/att.c:can_read_data() (chan 0x55f8ad8db380)
ATT PDU received: 0x1b
bluetoothd[576]: src/shared/att.c:can_read_data() (chan 0x55f8ad8db380)
ATT PDU received: 0x1b
bluetoothd[576]: src/shared/att.c:can_read_data() (chan 0x55f8ad8db380)
ATT PDU received: 0x1b

I kindly ask guidance on what could be done in these cases or any hints
how to further debug this issue.

For context, the controller works in other systems using generic drivers.

Regards,
Raul.