linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Unable to transfer big files to Nokia N9
@ 2021-12-01 17:39 Paul Menzel
  2021-12-01 18:29 ` Luiz Augusto von Dentz
  0 siblings, 1 reply; 12+ messages in thread
From: Paul Menzel @ 2021-12-01 17:39 UTC (permalink / raw)
  To: Marcel Holtmann, Johan Hedberg, Luiz Augusto von Dentz
  Cc: linux-bluetooth, LKML

Dear Linux folks,


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.


Kind regards,

Paul

^ permalink raw reply	[flat|nested] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2021-12-01 17:39 Unable to transfer big files to Nokia N9 Paul Menzel
@ 2021-12-01 18:29 ` Luiz Augusto von Dentz
  2021-12-01 22:07   ` Paul Menzel
  0 siblings, 1 reply; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2021-12-01 18:29 UTC (permalink / raw)
  To: Paul Menzel; +Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML

Hi Paul,

On Wed, Dec 1, 2021 at 9:39 AM Paul Menzel <pmenzel@molgen.mpg.de> wrote:
>
> Dear Linux folks,
>
>
> 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.

^ permalink raw reply	[flat|nested] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2021-12-01 18:29 ` Luiz Augusto von Dentz
@ 2021-12-01 22:07   ` Paul Menzel
  2021-12-20 21:31     ` Paul Menzel
  0 siblings, 1 reply; 12+ messages in thread
From: Paul Menzel @ 2021-12-01 22:07 UTC (permalink / raw)
  To: Luiz Augusto von Dentz
  Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML

Dear Luiz,


Thank you for your quick reply.

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


Kind regards,

Paul


[1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z

^ permalink raw reply	[flat|nested] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2021-12-01 22:07   ` Paul Menzel
@ 2021-12-20 21:31     ` Paul Menzel
  2022-01-16 13:27       ` Paul Menzel
  0 siblings, 1 reply; 12+ messages in thread
From: Paul Menzel @ 2021-12-20 21:31 UTC (permalink / raw)
  To: Luiz Augusto von Dentz
  Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML

Dear Luiz,


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?)


Kind regards,

Paul


> [1]: https://owww.molgen.mpg.de/~pmenzel/trace.log.7z

^ permalink raw reply	[flat|nested] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2021-12-20 21:31     ` Paul Menzel
@ 2022-01-16 13:27       ` Paul Menzel
  2022-01-28 10:36         ` Thorsten Leemhuis
  2022-02-11 16:10         ` Paul Menzel
  0 siblings, 2 replies; 12+ 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] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2022-01-16 13:27       ` Paul Menzel
@ 2022-01-28 10:36         ` Thorsten Leemhuis
  2022-02-07 13:14           ` Paul Menzel
  2022-02-11 16:10         ` Paul Menzel
  1 sibling, 1 reply; 12+ 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] 12+ 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; 12+ 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] 12+ 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; 12+ 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] 12+ 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; 12+ 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] 12+ 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; 12+ 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] 12+ 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; 12+ 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] 12+ messages in thread
* Re: Unable to transfer big files to Nokia N9
  2022-01-16 13:27       ` Paul Menzel
  2022-01-28 10:36         ` Thorsten Leemhuis
@ 2022-02-11 16:10         ` Paul Menzel
  1 sibling, 0 replies; 12+ messages in thread
From: Paul Menzel @ 2022-02-11 16:10 UTC (permalink / raw)
  To: Luiz Augusto von Dentz
  Cc: Marcel Holtmann, Johan Hedberg, linux-bluetooth, LKML, Takashi Iwai

Dear Luiz,


Am 16.01.22 um 14:27 schrieb Paul Menzel:

[…]

> 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.

The revert required one more revert [4]. You asked for logs, which I had 
already provided in my response to your request. I tried it again, and 
attached it to [5]. As written there, I failed to get logs for obexd.


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


>>> [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/ [4]: 
https://lore.kernel.org/linux-bluetooth/20220208221911.57058-1-pmenzel@molgen.mpg.de/
[5]: https://bugzilla.kernel.org/show_bug.cgi?id=215594

^ permalink raw reply	[flat|nested] 12+ messages in thread
end of thread, other threads:[~2022-02-11 16:10 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-12-01 17:39 Unable to transfer big files to Nokia N9 Paul Menzel
2021-12-01 18:29 ` Luiz Augusto von Dentz
2021-12-01 22:07   ` Paul Menzel
2021-12-20 21:31     ` Paul Menzel
2022-01-16 13:27       ` 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
2022-02-11 16:10         ` Paul Menzel

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).