* Re: Unable to transfer big files to Nokia N9
[not found] ` <a93c0fa7-7b84-6aea-265b-c913e0c84678@molgen.mpg.de>
@ 2022-01-16 13:27 ` Paul Menzel
2022-01-28 10:36 ` Thorsten Leemhuis
0 siblings, 1 reply; 7+ messages in thread
From: Paul Menzel @ 2022-01-16 13:27 UTC (permalink / raw)
To: Luiz Augusto von Dentz
Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML,
regressions, Takashi Iwai
#regzbot introduced: 81be03e026dc0c16dc1c64e088b2a53b73caa895
Dear Luiz,
It turns out there was a regression in Linux 5.16-rc1.
Am 20.12.21 um 22:31 schrieb Paul Menzel:
> Am 01.12.21 um 23:07 schrieb Paul Menzel:
>
>> Am 01.12.21 um 19:29 schrieb Luiz Augusto von Dentz:
>>
>>> On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de>
>>> wrote:
>>
>>>> For the first time, I wanted to transfer a 2 MB PDF file from a Dell
>>>> Latitude E7250 with Debian sid/unstable with Linux 5.16-rc1 to a Nokia
>>>> N9 (MeeGo/Harmattan). Using the package *bluez-obexd* 5.61-1 and GNOME
>>>> 41, the device was found, and paired fine. Then I selected to transfer
>>>> the 2 MB file, and after starting for a second, it timed out after the
>>>> progress bar moves forward ones and failed.
>>>>
>>>> The systemd journal contains:
>>>>
>>>> obexd[21139]: Transfer(0x56243fe4f790) Error: Timed out waiting for response
>>>>
>>>> Testing with a a 5 byte test text file, worked fine. Also testing with a
>>>> Galaly M32, both files were transferred without problems (though slowly
>>>> with 32 KB/s.)
>>>>
>>>> Trying to connect to the device with bluetoothctl failed for me, and the
>>>> journal contained, it failed.
>>>>
>>>> $ bluetoothctl
>>>> Agent registered
>>>> [bluetooth]# connect 40:98:4E:5B:CE:XX
>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>> Failed to connect: org.bluez.Error.Failed
>>>>
>>>> bluetoothd[21104]: src/service.c:btd_service_connect() a2dp-source profile connect failed for 40:98:4E:5B:CE:B3: Protocol not available
>>>>
>>>> As the Nokia N9 was once pretty popular in the Linux community, I am
>>>> pretty sure, it used to work fine in the past, and there is some
>>>> regression. It’d be great, if you could give me some hints how to
>>>> further debug the issue.
>>>
>>> We will need some logs, obexd and btmon, if possible.
>>
>> I only managed to get the btmon trace [1]. I did `sudo modprobe -r
>> btusb` and `sudo btmon -w /dev/shm/trace.log`.
>>
>> Linux messages:
>>
>> [29880.100381] calling btusb_driver_init+0x0/0x1000 [btusb] @ 28716
>> [29880.239603] usbcore: registered new interface driver btusb
>> [29880.239608] initcall btusb_driver_init+0x0/0x1000 [btusb] returned 0 after 135952 usecs
>> [29880.240706] Bluetooth: hci0: unexpected event for opcode 0x0500
>> [29880.241598] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0 build 3 week 17 2014
>> [29880.241605] Bluetooth: hci0: Intel device is already patched. patch num: 32
>>
>> From the system journal:
>>
>> Dez 01 22:52:19 ersatz obexd[21139]: Transfer(0x56243fe53dd0) Error: Timed out waiting for response
>
> Were you able to see anything in the attached logs? If the obexd logs
> are missing, can you please tell how I should capture them?
>
> I also tested with Ubuntu 20.04 (*linux-image-5.11.0-27-generic*) and
> 21.10 (*linux-image-5.13.0-19-generic*) live systems booted from a USB
> storage device, and transferring `/usr/bin/systemctl`
> (`/lib/systemd/systemd`) with size of 1.8 MB worked fine.
>
> Could there be a regression in that area? Unfortunately, it’s not easy
> for me to do a bisection on the device at hand.
>
> (Would it be possible to do with QEMU and USB controller and Bluetooth
> device passthrough? How can I transfer the file on the command line so I
> wouldn’t need to install a desktop environment?)
Turns out, that is indeed possible [2], but turned out to be cumbersome,
as I hit the regression [3], which seems to have been fixed by commit
95655456e7ce (Bluetooth: btintel: Fix broken LED quirk for legacy ROM
devices) merged in the current Linux 5.17 cycle this week.
As a work around, I applied a hunk from Takashi’s patch.
- { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED },
+ { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED |
+
BTUSB_INTEL_BROKEN_INITIAL_NCMD },
My problem with the Nokia N9 is still present in Linus’ master branch.
Then I built a minimal Linux kernel for QEMU, and ran:
qemu-system-x86_64 -cpu host -m 2G -enable-kvm \
-usb -device usb-host,vendorid=0x8087,productid=0x0a2a \
-drive file=/dev/shm/debian-64.img,format=raw,if=virtio \
-net nic -net user,hostfwd=tcp::22223-:22 \
-kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"
In the Debian sid/unstable VM, I used
ssh root@localhost -p 22223
I once had to pair the VM with the Nokia N9 in bluetoothctl, and then
started `/usr/libexec/bluetooth/obexd`, and ran `obexctl`, and connected
first with `connect`, and then ran `send /lib/systemd/systemd` to
transfer the file. In the problematic cases it stopped/hung after the
first progress message.
# obexctl
[NEW] Client /org/bluez/obex
[obex]# connect 40:98:4E:5B:CE:XX
Attempting to connect to 40:98:4E:5B:CE:XX
[NEW] Session /org/bluez/obex/client/session0 [default]
[NEW] ObjectPush /org/bluez/obex/client/session0
Connection successful
[40:98:4E:5B:CE:XX]# send /lib/systemd/systemd
Attempting to send /lib/systemd/systemd to
/org/bluez/obex/client/session0
[NEW] Transfer /org/bluez/obex/client/session0/transfer0
Transfer /org/bluez/obex/client/session0/transfer0
Status: queued
Name: systemd
Size: 1841712
Filename: /lib/systemd/systemd
Session: /org/bluez/obex/client/session0
[CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: active
[CHG] Transfer /org/bluez/obex/client/session0/transfer0
Transferred: 32737 (@32KB/s 00:55)
[CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: error
[DEL] Transfer /org/bluez/obex/client/session0/transfer0
Some manual bisection of Linux releases, verified, that the regression
was introduced in Linux 5.16-rc1. (Lucky me, I started using Bluetooth
with the Nokia with Linux 5.16-rc1.) Then I verified it was introduced
by the Bluetooth pull request for Linux 5.16. Then I picked commit
81be03e026dc0c16dc1c64e088b2a53b73caa895 due to the commit message, and
bisected from there, and it turns out, that this commit is actually
introducing the regression.
$ git bisect good
81be03e026dc0c16dc1c64e088b2a53b73caa895 is the first bad commit
commit 81be03e026dc0c16dc1c64e088b2a53b73caa895
Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Date: Fri Sep 3 15:27:32 2021 -0700
Bluetooth: RFCOMM: Replace use of memcpy_from_msg with
bt_skb_sendmmsg
This makes use of bt_skb_sendmmsg instead using memcpy_from_msg
which
is not considered safe to be used when lock_sock is held.
Also make rfcomm_dlc_send handle skb with fragments and queue
them all
atomically.
Signed-off-by: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Signed-off-by: Marcel Holtmann <marcel@holtmann.org>
net/bluetooth/rfcomm/core.c | 50
++++++++++++++++++++++++++++++++++++++-------
net/bluetooth/rfcomm/sock.c | 46
+++++++++--------------------------------
2 files changed, 53 insertions(+), 43 deletions(-)
Unfortunately, the patch does not cleanly revert, so users have to wait
until an expert can take a look, and come up with a fix.
Kind regards,
Paul
PS: For the records:
$ git bisect log
# bad: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth:
RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
# good: [49d8a5606428ca0962d09050a5af81461ff90fbb] Bluetooth: fix
init and cleanup of sco_conn.timeout_work
git bisect start '81be03e026dc0' 'HEAD^'
# good: [904c139a2517191e48f9cb1bb2d611ae59434009] Bluetooth: Add
support for msbc coding format
git bisect good 904c139a2517191e48f9cb1bb2d611ae59434009
# good: [8bba13b1d08d42e2e8308924fa5c1551a7b2b011] Bluetooth:
btintel: Fix incorrect out of memory check
git bisect good 8bba13b1d08d42e2e8308924fa5c1551a7b2b011
# good: [38f64f650dc0e44c146ff88d15a7339efa325918] Bluetooth: Add
bt_skb_sendmsg helper
git bisect good 38f64f650dc0e44c146ff88d15a7339efa325918
# good: [0771cbb3b97d3c1d68eecd7f00055f599954c34e] Bluetooth: SCO:
Replace use of memcpy_from_msg with bt_skb_sendmsg
git bisect good 0771cbb3b97d3c1d68eecd7f00055f599954c34e
# first bad commit: [81be03e026dc0c16dc1c64e088b2a53b73caa895]
Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
Kind regards,
Paul
>> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z
[2]:
https://lore.kernel.org/linux-bluetooth/5891f0d5-8d51-9da5-7663-718f301490b1@molgen.mpg.de/T/#u
[3]:
https://lore.kernel.org/linux-bluetooth/20211202162256.31837-1-tiwai@suse.de/
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-01-16 13:27 ` Unable to transfer big files to Nokia N9 Paul Menzel
@ 2022-01-28 10:36 ` Thorsten Leemhuis
2022-02-07 13:14 ` Paul Menzel
0 siblings, 1 reply; 7+ messages in thread
From: Thorsten Leemhuis @ 2022-01-28 10:36 UTC (permalink / raw)
To: Paul Menzel, Luiz Augusto von Dentz
Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML,
regressions, Takashi Iwai
Hi, this is your Linux kernel regression tracker speaking.
On 16.01.22 14:27, Paul Menzel wrote:
> #regzbot introduced: 81be03e026dc0c16dc1c64e088b2a53b73caa895
thx for getting regzbot involved, much appreciated!
> Dear Luiz,
>
> It turns out there was a regression in Linux 5.16-rc1.
@bt-maintaners, what's the status here? Paul reported that over ten days
ago and there wasn't a single reply. Or did the discussion move
somewhere else?
@Paul: just wondering, did you give 5.17-rc1 a try? Might be worth a
shot, if only to confirm the issue is still present.
Ciao, Thorsten
> Am 20.12.21 um 22:31 schrieb Paul Menzel:
>
>> Am 01.12.21 um 23:07 schrieb Paul Menzel:
>>
>>> Am 01.12.21 um 19:29 schrieb Luiz Augusto von Dentz:
>>>
>>>> On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de>
>>>> wrote:
>>>
>>>>> For the first time, I wanted to transfer a 2 MB PDF file from a Dell
>>>>> Latitude E7250 with Debian sid/unstable with Linux 5.16-rc1 to a Nokia
>>>>> N9 (MeeGo/Harmattan). Using the package *bluez-obexd* 5.61-1 and GNOME
>>>>> 41, the device was found, and paired fine. Then I selected to transfer
>>>>> the 2 MB file, and after starting for a second, it timed out after the
>>>>> progress bar moves forward ones and failed.
>>>>>
>>>>> The systemd journal contains:
>>>>>
>>>>> obexd[21139]: Transfer(0x56243fe4f790) Error: Timed out
>>>>> waiting for response
>>>>>
>>>>> Testing with a a 5 byte test text file, worked fine. Also testing
>>>>> with a
>>>>> Galaly M32, both files were transferred without problems (though
>>>>> slowly
>>>>> with 32 KB/s.)
>>>>>
>>>>> Trying to connect to the device with bluetoothctl failed for me,
>>>>> and the
>>>>> journal contained, it failed.
>>>>>
>>>>> $ bluetoothctl
>>>>> Agent registered
>>>>> [bluetooth]# connect 40:98:4E:5B:CE:XX
>>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>>> Failed to connect: org.bluez.Error.Failed
>>>>>
>>>>> bluetoothd[21104]: src/service.c:btd_service_connect()
>>>>> a2dp-source profile connect failed for 40:98:4E:5B:CE:B3: Protocol
>>>>> not available
>>>>>
>>>>> As the Nokia N9 was once pretty popular in the Linux community, I am
>>>>> pretty sure, it used to work fine in the past, and there is some
>>>>> regression. It’d be great, if you could give me some hints how to
>>>>> further debug the issue.
>>>>
>>>> We will need some logs, obexd and btmon, if possible.
>>>
>>> I only managed to get the btmon trace [1]. I did `sudo modprobe -r
>>> btusb` and `sudo btmon -w /dev/shm/trace.log`.
>>>
>>> Linux messages:
>>>
>>> [29880.100381] calling btusb_driver_init+0x0/0x1000 [btusb] @
>>> 28716
>>> [29880.239603] usbcore: registered new interface driver btusb
>>> [29880.239608] initcall btusb_driver_init+0x0/0x1000 [btusb]
>>> returned 0 after 135952 usecs
>>> [29880.240706] Bluetooth: hci0: unexpected event for opcode 0x0500
>>> [29880.241598] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0
>>> build 3 week 17 2014
>>> [29880.241605] Bluetooth: hci0: Intel device is already patched.
>>> patch num: 32
>>>
>>> From the system journal:
>>>
>>> Dez 01 22:52:19 ersatz obexd[21139]: Transfer(0x56243fe53dd0)
>>> Error: Timed out waiting for response
>>
>> Were you able to see anything in the attached logs? If the obexd logs
>> are missing, can you please tell how I should capture them?
>>
>> I also tested with Ubuntu 20.04 (*linux-image-5.11.0-27-generic*) and
>> 21.10 (*linux-image-5.13.0-19-generic*) live systems booted from a USB
>> storage device, and transferring `/usr/bin/systemctl`
>> (`/lib/systemd/systemd`) with size of 1.8 MB worked fine.
>>
>> Could there be a regression in that area? Unfortunately, it’s not easy
>> for me to do a bisection on the device at hand.
>>
>> (Would it be possible to do with QEMU and USB controller and Bluetooth
>> device passthrough? How can I transfer the file on the command line so
>> I wouldn’t need to install a desktop environment?)
>
> Turns out, that is indeed possible [2], but turned out to be cumbersome,
> as I hit the regression [3], which seems to have been fixed by commit
> 95655456e7ce (Bluetooth: btintel: Fix broken LED quirk for legacy ROM
> devices) merged in the current Linux 5.17 cycle this week.
>
> As a work around, I applied a hunk from Takashi’s patch.
>
> - { USB_DEVICE(0x8087, 0x0a2a), .driver_info =
> BTUSB_INTEL_COMBINED },
> + { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED |
> + BTUSB_INTEL_BROKEN_INITIAL_NCMD },
>
> My problem with the Nokia N9 is still present in Linus’ master branch.
>
> Then I built a minimal Linux kernel for QEMU, and ran:
>
> qemu-system-x86_64 -cpu host -m 2G -enable-kvm \
> -usb -device usb-host,vendorid=0x8087,productid=0x0a2a \
> -drive file=/dev/shm/debian-64.img,format=raw,if=virtio \
> -net nic -net user,hostfwd=tcp::22223-:22 \
> -kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"
>
> In the Debian sid/unstable VM, I used
>
> ssh root@localhost -p 22223
>
> I once had to pair the VM with the Nokia N9 in bluetoothctl, and then
> started `/usr/libexec/bluetooth/obexd`, and ran `obexctl`, and connected
> first with `connect`, and then ran `send /lib/systemd/systemd` to
> transfer the file. In the problematic cases it stopped/hung after the
> first progress message.
>
> # obexctl
> [NEW] Client /org/bluez/obex
> [obex]# connect 40:98:4E:5B:CE:XX
> Attempting to connect to 40:98:4E:5B:CE:XX
> [NEW] Session /org/bluez/obex/client/session0 [default]
> [NEW] ObjectPush /org/bluez/obex/client/session0
> Connection successful
> [40:98:4E:5B:CE:XX]# send /lib/systemd/systemd
> Attempting to send /lib/systemd/systemd to
> /org/bluez/obex/client/session0
> [NEW] Transfer /org/bluez/obex/client/session0/transfer0
> Transfer /org/bluez/obex/client/session0/transfer0
> Status: queued
> Name: systemd
> Size: 1841712
> Filename: /lib/systemd/systemd
> Session: /org/bluez/obex/client/session0
> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: active
> [CHG] Transfer /org/bluez/obex/client/session0/transfer0
> Transferred: 32737 (@32KB/s 00:55)
> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: error
> [DEL] Transfer /org/bluez/obex/client/session0/transfer0
>
> Some manual bisection of Linux releases, verified, that the regression
> was introduced in Linux 5.16-rc1. (Lucky me, I started using Bluetooth
> with the Nokia with Linux 5.16-rc1.) Then I verified it was introduced
> by the Bluetooth pull request for Linux 5.16. Then I picked commit
> 81be03e026dc0c16dc1c64e088b2a53b73caa895 due to the commit message, and
> bisected from there, and it turns out, that this commit is actually
> introducing the regression.
>
> $ git bisect good
> 81be03e026dc0c16dc1c64e088b2a53b73caa895 is the first bad commit
> commit 81be03e026dc0c16dc1c64e088b2a53b73caa895
> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> Date: Fri Sep 3 15:27:32 2021 -0700
>
> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with
> bt_skb_sendmmsg
>
> This makes use of bt_skb_sendmmsg instead using memcpy_from_msg
> which
> is not considered safe to be used when lock_sock is held.
>
> Also make rfcomm_dlc_send handle skb with fragments and queue
> them all
> atomically.
>
> Signed-off-by: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> Signed-off-by: Marcel Holtmann <marcel@holtmann.org>
>
> net/bluetooth/rfcomm/core.c | 50
> ++++++++++++++++++++++++++++++++++++++-------
> net/bluetooth/rfcomm/sock.c | 46
> +++++++++--------------------------------
> 2 files changed, 53 insertions(+), 43 deletions(-)
>
> Unfortunately, the patch does not cleanly revert, so users have to wait
> until an expert can take a look, and come up with a fix.
>
>
> Kind regards,
>
> Paul
>
>
> PS: For the records:
>
> $ git bisect log
> # bad: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth: RFCOMM:
> Replace use of memcpy_from_msg with bt_skb_sendmmsg
> # good: [49d8a5606428ca0962d09050a5af81461ff90fbb] Bluetooth: fix
> init and cleanup of sco_conn.timeout_work
> git bisect start '81be03e026dc0' 'HEAD^'
> # good: [904c139a2517191e48f9cb1bb2d611ae59434009] Bluetooth: Add
> support for msbc coding format
> git bisect good 904c139a2517191e48f9cb1bb2d611ae59434009
> # good: [8bba13b1d08d42e2e8308924fa5c1551a7b2b011] Bluetooth:
> btintel: Fix incorrect out of memory check
> git bisect good 8bba13b1d08d42e2e8308924fa5c1551a7b2b011
> # good: [38f64f650dc0e44c146ff88d15a7339efa325918] Bluetooth: Add
> bt_skb_sendmsg helper
> git bisect good 38f64f650dc0e44c146ff88d15a7339efa325918
> # good: [0771cbb3b97d3c1d68eecd7f00055f599954c34e] Bluetooth: SCO:
> Replace use of memcpy_from_msg with bt_skb_sendmsg
> git bisect good 0771cbb3b97d3c1d68eecd7f00055f599954c34e
> # first bad commit: [81be03e026dc0c16dc1c64e088b2a53b73caa895]
> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>
>
> Kind regards,
>
> Paul
>
>
>>> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z
> [2]:
> https://lore.kernel.org/linux-bluetooth/5891f0d5-8d51-9da5-7663-718f301490b1@molgen.mpg.de/T/#u
>
> [3]:
> https://lore.kernel.org/linux-bluetooth/20211202162256.31837-1-tiwai@suse.de/
>
>
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-01-28 10:36 ` Thorsten Leemhuis
@ 2022-02-07 13:14 ` Paul Menzel
2022-02-08 7:49 ` Paul Menzel
0 siblings, 1 reply; 7+ messages in thread
From: Paul Menzel @ 2022-02-07 13:14 UTC (permalink / raw)
To: Thorsten Leemhuis, Luiz Augusto von Dentz
Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML,
regressions, Takashi Iwai
Dear Thorsten, dear Luiz,
Am 28.01.22 um 11:36 schrieb Thorsten Leemhuis:
> Hi, this is your Linux kernel regression tracker speaking.
Thorsten, thank you for following up on this.
> On 16.01.22 14:27, Paul Menzel wrote:
>> #regzbot introduced: 81be03e026dc0c16dc1c64e088b2a53b73caa895
>
> thx for getting regzbot involved, much appreciated!
>
>> Dear Luiz,
>>
>> It turns out there was a regression in Linux 5.16-rc1.
>
> @bt-maintaners, what's the status here? Paul reported that over ten days
> ago and there wasn't a single reply. Or did the discussion move
> somewhere else?
>
> @Paul: just wondering, did you give 5.17-rc1 a try? Might be worth a
> shot, if only to confirm the issue is still present.
I just tried with 5.17-rc3, and the issue is still present.
Kind regards,
Paul
>> Am 20.12.21 um 22:31 schrieb Paul Menzel:
>>
>>> Am 01.12.21 um 23:07 schrieb Paul Menzel:
>>>
>>>> Am 01.12.21 um 19:29 schrieb Luiz Augusto von Dentz:
>>>>
>>>>> On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de>
>>>>> wrote:
>>>>
>>>>>> For the first time, I wanted to transfer a 2 MB PDF file from a Dell
>>>>>> Latitude E7250 with Debian sid/unstable with Linux 5.16-rc1 to a Nokia
>>>>>> N9 (MeeGo/Harmattan). Using the package *bluez-obexd* 5.61-1 and GNOME
>>>>>> 41, the device was found, and paired fine. Then I selected to transfer
>>>>>> the 2 MB file, and after starting for a second, it timed out after the
>>>>>> progress bar moves forward ones and failed.
>>>>>>
>>>>>> The systemd journal contains:
>>>>>>
>>>>>> obexd[21139]: Transfer(0x56243fe4f790) Error: Timed out
>>>>>> waiting for response
>>>>>>
>>>>>> Testing with a a 5 byte test text file, worked fine. Also testing
>>>>>> with a
>>>>>> Galaly M32, both files were transferred without problems (though
>>>>>> slowly
>>>>>> with 32 KB/s.)
>>>>>>
>>>>>> Trying to connect to the device with bluetoothctl failed for me,
>>>>>> and the
>>>>>> journal contained, it failed.
>>>>>>
>>>>>> $ bluetoothctl
>>>>>> Agent registered
>>>>>> [bluetooth]# connect 40:98:4E:5B:CE:XX
>>>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>>>> Failed to connect: org.bluez.Error.Failed
>>>>>>
>>>>>> bluetoothd[21104]: src/service.c:btd_service_connect()
>>>>>> a2dp-source profile connect failed for 40:98:4E:5B:CE:B3: Protocol
>>>>>> not available
>>>>>>
>>>>>> As the Nokia N9 was once pretty popular in the Linux community, I am
>>>>>> pretty sure, it used to work fine in the past, and there is some
>>>>>> regression. It’d be great, if you could give me some hints how to
>>>>>> further debug the issue.
>>>>>
>>>>> We will need some logs, obexd and btmon, if possible.
>>>>
>>>> I only managed to get the btmon trace [1]. I did `sudo modprobe -r
>>>> btusb` and `sudo btmon -w /dev/shm/trace.log`.
>>>>
>>>> Linux messages:
>>>>
>>>> [29880.100381] calling btusb_driver_init+0x0/0x1000 [btusb] @
>>>> 28716
>>>> [29880.239603] usbcore: registered new interface driver btusb
>>>> [29880.239608] initcall btusb_driver_init+0x0/0x1000 [btusb]
>>>> returned 0 after 135952 usecs
>>>> [29880.240706] Bluetooth: hci0: unexpected event for opcode 0x0500
>>>> [29880.241598] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0
>>>> build 3 week 17 2014
>>>> [29880.241605] Bluetooth: hci0: Intel device is already patched.
>>>> patch num: 32
>>>>
>>>> From the system journal:
>>>>
>>>> Dez 01 22:52:19 ersatz obexd[21139]: Transfer(0x56243fe53dd0)
>>>> Error: Timed out waiting for response
>>>
>>> Were you able to see anything in the attached logs? If the obexd logs
>>> are missing, can you please tell how I should capture them?
>>>
>>> I also tested with Ubuntu 20.04 (*linux-image-5.11.0-27-generic*) and
>>> 21.10 (*linux-image-5.13.0-19-generic*) live systems booted from a USB
>>> storage device, and transferring `/usr/bin/systemctl`
>>> (`/lib/systemd/systemd`) with size of 1.8 MB worked fine.
>>>
>>> Could there be a regression in that area? Unfortunately, it’s not easy
>>> for me to do a bisection on the device at hand.
>>>
>>> (Would it be possible to do with QEMU and USB controller and Bluetooth
>>> device passthrough? How can I transfer the file on the command line so
>>> I wouldn’t need to install a desktop environment?)
>>
>> Turns out, that is indeed possible [2], but turned out to be cumbersome,
>> as I hit the regression [3], which seems to have been fixed by commit
>> 95655456e7ce (Bluetooth: btintel: Fix broken LED quirk for legacy ROM
>> devices) merged in the current Linux 5.17 cycle this week.
>>
>> As a work around, I applied a hunk from Takashi’s patch.
>>
>> - { USB_DEVICE(0x8087, 0x0a2a), .driver_info =
>> BTUSB_INTEL_COMBINED },
>> + { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED |
>> + BTUSB_INTEL_BROKEN_INITIAL_NCMD },
>>
>> My problem with the Nokia N9 is still present in Linus’ master branch.
>>
>> Then I built a minimal Linux kernel for QEMU, and ran:
>>
>> qemu-system-x86_64 -cpu host -m 2G -enable-kvm \
>> -usb -device usb-host,vendorid=0x8087,productid=0x0a2a \
>> -drive file=/dev/shm/debian-64.img,format=raw,if=virtio \
>> -net nic -net user,hostfwd=tcp::22223-:22 \
>> -kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"
>>
>> In the Debian sid/unstable VM, I used
>>
>> ssh root@localhost -p 22223
>>
>> I once had to pair the VM with the Nokia N9 in bluetoothctl, and then
>> started `/usr/libexec/bluetooth/obexd`, and ran `obexctl`, and connected
>> first with `connect`, and then ran `send /lib/systemd/systemd` to
>> transfer the file. In the problematic cases it stopped/hung after the
>> first progress message.
>>
>> # obexctl
>> [NEW] Client /org/bluez/obex
>> [obex]# connect 40:98:4E:5B:CE:XX
>> Attempting to connect to 40:98:4E:5B:CE:XX
>> [NEW] Session /org/bluez/obex/client/session0 [default]
>> [NEW] ObjectPush /org/bluez/obex/client/session0
>> Connection successful
>> [40:98:4E:5B:CE:XX]# send /lib/systemd/systemd
>> Attempting to send /lib/systemd/systemd to
>> /org/bluez/obex/client/session0
>> [NEW] Transfer /org/bluez/obex/client/session0/transfer0
>> Transfer /org/bluez/obex/client/session0/transfer0
>> Status: queued
>> Name: systemd
>> Size: 1841712
>> Filename: /lib/systemd/systemd
>> Session: /org/bluez/obex/client/session0
>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: active
>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0
>> Transferred: 32737 (@32KB/s 00:55)
>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: error
>> [DEL] Transfer /org/bluez/obex/client/session0/transfer0
>>
>> Some manual bisection of Linux releases, verified, that the regression
>> was introduced in Linux 5.16-rc1. (Lucky me, I started using Bluetooth
>> with the Nokia with Linux 5.16-rc1.) Then I verified it was introduced
>> by the Bluetooth pull request for Linux 5.16. Then I picked commit
>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 due to the commit message, and
>> bisected from there, and it turns out, that this commit is actually
>> introducing the regression.
>>
>> $ git bisect good
>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 is the first bad commit
>> commit 81be03e026dc0c16dc1c64e088b2a53b73caa895
>> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
>> Date: Fri Sep 3 15:27:32 2021 -0700
>>
>> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with
>> bt_skb_sendmmsg
>>
>> This makes use of bt_skb_sendmmsg instead using memcpy_from_msg
>> which
>> is not considered safe to be used when lock_sock is held.
>>
>> Also make rfcomm_dlc_send handle skb with fragments and queue
>> them all
>> atomically.
>>
>> Signed-off-by: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
>> Signed-off-by: Marcel Holtmann <marcel@holtmann.org>
>>
>> net/bluetooth/rfcomm/core.c | 50
>> ++++++++++++++++++++++++++++++++++++++-------
>> net/bluetooth/rfcomm/sock.c | 46
>> +++++++++--------------------------------
>> 2 files changed, 53 insertions(+), 43 deletions(-)
>>
>> Unfortunately, the patch does not cleanly revert, so users have to wait
>> until an expert can take a look, and come up with a fix.
>>
>>
>> Kind regards,
>>
>> Paul
>>
>>
>> PS: For the records:
>>
>> $ git bisect log
>> # bad: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth: RFCOMM:
>> Replace use of memcpy_from_msg with bt_skb_sendmmsg
>> # good: [49d8a5606428ca0962d09050a5af81461ff90fbb] Bluetooth: fix
>> init and cleanup of sco_conn.timeout_work
>> git bisect start '81be03e026dc0' 'HEAD^'
>> # good: [904c139a2517191e48f9cb1bb2d611ae59434009] Bluetooth: Add
>> support for msbc coding format
>> git bisect good 904c139a2517191e48f9cb1bb2d611ae59434009
>> # good: [8bba13b1d08d42e2e8308924fa5c1551a7b2b011] Bluetooth:
>> btintel: Fix incorrect out of memory check
>> git bisect good 8bba13b1d08d42e2e8308924fa5c1551a7b2b011
>> # good: [38f64f650dc0e44c146ff88d15a7339efa325918] Bluetooth: Add
>> bt_skb_sendmsg helper
>> git bisect good 38f64f650dc0e44c146ff88d15a7339efa325918
>> # good: [0771cbb3b97d3c1d68eecd7f00055f599954c34e] Bluetooth: SCO:
>> Replace use of memcpy_from_msg with bt_skb_sendmsg
>> git bisect good 0771cbb3b97d3c1d68eecd7f00055f599954c34e
>> # first bad commit: [81be03e026dc0c16dc1c64e088b2a53b73caa895]
>> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>
>>
>> Kind regards,
>>
>> Paul
>>
>>
>>>> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z
>> [2]:
>> https://lore.kernel.org/linux-bluetooth/5891f0d5-8d51-9da5-7663-718f301490b1@molgen.mpg.de/T/#u
>>
>> [3]:
>> https://lore.kernel.org/linux-bluetooth/20211202162256.31837-1-tiwai@suse.de/
>>
>>
>>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-02-07 13:14 ` Paul Menzel
@ 2022-02-08 7:49 ` Paul Menzel
2022-02-10 10:36 ` Thorsten Leemhuis
0 siblings, 1 reply; 7+ messages in thread
From: Paul Menzel @ 2022-02-08 7:49 UTC (permalink / raw)
To: Thorsten Leemhuis, Luiz Augusto von Dentz
Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML,
regressions, Takashi Iwai
Dear Thorsten, dear Luiz,
Am 07.02.22 um 14:14 schrieb Paul Menzel:
> Am 28.01.22 um 11:36 schrieb Thorsten Leemhuis:
>> Hi, this is your Linux kernel regression tracker speaking.
>
> Thorsten, thank you for following up on this.
>
>> On 16.01.22 14:27, Paul Menzel wrote:
>>> #regzbot introduced: 81be03e026dc0c16dc1c64e088b2a53b73caa895
>>
>> thx for getting regzbot involved, much appreciated!
>>
>>> Dear Luiz,
>>>
>>> It turns out there was a regression in Linux 5.16-rc1.
>>
>> @bt-maintaners, what's the status here? Paul reported that over ten days
>> ago and there wasn't a single reply. Or did the discussion move
>> somewhere else?
>>
>> @Paul: just wondering, did you give 5.17-rc1 a try? Might be worth a
>> shot, if only to confirm the issue is still present.
>
> I just tried with 5.17-rc3, and the issue is still present.
Merging 4840aa67576b (Bluetooth: hci_core: Fix leaking sent_cmd skb) from
https://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth-next.git
into Linux 5.17-rc3, the resulting Linux kernel also has the problem.
Kind regards,
Paul
>>> Am 20.12.21 um 22:31 schrieb Paul Menzel:
>>>
>>>> Am 01.12.21 um 23:07 schrieb Paul Menzel:
>>>>
>>>>> Am 01.12.21 um 19:29 schrieb Luiz Augusto von Dentz:
>>>>>
>>>>>> On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de>
>>>>>> wrote:
>>>>>
>>>>>>> For the first time, I wanted to transfer a 2 MB PDF file from a Dell
>>>>>>> Latitude E7250 with Debian sid/unstable with Linux 5.16-rc1 to a Nokia
>>>>>>> N9 (MeeGo/Harmattan). Using the package *bluez-obexd* 5.61-1 and GNOME
>>>>>>> 41, the device was found, and paired fine. Then I selected to transfer
>>>>>>> the 2 MB file, and after starting for a second, it timed out after the
>>>>>>> progress bar moves forward ones and failed.
>>>>>>>
>>>>>>> The systemd journal contains:
>>>>>>>
>>>>>>> obexd[21139]: Transfer(0x56243fe4f790) Error: Timed out waiting for response
>>>>>>>
>>>>>>> Testing with a a 5 byte test text file, worked fine. Also testing with a
>>>>>>> Galaly M32, both files were transferred without problems (though slowly
>>>>>>> with 32 KB/s.)
>>>>>>>
>>>>>>> Trying to connect to the device with bluetoothctl failed for me,
>>>>>>> and the journal contained, it failed.
>>>>>>>
>>>>>>> $ bluetoothctl
>>>>>>> Agent registered
>>>>>>> [bluetooth]# connect 40:98:4E:5B:CE:XX
>>>>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>>>>> Failed to connect: org.bluez.Error.Failed
>>>>>>>
>>>>>>> bluetoothd[21104]: src/service.c:btd_service_connect() a2dp-source profile connect failed for 40:98:4E:5B:CE:B3: Protocol not
available
>>>>>>>
>>>>>>> As the Nokia N9 was once pretty popular in the Linux community, I am
>>>>>>> pretty sure, it used to work fine in the past, and there is some
>>>>>>> regression. It’d be great, if you could give me some hints how to
>>>>>>> further debug the issue.
>>>>>>
>>>>>> We will need some logs, obexd and btmon, if possible.
>>>>>
>>>>> I only managed to get the btmon trace [1]. I did `sudo modprobe -r
>>>>> btusb` and `sudo btmon -w /dev/shm/trace.log`.
>>>>>
>>>>> Linux messages:
>>>>>
>>>>> [29880.100381] calling btusb_driver_init+0x0/0x1000 [btusb] @28716
>>>>> [29880.239603] usbcore: registered new interface driver btusb
>>>>> [29880.239608] initcall btusb_driver_init+0x0/0x1000 [btusb] returned 0 after 135952 usecs
>>>>> [29880.240706] Bluetooth: hci0: unexpected event for opcode 0x0500
>>>>> [29880.241598] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0 build 3 week 17 2014
>>>>> [29880.241605] Bluetooth: hci0: Intel device is already patched. patch num: 32
>>>>>
>>>>> From the system journal:
>>>>>
>>>>> Dez 01 22:52:19 ersatz obexd[21139]: Transfer(0x56243fe53dd0) Error: Timed out waiting for response
>>>>
>>>> Were you able to see anything in the attached logs? If the obexd logs
>>>> are missing, can you please tell how I should capture them?
>>>>
>>>> I also tested with Ubuntu 20.04 (*linux-image-5.11.0-27-generic*) and
>>>> 21.10 (*linux-image-5.13.0-19-generic*) live systems booted from a USB
>>>> storage device, and transferring `/usr/bin/systemctl`
>>>> (`/lib/systemd/systemd`) with size of 1.8 MB worked fine.
>>>>
>>>> Could there be a regression in that area? Unfortunately, it’s not easy
>>>> for me to do a bisection on the device at hand.
>>>>
>>>> (Would it be possible to do with QEMU and USB controller and Bluetooth
>>>> device passthrough? How can I transfer the file on the command line so
>>>> I wouldn’t need to install a desktop environment?)
>>>
>>> Turns out, that is indeed possible [2], but turned out to be cumbersome,
>>> as I hit the regression [3], which seems to have been fixed by commit
>>> 95655456e7ce (Bluetooth: btintel: Fix broken LED quirk for legacy ROM
>>> devices) merged in the current Linux 5.17 cycle this week.
>>>
>>> As a work around, I applied a hunk from Takashi’s patch.
>>>
>>> - { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED },
>>> + { USB_DEVICE(0x8087, 0x0a2a), .driver_info = BTUSB_INTEL_COMBINED |
>>> + BTUSB_INTEL_BROKEN_INITIAL_NCMD },
>>>
>>> My problem with the Nokia N9 is still present in Linus’ master branch.
>>>
>>> Then I built a minimal Linux kernel for QEMU, and ran:
>>>
>>> qemu-system-x86_64 -cpu host -m 2G -enable-kvm \
>>> -usb -device usb-host,vendorid=0x8087,productid=0x0a2a \
>>> -drive file=/dev/shm/debian-64.img,format=raw,if=virtio \
>>> -net nic -net user,hostfwd=tcp::22223-:22 \
>>> -kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"
>>>
>>> In the Debian sid/unstable VM, I used
>>>
>>> ssh root@localhost -p 22223
>>>
>>> I once had to pair the VM with the Nokia N9 in bluetoothctl, and then
>>> started `/usr/libexec/bluetooth/obexd`, and ran `obexctl`, and connected
>>> first with `connect`, and then ran `send /lib/systemd/systemd` to
>>> transfer the file. In the problematic cases it stopped/hung after the
>>> first progress message.
>>>
>>> # obexctl
>>> [NEW] Client /org/bluez/obex
>>> [obex]# connect 40:98:4E:5B:CE:XX
>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>> [NEW] Session /org/bluez/obex/client/session0 [default]
>>> [NEW] ObjectPush /org/bluez/obex/client/session0
>>> Connection successful
>>> [40:98:4E:5B:CE:XX]# send /lib/systemd/systemd
>>> Attempting to send /lib/systemd/systemd to /org/bluez/obex/client/session0
>>> [NEW] Transfer /org/bluez/obex/client/session0/transfer0
>>> Transfer /org/bluez/obex/client/session0/transfer0
>>> Status: queued
>>> Name: systemd
>>> Size: 1841712
>>> Filename: /lib/systemd/systemd
>>> Session: /org/bluez/obex/client/session0
>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: active
>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Transferred: 32737 (@32KB/s 00:55)
>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0 Status: error
>>> [DEL] Transfer /org/bluez/obex/client/session0/transfer0
>>>
>>> Some manual bisection of Linux releases, verified, that the regression
>>> was introduced in Linux 5.16-rc1. (Lucky me, I started using Bluetooth
>>> with the Nokia with Linux 5.16-rc1.) Then I verified it was introduced
>>> by the Bluetooth pull request for Linux 5.16. Then I picked commit
>>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 due to the commit message, and
>>> bisected from there, and it turns out, that this commit is actually
>>> introducing the regression.
>>>
>>> $ git bisect good
>>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 is the first bad commit
>>> commit 81be03e026dc0c16dc1c64e088b2a53b73caa895
>>> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
>>> Date: Fri Sep 3 15:27:32 2021 -0700
>>>
>>> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>>
>>> This makes use of bt_skb_sendmmsg instead using memcpy_from_msg which
>>> is not considered safe to be used when lock_sock is held.
>>>
>>> Also make rfcomm_dlc_send handle skb with fragments and queue them all
>>> atomically.
>>>
>>> Signed-off-by: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
>>> Signed-off-by: Marcel Holtmann <marcel@holtmann.org>
>>>
>>> net/bluetooth/rfcomm/core.c | 50 ++++++++++++++++++++++++++++++++++++++-------
>>> net/bluetooth/rfcomm/sock.c | 46 +++++++++--------------------------------
>>> 2 files changed, 53 insertions(+), 43 deletions(-)
>>>
>>> Unfortunately, the patch does not cleanly revert, so users have to wait
>>> until an expert can take a look, and come up with a fix.
>>>
>>>
>>> Kind regards,
>>>
>>> Paul
>>>
>>>
>>> PS: For the records:
>>>
>>> $ git bisect log
>>> # bad: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>> # good: [49d8a5606428ca0962d09050a5af81461ff90fbb] Bluetooth: fix init and cleanup of sco_conn.timeout_work
>>> git bisect start '81be03e026dc0' 'HEAD^'
>>> # good: [904c139a2517191e48f9cb1bb2d611ae59434009] Bluetooth: Add support for msbc coding format
>>> git bisect good 904c139a2517191e48f9cb1bb2d611ae59434009
>>> # good: [8bba13b1d08d42e2e8308924fa5c1551a7b2b011] Bluetooth: btintel: Fix incorrect out of memory check
>>> git bisect good 8bba13b1d08d42e2e8308924fa5c1551a7b2b011
>>> # good: [38f64f650dc0e44c146ff88d15a7339efa325918] Bluetooth: Add bt_skb_sendmsg helper
>>> git bisect good 38f64f650dc0e44c146ff88d15a7339efa325918
>>> # good: [0771cbb3b97d3c1d68eecd7f00055f599954c34e] Bluetooth: SCO: Replace use of memcpy_from_msg with bt_skb_sendmsg
>>> git bisect good 0771cbb3b97d3c1d68eecd7f00055f599954c34e
>>> # first bad commit: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>>
>>>
>>> Kind regards,
>>>
>>> Paul
>>>
>>>
>>>>> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z
>>> [2]: https://lore.kernel.org/linux-bluetooth/5891f0d5-8d51-9da5-7663-718f301490b1@molgen.mpg.de/T/#u
>>> [3]: https://lore.kernel.org/linux-bluetooth/20211202162256.31837-1-tiwai@suse.de/
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-02-08 7:49 ` Paul Menzel
@ 2022-02-10 10:36 ` Thorsten Leemhuis
2022-02-11 8:29 ` Paul Menzel
0 siblings, 1 reply; 7+ messages in thread
From: Thorsten Leemhuis @ 2022-02-10 10:36 UTC (permalink / raw)
To: Paul Menzel, Luiz Augusto von Dentz
Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML,
regressions, Takashi Iwai
Hi, this is your Linux kernel regression tracker speaking. Top-posting
for once, to make this easy accessible to everyone.
Hey bluetooth-maintainers, what's the status here? I already asked for a
status update more that a week ago and didn't get a reply. Paul also
confirmed recently the issue is still present and no reply either. IOW:
this is talking way to long for a issue that was bisected?
Could you please comment on this? What can be done to get this rolling?
Or do I have to ask upstream maintainers to revert the culprit?
Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
P.S.: As the Linux kernel's regression tracker I'm getting a lot of
reports on my table. I can only look briefly into most of them and lack
knowledge about most of the areas they concern. I thus unfortunately
will sometimes get things wrong or miss something important. I hope
that's not the case here; if you think it is, don't hesitate to tell me
in a public reply, it's in everyone's interest to set the public record
straight.
#regzbot poke
On 08.02.22 08:49, Paul Menzel wrote:
> Dear Thorsten, dear Luiz,
>
>
> Am 07.02.22 um 14:14 schrieb Paul Menzel:
>
>> Am 28.01.22 um 11:36 schrieb Thorsten Leemhuis:
>>> Hi, this is your Linux kernel regression tracker speaking.
>>
>> Thorsten, thank you for following up on this.
>>
>>> On 16.01.22 14:27, Paul Menzel wrote:
>>>> #regzbot introduced: 81be03e026dc0c16dc1c64e088b2a53b73caa895
>>>
>>> thx for getting regzbot involved, much appreciated!
>>>
>>>> Dear Luiz,
>>>>
>>>> It turns out there was a regression in Linux 5.16-rc1.
>>>
>>> @bt-maintaners, what's the status here? Paul reported that over ten days
>>> ago and there wasn't a single reply. Or did the discussion move
>>> somewhere else?
>>>
>>> @Paul: just wondering, did you give 5.17-rc1 a try? Might be worth a
>>> shot, if only to confirm the issue is still present.
>>
>> I just tried with 5.17-rc3, and the issue is still present.
>
> Merging 4840aa67576b (Bluetooth: hci_core: Fix leaking sent_cmd skb) from
>
> https://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth-next.git
>
>
> into Linux 5.17-rc3, the resulting Linux kernel also has the problem.
>
>
> Kind regards,
>
> Paul
>
>
>>>> Am 20.12.21 um 22:31 schrieb Paul Menzel:
>>>>
>>>>> Am 01.12.21 um 23:07 schrieb Paul Menzel:
>>>>>
>>>>>> Am 01.12.21 um 19:29 schrieb Luiz Augusto von Dentz:
>>>>>>
>>>>>>> On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de>
>>>>>>> wrote:
>>>>>>
>>>>>>>> For the first time, I wanted to transfer a 2 MB PDF file from a
>>>>>>>> Dell
>>>>>>>> Latitude E7250 with Debian sid/unstable with Linux 5.16-rc1 to a
>>>>>>>> Nokia
>>>>>>>> N9 (MeeGo/Harmattan). Using the package *bluez-obexd* 5.61-1 and
>>>>>>>> GNOME
>>>>>>>> 41, the device was found, and paired fine. Then I selected to
>>>>>>>> transfer
>>>>>>>> the 2 MB file, and after starting for a second, it timed out
>>>>>>>> after the
>>>>>>>> progress bar moves forward ones and failed.
>>>>>>>>
>>>>>>>> The systemd journal contains:
>>>>>>>>
>>>>>>>> obexd[21139]: Transfer(0x56243fe4f790) Error: Timed out
>>>>>>>> waiting for response
>>>>>>>>
>>>>>>>> Testing with a a 5 byte test text file, worked fine. Also
>>>>>>>> testing with a
>>>>>>>> Galaly M32, both files were transferred without problems (though
>>>>>>>> slowly
>>>>>>>> with 32 KB/s.)
>>>>>>>>
>>>>>>>> Trying to connect to the device with bluetoothctl failed for me,
>>>>>>>> and the journal contained, it failed.
>>>>>>>>
>>>>>>>> $ bluetoothctl
>>>>>>>> Agent registered
>>>>>>>> [bluetooth]# connect 40:98:4E:5B:CE:XX
>>>>>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>>>>>> Failed to connect: org.bluez.Error.Failed
>>>>>>>>
>>>>>>>> bluetoothd[21104]: src/service.c:btd_service_connect()
>>>>>>>> a2dp-source profile connect failed for 40:98:4E:5B:CE:B3:
>>>>>>>> Protocol not
> available
>>>>>>>>
>>>>>>>> As the Nokia N9 was once pretty popular in the Linux community,
>>>>>>>> I am
>>>>>>>> pretty sure, it used to work fine in the past, and there is some
>>>>>>>> regression. It’d be great, if you could give me some hints how to
>>>>>>>> further debug the issue.
>>>>>>>
>>>>>>> We will need some logs, obexd and btmon, if possible.
>>>>>>
>>>>>> I only managed to get the btmon trace [1]. I did `sudo modprobe -r
>>>>>> btusb` and `sudo btmon -w /dev/shm/trace.log`.
>>>>>>
>>>>>> Linux messages:
>>>>>>
>>>>>> [29880.100381] calling btusb_driver_init+0x0/0x1000 [btusb]
>>>>>> @28716
>>>>>> [29880.239603] usbcore: registered new interface driver btusb
>>>>>> [29880.239608] initcall btusb_driver_init+0x0/0x1000 [btusb]
>>>>>> returned 0 after 135952 usecs
>>>>>> [29880.240706] Bluetooth: hci0: unexpected event for opcode
>>>>>> 0x0500
>>>>>> [29880.241598] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0
>>>>>> build 3 week 17 2014
>>>>>> [29880.241605] Bluetooth: hci0: Intel device is already
>>>>>> patched. patch num: 32
>>>>>>
>>>>>> From the system journal:
>>>>>>
>>>>>> Dez 01 22:52:19 ersatz obexd[21139]:
>>>>>> Transfer(0x56243fe53dd0) Error: Timed out waiting for response
>>>>>
>>>>> Were you able to see anything in the attached logs? If the obexd logs
>>>>> are missing, can you please tell how I should capture them?
>>>>>
>>>>> I also tested with Ubuntu 20.04 (*linux-image-5.11.0-27-generic*) and
>>>>> 21.10 (*linux-image-5.13.0-19-generic*) live systems booted from a USB
>>>>> storage device, and transferring `/usr/bin/systemctl`
>>>>> (`/lib/systemd/systemd`) with size of 1.8 MB worked fine.
>>>>>
>>>>> Could there be a regression in that area? Unfortunately, it’s not easy
>>>>> for me to do a bisection on the device at hand.
>>>>>
>>>>> (Would it be possible to do with QEMU and USB controller and Bluetooth
>>>>> device passthrough? How can I transfer the file on the command line so
>>>>> I wouldn’t need to install a desktop environment?)
>>>>
>>>> Turns out, that is indeed possible [2], but turned out to be
>>>> cumbersome,
>>>> as I hit the regression [3], which seems to have been fixed by commit
>>>> 95655456e7ce (Bluetooth: btintel: Fix broken LED quirk for legacy ROM
>>>> devices) merged in the current Linux 5.17 cycle this week.
>>>>
>>>> As a work around, I applied a hunk from Takashi’s patch.
>>>>
>>>> - { USB_DEVICE(0x8087, 0x0a2a), .driver_info =
>>>> BTUSB_INTEL_COMBINED },
>>>> + { USB_DEVICE(0x8087, 0x0a2a), .driver_info =
>>>> BTUSB_INTEL_COMBINED |
>>>> + BTUSB_INTEL_BROKEN_INITIAL_NCMD },
>>>>
>>>> My problem with the Nokia N9 is still present in Linus’ master branch.
>>>>
>>>> Then I built a minimal Linux kernel for QEMU, and ran:
>>>>
>>>> qemu-system-x86_64 -cpu host -m 2G -enable-kvm \
>>>> -usb -device usb-host,vendorid=0x8087,productid=0x0a2a \
>>>> -drive file=/dev/shm/debian-64.img,format=raw,if=virtio \
>>>> -net nic -net user,hostfwd=tcp::22223-:22 \
>>>> -kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"
>>>>
>>>> In the Debian sid/unstable VM, I used
>>>>
>>>> ssh root@localhost -p 22223
>>>>
>>>> I once had to pair the VM with the Nokia N9 in bluetoothctl, and then
>>>> started `/usr/libexec/bluetooth/obexd`, and ran `obexctl`, and
>>>> connected
>>>> first with `connect`, and then ran `send /lib/systemd/systemd` to
>>>> transfer the file. In the problematic cases it stopped/hung after the
>>>> first progress message.
>>>>
>>>> # obexctl
>>>> [NEW] Client /org/bluez/obex
>>>> [obex]# connect 40:98:4E:5B:CE:XX
>>>> Attempting to connect to 40:98:4E:5B:CE:XX
>>>> [NEW] Session /org/bluez/obex/client/session0 [default]
>>>> [NEW] ObjectPush /org/bluez/obex/client/session0
>>>> Connection successful
>>>> [40:98:4E:5B:CE:XX]# send /lib/systemd/systemd
>>>> Attempting to send /lib/systemd/systemd to
>>>> /org/bluez/obex/client/session0
>>>> [NEW] Transfer /org/bluez/obex/client/session0/transfer0
>>>> Transfer /org/bluez/obex/client/session0/transfer0
>>>> Status: queued
>>>> Name: systemd
>>>> Size: 1841712
>>>> Filename: /lib/systemd/systemd
>>>> Session: /org/bluez/obex/client/session0
>>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0
>>>> Status: active
>>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0
>>>> Transferred: 32737 (@32KB/s 00:55)
>>>> [CHG] Transfer /org/bluez/obex/client/session0/transfer0
>>>> Status: error
>>>> [DEL] Transfer /org/bluez/obex/client/session0/transfer0
>>>>
>>>> Some manual bisection of Linux releases, verified, that the regression
>>>> was introduced in Linux 5.16-rc1. (Lucky me, I started using Bluetooth
>>>> with the Nokia with Linux 5.16-rc1.) Then I verified it was introduced
>>>> by the Bluetooth pull request for Linux 5.16. Then I picked commit
>>>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 due to the commit message, and
>>>> bisected from there, and it turns out, that this commit is actually
>>>> introducing the regression.
>>>>
>>>> $ git bisect good
>>>> 81be03e026dc0c16dc1c64e088b2a53b73caa895 is the first bad commit
>>>> commit 81be03e026dc0c16dc1c64e088b2a53b73caa895
>>>> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
>>>> Date: Fri Sep 3 15:27:32 2021 -0700
>>>>
>>>> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with
>>>> bt_skb_sendmmsg
>>>>
>>>> This makes use of bt_skb_sendmmsg instead using
>>>> memcpy_from_msg which
>>>> is not considered safe to be used when lock_sock is held.
>>>>
>>>> Also make rfcomm_dlc_send handle skb with fragments and
>>>> queue them all
>>>> atomically.
>>>>
>>>> Signed-off-by: Luiz Augusto von Dentz
>>>> <luiz.von.dentz@intel.com>
>>>> Signed-off-by: Marcel Holtmann <marcel@holtmann.org>
>>>>
>>>> net/bluetooth/rfcomm/core.c | 50
>>>> ++++++++++++++++++++++++++++++++++++++-------
>>>> net/bluetooth/rfcomm/sock.c | 46
>>>> +++++++++--------------------------------
>>>> 2 files changed, 53 insertions(+), 43 deletions(-)
>>>>
>>>> Unfortunately, the patch does not cleanly revert, so users have to wait
>>>> until an expert can take a look, and come up with a fix.
>>>>
>>>>
>>>> Kind regards,
>>>>
>>>> Paul
>>>>
>>>>
>>>> PS: For the records:
>>>>
>>>> $ git bisect log
>>>> # bad: [81be03e026dc0c16dc1c64e088b2a53b73caa895] Bluetooth:
>>>> RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>>> # good: [49d8a5606428ca0962d09050a5af81461ff90fbb] Bluetooth:
>>>> fix init and cleanup of sco_conn.timeout_work
>>>> git bisect start '81be03e026dc0' 'HEAD^'
>>>> # good: [904c139a2517191e48f9cb1bb2d611ae59434009] Bluetooth:
>>>> Add support for msbc coding format
>>>> git bisect good 904c139a2517191e48f9cb1bb2d611ae59434009
>>>> # good: [8bba13b1d08d42e2e8308924fa5c1551a7b2b011] Bluetooth:
>>>> btintel: Fix incorrect out of memory check
>>>> git bisect good 8bba13b1d08d42e2e8308924fa5c1551a7b2b011
>>>> # good: [38f64f650dc0e44c146ff88d15a7339efa325918] Bluetooth:
>>>> Add bt_skb_sendmsg helper
>>>> git bisect good 38f64f650dc0e44c146ff88d15a7339efa325918
>>>> # good: [0771cbb3b97d3c1d68eecd7f00055f599954c34e] Bluetooth:
>>>> SCO: Replace use of memcpy_from_msg with bt_skb_sendmsg
>>>> git bisect good 0771cbb3b97d3c1d68eecd7f00055f599954c34e
>>>> # first bad commit: [81be03e026dc0c16dc1c64e088b2a53b73caa895]
>>>> Bluetooth: RFCOMM: Replace use of memcpy_from_msg with bt_skb_sendmmsg
>>>>
>>>>
>>>> Kind regards,
>>>>
>>>> Paul
>>>>
>>>>
>>>>>> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z
>>>> [2]:
>>>> https://lore.kernel.org/linux-bluetooth/5891f0d5-8d51-9da5-7663-718f301490b1@molgen.mpg.de/T/#u
>>>> [3]:
>>>> https://lore.kernel.org/linux-bluetooth/20211202162256.31837-1-tiwai@suse.de/
>>>>
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-02-10 10:36 ` Thorsten Leemhuis
@ 2022-02-11 8:29 ` Paul Menzel
2022-02-11 8:59 ` Thorsten Leemhuis
0 siblings, 1 reply; 7+ messages in thread
From: Paul Menzel @ 2022-02-11 8:29 UTC (permalink / raw)
To: Thorsten Leemhuis
Cc: Luiz Augusto von Dentz, Marcel Holtmann, Johan Hedberg,
linux-bluetooth, LKML, regressions, Takashi Iwai
Dear Thorsten,
Am 10.02.22 um 11:36 schrieb Thorsten Leemhuis:
> Hi, this is your Linux kernel regression tracker speaking. Top-posting
> for once, to make this easy accessible to everyone.
>
> Hey bluetooth-maintainers, what's the status here? I already asked for a
> status update more that a week ago and didn't get a reply. Paul also
> confirmed recently the issue is still present and no reply either. IOW:
> this is talking way to long for a issue that was bisected?
>
> Could you please comment on this? What can be done to get this rolling?
> Or do I have to ask upstream maintainers to revert the culprit?
I sent two reverts [1], and probably forgot to add a tag to reference
this discussion.
Luiz asked me two provide more logs. Hopefully, I am going to come
around to that today, but maybe it’s better to revert so that Linux 5.16
can also be fixed.
Kind regards,
Paul
[1]:
https://lore.kernel.org/linux-bluetooth/20220208221911.57058-1-pmenzel@molgen.mpg.de/T/
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Unable to transfer big files to Nokia N9
2022-02-11 8:29 ` Paul Menzel
@ 2022-02-11 8:59 ` Thorsten Leemhuis
0 siblings, 0 replies; 7+ messages in thread
From: Thorsten Leemhuis @ 2022-02-11 8:59 UTC (permalink / raw)
To: Paul Menzel
Cc: Luiz Augusto von Dentz, Marcel Holtmann, Johan Hedberg,
linux-bluetooth, LKML, regressions, Takashi Iwai
On 11.02.22 09:29, Paul Menzel wrote:
> Am 10.02.22 um 11:36 schrieb Thorsten Leemhuis:
>> Hi, this is your Linux kernel regression tracker speaking. Top-posting
>> for once, to make this easy accessible to everyone.
>>
>> Hey bluetooth-maintainers, what's the status here? I already asked for a
>> status update more that a week ago and didn't get a reply. Paul also
>> confirmed recently the issue is still present and no reply either. IOW:
>> this is talking way to long for a issue that was bisected?
>>
>> Could you please comment on this? What can be done to get this rolling?
>> Or do I have to ask upstream maintainers to revert the culprit?
>
> I sent two reverts [1], and probably forgot to add a tag to reference
> this discussion.
>
> Luiz asked me two provide more logs. Hopefully, I am going to come
> around to that today, but maybe it’s better to revert so that Linux 5.16
> can also be fixed.
Ahh, thx, great to see this finally got things running.
This will let regzbot know about it:
#regzbot monitor:
https://lore.kernel.org/linux-bluetooth/20220208221911.57058-1-pmenzel@molgen.mpg.de/
With a proper "Link:" tag this would have happened automatically, but no
worries, a lot of people forget to set it. :-D
Ciao, Thorsten
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2022-02-11 9:00 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <eb6d86eb-d156-d7ac-0965-181719023d51@molgen.mpg.de>
[not found] ` <CABBYNZLENxvXMCh6XbBSnu0jasV1F0QestEK5v2mnNUpJdw3Vw@mail.gmail.com>
[not found] ` <cf71bdea-ec22-e4c9-016c-69e94a130607@molgen.mpg.de>
[not found] ` <a93c0fa7-7b84-6aea-265b-c913e0c84678@molgen.mpg.de>
2022-01-16 13:27 ` Unable to transfer big files to Nokia N9 Paul Menzel
2022-01-28 10:36 ` Thorsten Leemhuis
2022-02-07 13:14 ` Paul Menzel
2022-02-08 7:49 ` Paul Menzel
2022-02-10 10:36 ` Thorsten Leemhuis
2022-02-11 8:29 ` Paul Menzel
2022-02-11 8:59 ` Thorsten Leemhuis
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).