All of lore.kernel.org
 help / color / mirror / Atom feed
* Latest Linux tree (merge window): BT mouse does not work
@ 2022-01-11 19:56 Oliver Hartkopp
  2022-01-12 20:55 ` Luiz Augusto von Dentz
  0 siblings, 1 reply; 3+ messages in thread
From: Oliver Hartkopp @ 2022-01-11 19:56 UTC (permalink / raw)
  To: linux-bluetooth

Hi all,

after upgrading from Linus' tree 5.16.0-rc7-00108-g800829388818 to the 
current merge window version 5.16.0-05432-g6f38be8f2ccd my BT mouse is 
not working anymore.

I now get two new error messages:

	hci0: unexpected event 0xff length: 5 > 0

and

	hci0: unexpected event 0xff length: 7 > 0

Any idea? Any new firmware required?

Best regards,
Oliver

[    8.790201] Bluetooth: Core ver 2.22
[    8.847435] Bluetooth: hci0: Bootloader revision 0.0 build 26 week 38 
2015
[    8.853022] Bluetooth: hci0: Device revision is 16
[    8.853025] Bluetooth: hci0: Secure boot is enabled
[    8.853026] Bluetooth: hci0: OTP lock is enabled
[    8.853027] Bluetooth: hci0: API lock is enabled
[    8.853028] Bluetooth: hci0: Debug lock is disabled
[    8.853028] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
[    8.855879] Bluetooth: hci0: Found device firmware: intel/ibt-12-16.sfi

[    9.422098] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    9.423532] Bluetooth: BNEP filters: protocol multicast
[    9.423537] Bluetooth: BNEP socket layer initialized
[    9.439281] iwlwifi 0000:01:00.0 wlp1s0: renamed from wlan0
[   10.391796] Bluetooth: hci0: Waiting for firmware download to complete
[   10.392752] Bluetooth: hci0: unexpected event 0xff length: 5 > 0
[   10.392789] Bluetooth: hci0: Firmware loaded in 1492456 usecs
[   10.392985] Bluetooth: hci0: Waiting for device to boot
[   10.404942] Bluetooth: hci0: unexpected event 0xff length: 7 > 0
[   10.404971] Bluetooth: hci0: Device booted in 11747 usecs
[   10.405416] Bluetooth: hci0: Found Intel DDC parameters: 
intel/ibt-12-16.ddc
[   10.407835] Bluetooth: hci0: Applying Intel DDC parameters completed
[   10.408848] Bluetooth: hci0: Firmware revision 0.1 build 50 week 12 2019
[   10.468582] NET: Registered PF_ALG protocol family
[   11.277319] Bluetooth: RFCOMM TTY layer initialized
[   11.277343] Bluetooth: RFCOMM socket layer initialized
[   11.277367] Bluetooth: RFCOMM ver 1.11



^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Latest Linux tree (merge window): BT mouse does not work
  2022-01-11 19:56 Latest Linux tree (merge window): BT mouse does not work Oliver Hartkopp
@ 2022-01-12 20:55 ` Luiz Augusto von Dentz
  2022-01-13  7:41   ` Oliver Hartkopp
  0 siblings, 1 reply; 3+ messages in thread
From: Luiz Augusto von Dentz @ 2022-01-12 20:55 UTC (permalink / raw)
  To: Oliver Hartkopp; +Cc: linux-bluetooth

Hi Oliver,

On Wed, Jan 12, 2022 at 12:07 PM Oliver Hartkopp <socketcan@hartkopp.net> wrote:
>
> Hi all,
>
> after upgrading from Linus' tree 5.16.0-rc7-00108-g800829388818 to the
> current merge window version 5.16.0-05432-g6f38be8f2ccd my BT mouse is
> not working anymore.
>
> I now get two new error messages:
>
>         hci0: unexpected event 0xff length: 5 > 0
>
> and
>
>         hci0: unexpected event 0xff length: 7 > 0

These are vendor events which I don't think were being handled anyway,
so it is likely something else that is preventing it to work.

> Any idea? Any new firmware required?
>
> Best regards,
> Oliver
>
> [    8.790201] Bluetooth: Core ver 2.22
> [    8.847435] Bluetooth: hci0: Bootloader revision 0.0 build 26 week 38
> 2015
> [    8.853022] Bluetooth: hci0: Device revision is 16
> [    8.853025] Bluetooth: hci0: Secure boot is enabled
> [    8.853026] Bluetooth: hci0: OTP lock is enabled
> [    8.853027] Bluetooth: hci0: API lock is enabled
> [    8.853028] Bluetooth: hci0: Debug lock is disabled
> [    8.853028] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
> [    8.855879] Bluetooth: hci0: Found device firmware: intel/ibt-12-16.sfi
>
> [    9.422098] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
> [    9.423532] Bluetooth: BNEP filters: protocol multicast
> [    9.423537] Bluetooth: BNEP socket layer initialized
> [    9.439281] iwlwifi 0000:01:00.0 wlp1s0: renamed from wlan0
> [   10.391796] Bluetooth: hci0: Waiting for firmware download to complete
> [   10.392752] Bluetooth: hci0: unexpected event 0xff length: 5 > 0
> [   10.392789] Bluetooth: hci0: Firmware loaded in 1492456 usecs
> [   10.392985] Bluetooth: hci0: Waiting for device to boot
> [   10.404942] Bluetooth: hci0: unexpected event 0xff length: 7 > 0
> [   10.404971] Bluetooth: hci0: Device booted in 11747 usecs
> [   10.405416] Bluetooth: hci0: Found Intel DDC parameters:
> intel/ibt-12-16.ddc
> [   10.407835] Bluetooth: hci0: Applying Intel DDC parameters completed
> [   10.408848] Bluetooth: hci0: Firmware revision 0.1 build 50 week 12 2019
> [   10.468582] NET: Registered PF_ALG protocol family
> [   11.277319] Bluetooth: RFCOMM TTY layer initialized
> [   11.277343] Bluetooth: RFCOMM socket layer initialized
> [   11.277367] Bluetooth: RFCOMM ver 1.11

Can you attach the bluetoothd and btmon logs when you attempt to
connect the mouse, at least for the logs above it does seem the
firmware is being loaded properly.

>


-- 
Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Latest Linux tree (merge window): BT mouse does not work
  2022-01-12 20:55 ` Luiz Augusto von Dentz
@ 2022-01-13  7:41   ` Oliver Hartkopp
  0 siblings, 0 replies; 3+ messages in thread
From: Oliver Hartkopp @ 2022-01-13  7:41 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: linux-bluetooth

Hi Luiz,

On 12.01.22 21:55, Luiz Augusto von Dentz wrote:
> Hi Oliver,
> 
> On Wed, Jan 12, 2022 at 12:07 PM Oliver Hartkopp <socketcan@hartkopp.net> wrote:
>>
>> Hi all,
>>
>> after upgrading from Linus' tree 5.16.0-rc7-00108-g800829388818 to the
>> current merge window version 5.16.0-05432-g6f38be8f2ccd my BT mouse is
>> not working anymore.
>>
>> I now get two new error messages:
>>
>>          hci0: unexpected event 0xff length: 5 > 0
>>
>> and
>>
>>          hci0: unexpected event 0xff length: 7 > 0
> 
> These are vendor events which I don't think were being handled anyway,
> so it is likely something else that is preventing it to work.
> 

In the working 5.16.0-rc7 daemon log there are tons of warning messages 
instead that do not show up in 5.16.0-05432-g6f38be8f2ccd ...

>> Any idea? Any new firmware required?
>>
>> Best regards,
>> Oliver
>>
>> [    8.790201] Bluetooth: Core ver 2.22
>> [    8.847435] Bluetooth: hci0: Bootloader revision 0.0 build 26 week 38
>> 2015
>> [    8.853022] Bluetooth: hci0: Device revision is 16
>> [    8.853025] Bluetooth: hci0: Secure boot is enabled
>> [    8.853026] Bluetooth: hci0: OTP lock is enabled
>> [    8.853027] Bluetooth: hci0: API lock is enabled
>> [    8.853028] Bluetooth: hci0: Debug lock is disabled
>> [    8.853028] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
>> [    8.855879] Bluetooth: hci0: Found device firmware: intel/ibt-12-16.sfi
>>
>> [    9.422098] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
>> [    9.423532] Bluetooth: BNEP filters: protocol multicast
>> [    9.423537] Bluetooth: BNEP socket layer initialized
>> [    9.439281] iwlwifi 0000:01:00.0 wlp1s0: renamed from wlan0
>> [   10.391796] Bluetooth: hci0: Waiting for firmware download to complete
>> [   10.392752] Bluetooth: hci0: unexpected event 0xff length: 5 > 0
>> [   10.392789] Bluetooth: hci0: Firmware loaded in 1492456 usecs
>> [   10.392985] Bluetooth: hci0: Waiting for device to boot
>> [   10.404942] Bluetooth: hci0: unexpected event 0xff length: 7 > 0
>> [   10.404971] Bluetooth: hci0: Device booted in 11747 usecs
>> [   10.405416] Bluetooth: hci0: Found Intel DDC parameters:
>> intel/ibt-12-16.ddc
>> [   10.407835] Bluetooth: hci0: Applying Intel DDC parameters completed
>> [   10.408848] Bluetooth: hci0: Firmware revision 0.1 build 50 week 12 2019
>> [   10.468582] NET: Registered PF_ALG protocol family
>> [   11.277319] Bluetooth: RFCOMM TTY layer initialized
>> [   11.277343] Bluetooth: RFCOMM socket layer initialized
>> [   11.277367] Bluetooth: RFCOMM ver 1.11
> 
> Can you attach the bluetoothd and btmon logs when you attempt to
> connect the mouse, at least for the logs above it does seem the
> firmware is being loaded properly.
> 

The BT mouse just is not connecting at all and the btmon says nothing 
(with the latest tree) - whatever I do with the mouse.


So this is the deamon.log output of the BROKEN 
5.16.0-05432-g6f38be8f2ccd (grepped for "blue"):

Jan 13 08:12:02 silver bluetoothd[540]: Bluetooth daemon 5.55
Jan 13 08:12:02 silver bluetoothd[540]: Starting SDP server
Jan 13 08:12:02 silver blueman-mechanism[465]: Unable to init server: 
Could not connect: Connection refused
Jan 13 08:12:02 silver bluetoothd[540]: Bluetooth management interface 
1.21 initialized
Jan 13 08:12:02 silver blueman-mechanism[465]: Unable to init server: 
Could not connect: Connection refused
Jan 13 08:12:02 silver NetworkManager[478]: <info>  [1642057922.9396] 
Loaded device plugin: NMBluezManager 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.30.0/libnm-device-plugin-bluetooth.so)
Jan 13 08:12:04 silver bluetoothd[540]: 
profiles/sap/server.c:sap_server_register() Sap driver initialization 
failed.
Jan 13 08:12:04 silver bluetoothd[540]: sap-server: Operation not 
permitted (1)
Jan 13 08:12:05 silver bluetoothd[540]: Endpoint registered: 
sender=:1.26 path=/MediaEndpoint/A2DPSink/sbc
Jan 13 08:12:05 silver bluetoothd[540]: Endpoint registered: 
sender=:1.26 path=/MediaEndpoint/A2DPSource/sbc
Jan 13 08:12:13 silver bluetoothd[540]: Endpoint unregistered: 
sender=:1.26 path=/MediaEndpoint/A2DPSink/sbc
Jan 13 08:12:13 silver bluetoothd[540]: Endpoint unregistered: 
sender=:1.26 path=/MediaEndpoint/A2DPSource/sbc
Jan 13 08:12:13 silver bluetoothd[540]: Endpoint registered: 
sender=:1.40 path=/MediaEndpoint/A2DPSink/sbc
Jan 13 08:12:13 silver bluetoothd[540]: Endpoint registered: 
sender=:1.40 path=/MediaEndpoint/A2DPSource/sbc
Jan 13 08:12:15 silver dbus-daemon[1235]: [session uid=1000 pid=1235] 
Activating via systemd: service name='org.bluez.obex' 
unit='obex.service' requested by ':1.47' (uid=1000 pid=1416 
comm="/usr/bin/python3 /usr/bin/blueman-applet ")
Jan 13 08:12:15 silver dbus-daemon[1235]: [session uid=1000 pid=1235] 
Successfully activated service 'org.bluez.obex'
Jan 13 08:12:45 silver systemd[1]: blueman-mechanism.service: Succeeded.


And this is the deamon.log output of the WORKING 
5.16.0-rc7-00108-g800829388818 (grepped for "blue"):

Jan 12 19:11:38 silver bluetoothd[578]: Bluetooth daemon 5.55
Jan 12 19:11:38 silver bluetoothd[578]: Starting SDP server
Jan 12 19:11:38 silver bluetoothd[578]: Bluetooth management interface 
1.21 initialized
Jan 12 19:11:38 silver dbus-daemon[484]: [system] Activating via 
systemd: service name='org.freedesktop.hostname1' 
unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 
pid=578 comm="/usr/libexec/bluetooth/bluetoothd ")
Jan 12 19:11:39 silver blueman-mechanism[479]: Unable to init server: 
Could not connect: Connection refused
Jan 12 19:11:39 silver blueman-mechanism[479]: Unable to init server: 
Could not connect: Connection refused
Jan 12 19:11:39 silver NetworkManager[490]: <info>  [1642011099.0811] 
Loaded device plugin: NMBluezManager 
(/usr/lib/x86_64-linux-gnu/NetworkManager/1.30.0/libnm-device-plugin-bluetooth.so)
Jan 12 19:11:40 silver bluetoothd[578]: 
profiles/sap/server.c:sap_server_register() Sap driver initialization 
failed.
Jan 12 19:11:40 silver bluetoothd[578]: sap-server: Operation not 
permitted (1)
Jan 12 19:11:40 silver bluetoothd[578]: Endpoint registered: 
sender=:1.26 path=/MediaEndpoint/A2DPSink/sbc
Jan 12 19:11:40 silver bluetoothd[578]: Endpoint registered: 
sender=:1.26 path=/MediaEndpoint/A2DPSource/sbc
Jan 12 19:12:08 silver systemd[1]: blueman-mechanism.service: Succeeded.
Jan 12 19:12:23 silver bluetoothd[578]: Endpoint unregistered: 
sender=:1.26 path=/MediaEndpoint/A2DPSink/sbc
Jan 12 19:12:23 silver bluetoothd[578]: Endpoint unregistered: 
sender=:1.26 path=/MediaEndpoint/A2DPSource/sbc
Jan 12 19:12:23 silver bluetoothd[578]: Endpoint registered: 
sender=:1.40 path=/MediaEndpoint/A2DPSink/sbc
Jan 12 19:12:23 silver bluetoothd[578]: Endpoint registered: 
sender=:1.40 path=/MediaEndpoint/A2DPSource/sbc
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:24 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:25 silver dbus-daemon[484]: [system] Activating via 
systemd: service name='org.blueman.Mechanism' 
unit='blueman-mechanism.service' requested by ':1.51' (uid=1000 pid=1407 
comm="/usr/bin/python3 /usr/bin/blueman-applet ")
Jan 12 19:12:25 silver blueman-mechanism[1542]: Unable to init server: 
Could not connect: Connection refused
Jan 12 19:12:25 silver dbus-daemon[1232]: [session uid=1000 pid=1232] 
Activating via systemd: service name='org.blueman.Applet' 
unit='blueman-applet.service' requested by ':1.52' (uid=1000 pid=1538 
comm="/usr/bin/python3 /usr/bin/blueman-tray ")
Jan 12 19:12:25 silver blueman-mechanism[1542]: Unable to init server: 
Could not connect: Connection refused
Jan 12 19:12:25 silver dbus-daemon[484]: [system] Successfully activated 
service 'org.blueman.Mechanism'
Jan 12 19:12:25 silver dbus-daemon[1232]: [session uid=1000 pid=1232] 
Successfully activated service 'org.blueman.Applet'
Jan 12 19:12:25 silver dbus-daemon[1232]: [session uid=1000 pid=1232] 
Activating via systemd: service name='org.bluez.obex' 
unit='obex.service' requested by ':1.43' (uid=1000 pid=1407 
comm="/usr/bin/python3 /usr/bin/blueman-applet ")
Jan 12 19:12:25 silver dbus-daemon[1232]: [session uid=1000 pid=1232] 
Successfully activated service 'org.bluez.obex'
Jan 12 19:12:25 silver blueman-applet[1546]: blueman-applet version 
2.1.4 starting
Jan 12 19:12:25 silver blueman-applet[1546]: There is an instance 
already running
Jan 12 19:12:25 silver systemd[1208]: blueman-applet.service: Succeeded.
Jan 12 19:12:56 silver systemd[1]: blueman-mechanism.service: Succeeded.
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 19:12:56 silver bluetoothd[578]: 
profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid 
argument (22)
Jan 12 22:11:55 silver bluetoothd[578]: Terminating


Best regards,
Oliver

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2022-01-13  7:41 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-01-11 19:56 Latest Linux tree (merge window): BT mouse does not work Oliver Hartkopp
2022-01-12 20:55 ` Luiz Augusto von Dentz
2022-01-13  7:41   ` Oliver Hartkopp

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.