2017-09-18 17:14:39

by Marcel Holtmann

[permalink] [raw]
Subject: Fedora 27 kernel and RPi3 Bluetooth oops

Hi,

the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.

[ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
[ 229.171285] Hardware name: Generic DT based system
[ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
[ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
[ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
[ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
[ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
[ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
[ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
[ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
[ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
[ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
[ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
[ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
[ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
[ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
[ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
[ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)

It results in the first HCI command going through and then every other failing.

= Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
< HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
Encoded baud rate: Not used (0x0000)
Explicit baud rate: 2000000 Mbps
> HCI Event: Command Complete (0x0e) plen 4
Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
Status: Success (0x00)
< HCI Command: Reset (0x03|0x0003) plen 0

The HCI Reset command actually times out.

[ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout

What we really need is some kernel specific debug tracing when driver change baud rate etc. to show up in btmon. Drivers need the capability to insert HCI transport level specifics into monitoring interface.

Regards

Marcel



2017-09-22 11:32:52

by Peter Robinson

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

On Fri, Sep 22, 2017 at 10:09 AM, Loic Poulain <[email protected]> wrote:
> Hi Marcel, Peter,
>
>> > Hans added a script to automatically btattch some bcm controllers for
>> > atom devices, maybe we need to add more IDs for udev, not sure if
>> > there's a means of making that generic and upstreamable. Also some of
>> > the other distro patches I've seen had a different BT firmware, not
>> > sure if Loic needed that or not.
>>
>> The whole point behind serdev is that you no longer need btattach. The
>> UART can be enumerated by the kernel. So that should not be needed and we
>> also want to get rid of it for ACPI based systems as well.
>>
>
> Since it works with raspbian I had a try with Fedora 26.
>
> To make this 'simpler', I bypassed u-boot and just loaded my kernel + my
> dtb:
>
> - added bcm2837-rpi-3-b.dtb and kernel zImage (Linux 4.13 32-bit) (FAT PART)

Where did the kernel come from? Is that the Fedora kernel?

> - modified config.txt (FAT part):
> # Raspberry Pi 3
> [pi3]
> kernel=zImage
> device_tree=bcm2837-rpi-3-b.dtb
>
> - added cmdline.txt (FAT part):
> dwc_otg.lpm_enable=0 root=/dev/mmcblk0p4 rootfstype=ext4 elevator=deadline
> fsck.repair=yes rootwait splash plymouth.ignore-serial-consoles
>
> - added modules (rootfs ext4 part)
>
> That works as expected, my hci device is correctly configured and
> operational.
> Maybe u-boot adds some unexpected overlay or applies incorrect config.

It certainly doesn't add overlays by default, it uses the vanilla
linux kernel DT

2017-09-22 09:09:28

by Loic Poulain

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Marcel, Peter,

> Hans added a script to automatically btattch some bcm controllers for
> > atom devices, maybe we need to add more IDs for udev, not sure if
> > there's a means of making that generic and upstreamable. Also some of
> > the other distro patches I've seen had a different BT firmware, not
> > sure if Loic needed that or not.
>
> The whole point behind serdev is that you no longer need btattach. The
> UART can be enumerated by the kernel. So that should not be needed and we
> also want to get rid of it for ACPI based systems as well.
>
>
Since it works with raspbian I had a try with Fedora 26.

To make this 'simpler', I bypassed u-boot and just loaded my kernel + my
dtb:

- added bcm2837-rpi-3-b.dtb and kernel zImage (Linux 4.13 32-bit) (FAT PART)

- modified config.txt (FAT part):
# Raspberry Pi 3
[pi3]
kernel=zImage
device_tree=bcm2837-rpi-3-b.dtb

- added cmdline.txt (FAT part):
dwc_otg.lpm_enable=0 root=/dev/mmcblk0p4 rootfstype=ext4 elevator=deadline
fsck.repair=yes rootwait splash plymouth.ignore-serial-consoles

- added modules (rootfs ext4 part)

That works as expected, my hci device is correctly configured and
operational.
Maybe u-boot adds some unexpected overlay or applies incorrect config.

Regards
Loic

2017-09-20 12:04:53

by Marcel Holtmann

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Peter,

>>>>>>>> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.
>>>>>>>>
>>>>>>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
>>>>>>>> [ 229.171285] Hardware name: Generic DT based system
>>>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
>>>>>>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
>>>>>>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
>>>>>>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
>>>>>>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
>>>>>>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
>>>>>>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>>>>>>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>>>>>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>>>>>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>>>>>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
>>>>>>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
>>>>>>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
>>>>>>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)
>>>>>>>>
>>>>>>>> It results in the first HCI command going through and then every other failing.
>>>>>>>>
>>>>>>>> = Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>>>>>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>>>>>>> Encoded baud rate: Not used (0x0000)
>>>>>>>> Explicit baud rate: 2000000 Mbps
>>>>>>>>> HCI Event: Command Complete (0x0e) plen 4
>>>>>>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>>>>>>> Status: Success (0x00)
>>>>>>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>>>>>>
>>>>>>>> The HCI Reset command actually times out.
>>>>>>>>
>>>>>>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>>>>>>
>>>>>>>> What we really need is some kernel specific debug tracing when driver change baud rate etc. to show up in btmon. Drivers need the capability to insert HCI transport level specifics into monitoring interface.
>>>>>>>
>>>>>>> Thanks for noticing this, I've have that exact backlog sitting there
>>>>>>> to send out but I'd just not got to it yet, let me know if there's
>>>>>>> anything that needs tweaking on the Fedora side or patch.
>>>>>>
>>>>>> does it actually work for you? I didn’t get it running with the F27 kernel. I had issues with the initial baud rate using btattach in some cases. Does this go away if you use 115200 as max baud rate?
>>>>>
>>>>> No, not yet, I got to the point it would see an interface but that
>>>>> didn't have a MAC address, the patch series has also done something
>>>>> weird with serial consoles that I need to debug. I was wondering if it
>>>>> still needs the newer firmware rev that various distros have pulled
>>>>> in.
>>>>
>>>> is that the AA:AA:AA.. address? If so, we really need to blacklist that one and mark it with quirk for invalid BD_ADDR. However I am not even getting that far since the command above is the first command send to the hardware.
>>>
>>> No, it's all zeros, I'll try and spend some time on it this afternoon
>>> to reproduce what I was getting.
>>
>> please check if using 115200 baud rate does anything to make this work. At least that is what I had when testing this with btattach. It needed to be 115200 and otherwise it would fail.
>>
>> We can load the firmware at 115200 and only switch later to a higher rate. Maybe there are subtle difference in the default firmwares of the Bluetooth controller in the RPi3.
>>
>> Loic said that he had it working with a bluetooth-next and his patches. That is something I have not succeeded with yet.
>
> So testing on a 32 bit image bluetoothctl doesn't see a controller,
> but hciconfig shows a controller with a zero mac, on a 64 bit image I
> see nothing using either method.
>
> # hciconfig
> hci0: Type: Primary Bus: UART
> BD Address: 00:00:00:00:00:00 ACL MTU: 0:0 SCO MTU: 0:0
> DOWN
> RX bytes:14 acl:0 sco:0 events:1 errors:0
> TX bytes:14 acl:0 sco:0 commands:2 errors:0

if you run btmon before modprobe hci_uart (if you blacklisted its automatic loading), then you will see the same result as mine. You send 2 commands and received 1 event and then the UART is dead. Have you tried to specify 115200 as max-speed in the DTS?

> Hans added a script to automatically btattch some bcm controllers for
> atom devices, maybe we need to add more IDs for udev, not sure if
> there's a means of making that generic and upstreamable. Also some of
> the other distro patches I've seen had a different BT firmware, not
> sure if Loic needed that or not.

The whole point behind serdev is that you no longer need btattach. The UART can be enumerated by the kernel. So that should not be needed and we also want to get rid of it for ACPI based systems as well.

Regards

Marcel


2017-09-20 09:33:24

by Peter Robinson

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

On Tue, Sep 19, 2017 at 11:07 AM, Marcel Holtmann <[email protected]> wro=
te:
> Hi Peter,
>
>>>>>>> the latest Fedora 27 kernel which has all the RPi3 patches applied =
doesn=E2=80=99t actually work. It provides this backlog.
>>>>>>>
>>>>>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.=
2-300.fc27.armv7hl #1
>>>>>>> [ 229.171285] Hardware name: Generic DT based system
>>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (s=
how_stack+0x18/0x1c)
>>>>>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_st=
ack+0xa0/0xd8)
>>>>>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (registe=
r_lock_class+0x298/0x514)
>>>>>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>]=
(__lock_acquire+0xe4/0x1608)
>>>>>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (loc=
k_acquire+0x280/0x2dc)
>>>>>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_=
read_lock+0x4c/0x5c)
>>>>>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci=
_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>>>>>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<=
bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>>>>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [=
<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>>>>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3=
cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>>>>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f=
154>] (process_one_work+0x43c/0x83c)
>>>>>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (w=
orker_thread+0x290/0x40c)
>>>>>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthr=
ead+0x14c/0x168)
>>>>>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_f=
ork+0x14/0x24)
>>>>>>>
>>>>>>> It results in the first HCI command going through and then every ot=
her failing.
>>>>>>>
>>>>>>> =3D Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>>>>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>>>>>> Encoded baud rate: Not used (0x0000)
>>>>>>> Explicit baud rate: 2000000 Mbps
>>>>>>>> HCI Event: Command Complete (0x0e) plen 4
>>>>>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>>>>>> Status: Success (0x00)
>>>>>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>>>>>
>>>>>>> The HCI Reset command actually times out.
>>>>>>>
>>>>>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>>>>>
>>>>>>> What we really need is some kernel specific debug tracing when driv=
er change baud rate etc. to show up in btmon. Drivers need the capability t=
o insert HCI transport level specifics into monitoring interface.
>>>>>>
>>>>>> Thanks for noticing this, I've have that exact backlog sitting there
>>>>>> to send out but I'd just not got to it yet, let me know if there's
>>>>>> anything that needs tweaking on the Fedora side or patch.
>>>>>
>>>>> does it actually work for you? I didn=E2=80=99t get it running with t=
he F27 kernel. I had issues with the initial baud rate using btattach in so=
me cases. Does this go away if you use 115200 as max baud rate?
>>>>
>>>> No, not yet, I got to the point it would see an interface but that
>>>> didn't have a MAC address, the patch series has also done something
>>>> weird with serial consoles that I need to debug. I was wondering if it
>>>> still needs the newer firmware rev that various distros have pulled
>>>> in.
>>>
>>> is that the AA:AA:AA.. address? If so, we really need to blacklist that=
one and mark it with quirk for invalid BD_ADDR. However I am not even gett=
ing that far since the command above is the first command send to the hardw=
are.
>>
>> No, it's all zeros, I'll try and spend some time on it this afternoon
>> to reproduce what I was getting.
>
> please check if using 115200 baud rate does anything to make this work. A=
t least that is what I had when testing this with btattach. It needed to be=
115200 and otherwise it would fail.
>
> We can load the firmware at 115200 and only switch later to a higher rate=
. Maybe there are subtle difference in the default firmwares of the Bluetoo=
th controller in the RPi3.
>
> Loic said that he had it working with a bluetooth-next and his patches. T=
hat is something I have not succeeded with yet.

So testing on a 32 bit image bluetoothctl doesn't see a controller,
but hciconfig shows a controller with a zero mac, on a 64 bit image I
see nothing using either method.

# hciconfig
hci0: Type: Primary Bus: UART
BD Address: 00:00:00:00:00:00 ACL MTU: 0:0 SCO MTU: 0:0
DOWN
RX bytes:14 acl:0 sco:0 events:1 errors:0
TX bytes:14 acl:0 sco:0 commands:2 errors:0

Hans added a script to automatically btattch some bcm controllers for
atom devices, maybe we need to add more IDs for udev, not sure if
there's a means of making that generic and upstreamable. Also some of
the other distro patches I've seen had a different BT firmware, not
sure if Loic needed that or not.

https://src.fedoraproject.org/rpms/bluez/c/9089a629a195699747b1da0fa712e7ae=
e76d7a90?branch=3Dmaster

2017-09-19 10:07:57

by Marcel Holtmann

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Peter,

>>>>>> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.
>>>>>>
>>>>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
>>>>>> [ 229.171285] Hardware name: Generic DT based system
>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
>>>>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
>>>>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
>>>>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
>>>>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
>>>>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
>>>>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>>>>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>>>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>>>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>>>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
>>>>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
>>>>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
>>>>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)
>>>>>>
>>>>>> It results in the first HCI command going through and then every other failing.
>>>>>>
>>>>>> = Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>>>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>>>>> Encoded baud rate: Not used (0x0000)
>>>>>> Explicit baud rate: 2000000 Mbps
>>>>>>> HCI Event: Command Complete (0x0e) plen 4
>>>>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>>>>> Status: Success (0x00)
>>>>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>>>>
>>>>>> The HCI Reset command actually times out.
>>>>>>
>>>>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>>>>
>>>>>> What we really need is some kernel specific debug tracing when driver change baud rate etc. to show up in btmon. Drivers need the capability to insert HCI transport level specifics into monitoring interface.
>>>>>
>>>>> Thanks for noticing this, I've have that exact backlog sitting there
>>>>> to send out but I'd just not got to it yet, let me know if there's
>>>>> anything that needs tweaking on the Fedora side or patch.
>>>>
>>>> does it actually work for you? I didn’t get it running with the F27 kernel. I had issues with the initial baud rate using btattach in some cases. Does this go away if you use 115200 as max baud rate?
>>>
>>> No, not yet, I got to the point it would see an interface but that
>>> didn't have a MAC address, the patch series has also done something
>>> weird with serial consoles that I need to debug. I was wondering if it
>>> still needs the newer firmware rev that various distros have pulled
>>> in.
>>
>> is that the AA:AA:AA.. address? If so, we really need to blacklist that one and mark it with quirk for invalid BD_ADDR. However I am not even getting that far since the command above is the first command send to the hardware.
>
> No, it's all zeros, I'll try and spend some time on it this afternoon
> to reproduce what I was getting.

please check if using 115200 baud rate does anything to make this work. At least that is what I had when testing this with btattach. It needed to be 115200 and otherwise it would fail.

We can load the firmware at 115200 and only switch later to a higher rate. Maybe there are subtle difference in the default firmwares of the Bluetooth controller in the RPi3.

Loic said that he had it working with a bluetooth-next and his patches. That is something I have not succeeded with yet.

Regards

Marcel


2017-09-19 09:49:11

by Peter Robinson

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

On Tue, Sep 19, 2017 at 10:44 AM, Marcel Holtmann <[email protected]> wro=
te:
> Hi Peter,
>
>>>>> the latest Fedora 27 kernel which has all the RPi3 patches applied do=
esn=E2=80=99t actually work. It provides this backlog.
>>>>>
>>>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-=
300.fc27.armv7hl #1
>>>>> [ 229.171285] Hardware name: Generic DT based system
>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (sho=
w_stack+0x18/0x1c)
>>>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stac=
k+0xa0/0xd8)
>>>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_=
lock_class+0x298/0x514)
>>>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (=
__lock_acquire+0xe4/0x1608)
>>>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_=
acquire+0x280/0x2dc)
>>>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_re=
ad_lock+0x4c/0x5c)
>>>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_u=
art_tx_wakeup+0x1c/0x98 [hci_uart])
>>>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf=
47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<b=
f3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb=
334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f15=
4>] (process_one_work+0x43c/0x83c)
>>>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (wor=
ker_thread+0x290/0x40c)
>>>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthrea=
d+0x14c/0x168)
>>>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_for=
k+0x14/0x24)
>>>>>
>>>>> It results in the first HCI command going through and then every othe=
r failing.
>>>>>
>>>>> =3D Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>>>> Encoded baud rate: Not used (0x0000)
>>>>> Explicit baud rate: 2000000 Mbps
>>>>>> HCI Event: Command Complete (0x0e) plen 4
>>>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>>>> Status: Success (0x00)
>>>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>>>
>>>>> The HCI Reset command actually times out.
>>>>>
>>>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>>>
>>>>> What we really need is some kernel specific debug tracing when driver=
change baud rate etc. to show up in btmon. Drivers need the capability to =
insert HCI transport level specifics into monitoring interface.
>>>>
>>>> Thanks for noticing this, I've have that exact backlog sitting there
>>>> to send out but I'd just not got to it yet, let me know if there's
>>>> anything that needs tweaking on the Fedora side or patch.
>>>
>>> does it actually work for you? I didn=E2=80=99t get it running with the=
F27 kernel. I had issues with the initial baud rate using btattach in some=
cases. Does this go away if you use 115200 as max baud rate?
>>
>> No, not yet, I got to the point it would see an interface but that
>> didn't have a MAC address, the patch series has also done something
>> weird with serial consoles that I need to debug. I was wondering if it
>> still needs the newer firmware rev that various distros have pulled
>> in.
>
> is that the AA:AA:AA.. address? If so, we really need to blacklist that o=
ne and mark it with quirk for invalid BD_ADDR. However I am not even gettin=
g that far since the command above is the first command send to the hardwar=
e.

No, it's all zeros, I'll try and spend some time on it this afternoon
to reproduce what I was getting.

Peter

2017-09-19 09:44:44

by Marcel Holtmann

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Peter,

>>>> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.
>>>>
>>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
>>>> [ 229.171285] Hardware name: Generic DT based system
>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
>>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
>>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
>>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
>>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
>>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
>>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
>>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
>>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
>>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)
>>>>
>>>> It results in the first HCI command going through and then every other failing.
>>>>
>>>> = Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>>> Encoded baud rate: Not used (0x0000)
>>>> Explicit baud rate: 2000000 Mbps
>>>>> HCI Event: Command Complete (0x0e) plen 4
>>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>>> Status: Success (0x00)
>>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>>
>>>> The HCI Reset command actually times out.
>>>>
>>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>>
>>>> What we really need is some kernel specific debug tracing when driver change baud rate etc. to show up in btmon. Drivers need the capability to insert HCI transport level specifics into monitoring interface.
>>>
>>> Thanks for noticing this, I've have that exact backlog sitting there
>>> to send out but I'd just not got to it yet, let me know if there's
>>> anything that needs tweaking on the Fedora side or patch.
>>
>> does it actually work for you? I didn’t get it running with the F27 kernel. I had issues with the initial baud rate using btattach in some cases. Does this go away if you use 115200 as max baud rate?
>
> No, not yet, I got to the point it would see an interface but that
> didn't have a MAC address, the patch series has also done something
> weird with serial consoles that I need to debug. I was wondering if it
> still needs the newer firmware rev that various distros have pulled
> in.

is that the AA:AA:AA.. address? If so, we really need to blacklist that one and mark it with quirk for invalid BD_ADDR. However I am not even getting that far since the command above is the first command send to the hardware.

Regards

Marcel


2017-09-19 08:57:31

by Peter Robinson

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Marcel,

>>> the latest Fedora 27 kernel which has all the RPi3 patches applied does=
n=E2=80=99t actually work. It provides this backlog.
>>>
>>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-30=
0.fc27.armv7hl #1
>>> [ 229.171285] Hardware name: Generic DT based system
>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_=
stack+0x18/0x1c)
>>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+=
0xa0/0xd8)
>>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lo=
ck_class+0x298/0x514)
>>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__=
lock_acquire+0xe4/0x1608)
>>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_ac=
quire+0x280/0x2dc)
>>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read=
_lock+0x4c/0x5c)
>>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uar=
t_tx_wakeup+0x1c/0x98 [hci_uart])
>>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47=
a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3=
cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb33=
4>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>=
] (process_one_work+0x43c/0x83c)
>>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worke=
r_thread+0x290/0x40c)
>>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+=
0x14c/0x168)
>>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+=
0x14/0x24)
>>>
>>> It results in the first HCI command going through and then every other =
failing.
>>>
>>> =3D Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>>> Encoded baud rate: Not used (0x0000)
>>> Explicit baud rate: 2000000 Mbps
>>>> HCI Event: Command Complete (0x0e) plen 4
>>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>>> Status: Success (0x00)
>>> < HCI Command: Reset (0x03|0x0003) plen 0
>>>
>>> The HCI Reset command actually times out.
>>>
>>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>>
>>> What we really need is some kernel specific debug tracing when driver c=
hange baud rate etc. to show up in btmon. Drivers need the capability to in=
sert HCI transport level specifics into monitoring interface.
>>
>> Thanks for noticing this, I've have that exact backlog sitting there
>> to send out but I'd just not got to it yet, let me know if there's
>> anything that needs tweaking on the Fedora side or patch.
>
> does it actually work for you? I didn=E2=80=99t get it running with the F=
27 kernel. I had issues with the initial baud rate using btattach in some c=
ases. Does this go away if you use 115200 as max baud rate?

No, not yet, I got to the point it would see an interface but that
didn't have a MAC address, the patch series has also done something
weird with serial consoles that I need to debug. I was wondering if it
still needs the newer firmware rev that various distros have pulled
in.

Peter

2017-09-19 05:27:52

by Marcel Holtmann

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Peter,

>> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.
>>
>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
>> [ 229.171285] Hardware name: Generic DT based system
>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)
>>
>> It results in the first HCI command going through and then every other failing.
>>
>> = Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>> Encoded baud rate: Not used (0x0000)
>> Explicit baud rate: 2000000 Mbps
>>> HCI Event: Command Complete (0x0e) plen 4
>> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: Reset (0x03|0x0003) plen 0
>>
>> The HCI Reset command actually times out.
>>
>> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>>
>> What we really need is some kernel specific debug tracing when driver change baud rate etc. to show up in btmon. Drivers need the capability to insert HCI transport level specifics into monitoring interface.
>
> Thanks for noticing this, I've have that exact backlog sitting there
> to send out but I'd just not got to it yet, let me know if there's
> anything that needs tweaking on the Fedora side or patch.

does it actually work for you? I didn’t get it running with the F27 kernel. I had issues with the initial baud rate using btattach in some cases. Does this go away if you use 115200 as max baud rate?

Regards

Marcel


2017-09-18 23:23:27

by Peter Robinson

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

On Mon, Sep 18, 2017 at 6:14 PM, Marcel Holtmann <[email protected]> wrot=
e:
> Hi,
>
> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn=
=E2=80=99t actually work. It provides this backlog.
>
> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.=
fc27.armv7hl #1
> [ 229.171285] Hardware name: Generic DT based system
> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_st=
ack+0x18/0x1c)
> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0x=
a0/0xd8)
> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock=
_class+0x298/0x514)
> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lo=
ck_acquire+0xe4/0x1608)
> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acqu=
ire+0x280/0x2dc)
> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_l=
ock+0x4c/0x5c)
> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_=
tx_wakeup+0x1c/0x98 [hci_uart])
> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0=
e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb=
260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>=
] (hci_cmd_work+0xa8/0x124 [bluetooth])
> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] =
(process_one_work+0x43c/0x83c)
> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_=
thread+0x290/0x40c)
> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x=
14c/0x168)
> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x=
14/0x24)
>
> It results in the first HCI command going through and then every other fa=
iling.
>
> =3D Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
> Encoded baud rate: Not used (0x0000)
> Explicit baud rate: 2000000 Mbps
>> HCI Event: Command Complete (0x0e) plen 4
> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
> Status: Success (0x00)
> < HCI Command: Reset (0x03|0x0003) plen 0
>
> The HCI Reset command actually times out.
>
> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>
> What we really need is some kernel specific debug tracing when driver cha=
nge baud rate etc. to show up in btmon. Drivers need the capability to inse=
rt HCI transport level specifics into monitoring interface.

Thanks for noticing this, I've have that exact backlog sitting there
to send out but I'd just not got to it yet, let me know if there's
anything that needs tweaking on the Fedora side or patch.

Peter

2017-09-18 19:07:56

by Marcel Holtmann

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Luiz,

>> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn’t actually work. It provides this backlog.
>>
>> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.fc27.armv7hl #1
>> [ 229.171285] Hardware name: Generic DT based system
>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
>> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_stack+0x18/0x1c)
>> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0xa0/0xd8)
>> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock_class+0x298/0x514)
>> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lock_acquire+0xe4/0x1608)
>> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acquire+0x280/0x2dc)
>> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_lock+0x4c/0x5c)
>> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_tx_wakeup+0x1c/0x98 [hci_uart])
>> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
>> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
>> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>] (hci_cmd_work+0xa8/0x124 [bluetooth])
>> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] (process_one_work+0x43c/0x83c)
>> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_thread+0x290/0x40c)
>> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x14c/0x168)
>> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x14/0x24)
>>
>> It results in the first HCI command going through and then every other failing.
>>
>> = Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
>> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
>> Encoded baud rate: Not used (0x0000)
>> Explicit baud rate: 2000000 Mbps
>
> Either we are printing the baud rate incorrectly of there gotta be
> something wrong with it since 2 Tbps sounds pretty much impossible...
> I guess this must be 2 Mbps/2000000 bps.

I bet that is a btmon decoding issue which I might have just typed down wrongly when adding support for it.

Regards

Marcel


2017-09-18 18:51:28

by Luiz Augusto von Dentz

[permalink] [raw]
Subject: Re: Fedora 27 kernel and RPi3 Bluetooth oops

Hi Marcel,

On Mon, Sep 18, 2017 at 8:14 PM, Marcel Holtmann <[email protected]> wrot=
e:
> Hi,
>
> the latest Fedora 27 kernel which has all the RPi3 patches applied doesn=
=E2=80=99t actually work. It provides this backlog.
>
> [ 229.162921] CPU: 1 PID: 582 Comm: kworker/u9:1 Not tainted 4.13.2-300.=
fc27.armv7hl #1
> [ 229.171285] Hardware name: Generic DT based system
> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
> [ 229.176774] Workqueue: hci0 hci_cmd_work [bluetooth]
> [ 229.182117] [<c0312af4>] (unwind_backtrace) from [<c030d264>] (show_st=
ack+0x18/0x1c)
> [ 229.190374] [<c030d264>] (show_stack) from [<c0b66174>] (dump_stack+0x=
a0/0xd8)
> [ 229.198122] [<c0b66174>] (dump_stack) from [<c03aeaec>] (register_lock=
_class+0x298/0x514)
> [ 229.206835] [<c03aeaec>] (register_lock_class) from [<c03b1f9c>] (__lo=
ck_acquire+0xe4/0x1608)
> [ 229.215952] [<c03b1f9c>] (__lock_acquire) from [<c03b3fd0>] (lock_acqu=
ire+0x280/0x2dc)
> [ 229.224386] [<c03b3fd0>] (lock_acquire) from [<c0b80ba4>] (_raw_read_l=
ock+0x4c/0x5c)
> [ 229.232740] [<c0b80ba4>] (_raw_read_lock) from [<bf47903c>] (hci_uart_=
tx_wakeup+0x1c/0x98 [hci_uart])
> [ 229.242725] [<bf47903c>] (hci_uart_tx_wakeup [hci_uart]) from [<bf47a0=
e0>] (hci_uart_send_frame+0x54/0x6c [hci_uart])
> [ 229.254485] [<bf47a0e0>] (hci_uart_send_frame [hci_uart]) from [<bf3cb=
260>] (hci_send_frame+0xc8/0xf4 [bluetooth])
> [ 229.266157] [<bf3cb260>] (hci_send_frame [bluetooth]) from [<bf3cb334>=
] (hci_cmd_work+0xa8/0x124 [bluetooth])
> [ 229.277005] [<bf3cb334>] (hci_cmd_work [bluetooth]) from [<c036f154>] =
(process_one_work+0x43c/0x83c)
> [ 229.286689] [<c036f154>] (process_one_work) from [<c0370934>] (worker_=
thread+0x290/0x40c)
> [ 229.295355] [<c0370934>] (worker_thread) from [<c0376784>] (kthread+0x=
14c/0x168)
> [ 229.303195] [<c0376784>] (kthread) from [<c03080d0>] (ret_from_fork+0x=
14/0x24)
>
> It results in the first HCI command going through and then every other fa=
iling.
>
> =3D Index Info: 00:00:00:00:00:00 (Broadcom Corporation)
> < HCI Command: Broadcom Update UART Baud Rate (0x3f|0x0018) plen 6
> Encoded baud rate: Not used (0x0000)
> Explicit baud rate: 2000000 Mbps

Either we are printing the baud rate incorrectly of there gotta be
something wrong with it since 2 Tbps sounds pretty much impossible...
I guess this must be 2 Mbps/2000000 bps.

>> HCI Event: Command Complete (0x0e) plen 4
> Broadcom Update UART Baud Rate (0x3f|0x0018) ncmd 1
> Status: Success (0x00)
> < HCI Command: Reset (0x03|0x0003) plen 0
>
> The HCI Reset command actually times out.
>
> [ 231.349802] Bluetooth: hci0 command 0x0c03 tx timeout
>
> What we really need is some kernel specific debug tracing when driver cha=
nge baud rate etc. to show up in btmon. Drivers need the capability to inse=
rt HCI transport level specifics into monitoring interface.
>
> Regards
>
> Marcel
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth=
" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html



--=20
Luiz Augusto von Dentz