Betaflight-configurator: disconnect usb from btf-cfg leads to kernel hang at usb_submit_urb

[innofocus]

1. Describe your problem;
   using btf-cfg under linux ubuntu 20 with eachine qx65 with freshly installed btf 4.0.6
   when exiting from cli mode, the linux kernel hangs on cpu with kernel message :
   NMI watchdog: BUG: soft lockup - CPU#? stuck for 22s!"

2. Include ways to reproduce the problem;
   enter in cli mode and exit from cli mode
   or
   save config (it disconnects and tries to reconnect)
   then
   the pc hangs with kernel message: NMI watchdog: BUG: soft lockup - CPU#? stuck for 22s!

3. Provide as much information as possible about your hardware and software, including:

4. what hardware / software you are using;
   drone : Betaflight / OMNIBUS (OMNI) 4.0.6 Sep 1 2019 / 00:55:54 (2a64051a2) MSP API: 1.41 / FEATURE CUT LEVEL 9
   linux : Linux hostname 5.4.0-42-generic #46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

• the version of all the software used;
  betaflight-configurator : 10.6.0 or 10.7.0

• how things are connected / wired up.
  tested both usb ports on my laptop pc

• logs from /var/log/syslog with btf-cfg 10.7.0 :
  Aug 22 14:12:34 hostname kernel: [ 541.597171] BUG: unable to handle page fault for address: 00000004a6ca80b0
  Aug 22 14:12:34 hostname kernel: [ 541.597185] #PF: supervisor read access in kernel mode
  Aug 22 14:12:34 hostname kernel: [ 541.597191] #PF: error_code(0x0000) - not-present page
  Aug 22 14:12:34 hostname kernel: [ 541.597196] PGD 0 P4D 0
  Aug 22 14:12:34 hostname kernel: [ 541.597207] Oops: 0000 [#1] SMP PTI
  Aug 22 14:12:34 hostname kernel: [ 541.597217] CPU: 3 PID: 4893 Comm: kworker/3:1 Not tainted 5.4.0-42-generic #46-Ubuntu
  Aug 22 14:12:34 hostname kernel: [ 541.597223] Hardware name: LENOVO
  Aug 22 14:12:34 hostname kernel: [ 541.597241] Workqueue: events acm_softint [cdc_acm]
  Aug 22 14:12:34 hostname kernel: [ 541.597255] RIP: 0010:usb_submit_urb+0x22/0x5e0

• logs from /var/log/syslog with btf-cfg 10.6.0
  Aug 22 14:37:43 hostname kernel: [ 372.320458] WARNING: CPU: 3 PID: 4597 at kernel/workqueue.c:1477 __queue_work+0x348/0x3f0
  ...
  Aug 22 14:37:43 hostname kernel: [ 372.510591] usb 1-4: USB disconnect, device number 10
  Aug 22 14:37:43 hostname kernel: [ 372.510910] cdc_acm 1-4:1.0: failed to set dtr/rts

1. Other tests made
   error/bug happen when save or disconnect/reconnect too
   no error when using inav-configurator
   no error when unplug-plug-unplug drone

[haslinghuis]

No problems with Betaflight Configurator 10.7.0 / 10.8.0 on Ubuntu 20.04 LTS.
What do you mean by exit from cli mode by clicking on installation?
Ah I see the problem: you still have modemmanager installed
See wiki or docs

[innofocus]

Hi, thanks for your time.
Glad to know it's only my setup.
I'm exiting the cli by clicking another menu item in btf-cfg.

I didn't pay attention on the ModemManager conflict in the wiki at the time I first succeded in using btf-cfg on the very laptop months ago (it was ubuntu 19 at the time being, before update to 20).

But while it's obvious in the logs the gsm is taking major role (cdc_acm), updating the gsm firmware or removing all gsm kernel modules (not blacklisting them, just rmmod) and uninstalling ModemManager don't help at all.

The gsm is : ID 1199:9079 Sierra Wireless, Inc. Sierra Wireless EM7455 Qualcomm Snapdragon X7 LTE-A

[haslinghuis]

Might have to add the udev rules (see links above)

[innofocus]

The udev have been installed and working well long time ago. I've been checking that's still here in place. Yes.
Thus I've been able to flash my qx65 (but needed to reboot my computer after... as for any usb close connection event).
So annoying !

[haslinghuis]

.. the usb gsm issue .. do you have an smartphone connected to your pc/laptop? Perhaps it tries to hijack the serial port on some point

[innofocus]

Hey, the faulty modem isn't my gsm :
Aug 22 14:37:43 hostname kernel: [ 372.510591] usb 1-4: USB disconnect, device number 10
Aug 22 14:37:43 hostname kernel: [ 372.510910] cdc_acm 1-4:1.0: failed to set dtr/rts

The 1-4:1:0: device is the drone ! : here's the log syslog when unplug/plug drone (without btf-cfg running)

Aug 22 23:16:00 hostname kernel: [ 299.072556] usb 1-4: USB disconnect, device number 12
Aug 22 23:16:06 hostname kernel: [ 304.949869] usb 1-4: new full-speed USB device number 13 using xhci_hcd
Aug 22 23:16:06 hostname kernel: [ 305.077339] usb 1-4: device descriptor read/64, error -71
Aug 22 23:16:06 hostname kernel: [ 305.313872] usb 1-4: device descriptor read/64, error -71
Aug 22 23:16:07 hostname kernel: [ 305.549825] usb 1-4: new full-speed USB device number 14 using xhci_hcd
Aug 22 23:16:07 hostname kernel: [ 305.677844] usb 1-4: device descriptor read/64, error -71
Aug 22 23:16:07 hostname kernel: [ 306.189812] usb 1-4: device descriptor read/64, error -71
Aug 22 23:16:07 hostname kernel: [ 306.297787] usb usb1-port4: attempt power cycle
Aug 22 23:16:08 hostname kernel: [ 306.949730] usb 1-4: new full-speed USB device number 15 using xhci_hcd
Aug 22 23:16:08 hostname kernel: [ 306.970556] usb 1-4: New USB device found, idVendor=0483, idProduct=5740, bcdDevice= 2.00
Aug 22 23:16:08 hostname kernel: [ 306.970559] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 22 23:16:08 hostname kernel: [ 306.970561] usb 1-4: Product: STM32 Virtual COM Port
Aug 22 23:16:08 hostname kernel: [ 306.970562] usb 1-4: Manufacturer: STMicroelectronics
Aug 22 23:16:08 hostname kernel: [ 306.970564] usb 1-4: SerialNumber: 2222222222222
Aug 22 23:16:08 hostname kernel: [ 306.971981] cdc_acm 1-4:1.0: ttyACM0: USB ACM device
Aug 22 23:16:08 hostname mtp-probe: checking bus 1, device 15: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
Aug 22 23:16:08 hostname mtp-probe: bus: 1, device: 15 was not an MTP device
Aug 22 23:16:08 hostname snapd[886]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Aug 22 23:16:08 hostname mtp-probe: checking bus 1, device 15: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4"
Aug 22 23:16:08 hostname mtp-probe: bus: 1, device: 15 was not an MTP device
Aug 22 23:16:11 hostname ModemManager[941]: Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4': not supported by any plugin
Aug 22 23:17:01 hostname CRON[3566]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 22 23:17:05 hostname PackageKit: daemon quit
Aug 22 23:17:05 hostname systemd[1]: packagekit.service: Succeeded.

[haslinghuis]

My syslog after attaching drone to laptop:

Aug 22 23:43:18 lenovo systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 22 23:43:18 lenovo dbus-daemon[716]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 22 23:43:18 lenovo systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 22 23:43:28 lenovo systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Aug 22 23:44:24 lenovo kernel: [ 1872.807739] usb 3-4: USB disconnect, device number 2
Aug 22 23:44:24 lenovo kernel: [ 1872.808011] cdc_acm 3-4:1.0: failed to set dtr/rts
Aug 22 23:44:32 lenovo kernel: [ 1881.231983] usb 3-4: new full-speed USB device number 3 using xhci_hcd
Aug 22 23:44:32 lenovo kernel: [ 1881.381762] usb 3-4: New USB device found, idVendor=0483, idProduct=5740, bcdDevice= 2.00
Aug 22 23:44:32 lenovo kernel: [ 1881.381769] usb 3-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 22 23:44:32 lenovo kernel: [ 1881.381773] usb 3-4: Product: Betaflight STM32F411
Aug 22 23:44:32 lenovo kernel: [ 1881.381777] usb 3-4: Manufacturer: Betaflight
Aug 22 23:44:32 lenovo kernel: [ 1881.381780] usb 3-4: SerialNumber: 0x8000000
Aug 22 23:44:32 lenovo kernel: [ 1881.382885] cdc_acm 3-4:1.0: ttyACM0: USB ACM device
Aug 22 23:44:32 lenovo mtp-probe: checking bus 3, device 3: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4"
Aug 22 23:44:32 lenovo mtp-probe: bus: 3, device: 3 was not an MTP device
Aug 22 23:44:33 lenovo snapd[744]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Aug 22 23:44:33 lenovo mtp-probe: checking bus 3, device 3: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4"
Aug 22 23:44:33 lenovo mtp-probe: bus: 3, device: 3 was not an MTP device
Aug 22 23:51:22 lenovo kernel: [ 2291.082702] usb 3-4: USB disconnect, device number 3
Aug 22 23:51:31 lenovo kernel: [ 2300.294624] usb 3-4: new full-speed USB device number 4 using xhci_hcd
Aug 22 23:51:32 lenovo kernel: [ 2300.444163] usb 3-4: New USB device found, idVendor=0483, idProduct=5740, bcdDevice= 2.00
Aug 22 23:51:32 lenovo kernel: [ 2300.444170] usb 3-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 22 23:51:32 lenovo kernel: [ 2300.444175] usb 3-4: Product: Betaflight STM32F411
Aug 22 23:51:32 lenovo kernel: [ 2300.444178] usb 3-4: Manufacturer: Betaflight
Aug 22 23:51:32 lenovo kernel: [ 2300.444181] usb 3-4: SerialNumber: 0x8000000
Aug 22 23:51:32 lenovo kernel: [ 2300.445307] cdc_acm 3-4:1.0: ttyACM0: USB ACM device
Aug 22 23:51:32 lenovo mtp-probe: checking bus 3, device 4: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4"
Aug 22 23:51:32 lenovo mtp-probe: bus: 3, device: 4 was not an MTP device
Aug 22 23:51:32 lenovo snapd[744]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Aug 22 23:51:32 lenovo mtp-probe: checking bus 3, device 4: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-4"
Aug 22 23:51:32 lenovo mtp-probe: bus: 3, device: 4 was not an MTP device

[innofocus]

So trying to establish a clean configuration regarding to the ModemManager : let's adding good exclusion rules for the stm32 in udev.

root@hostname:/etc/udev/rules.d# cat > 49-stm32.rules

0483:5740 - STM32 in USB Serial Mode (CN5)

ATTRS{idVendor}=="0483", ATTRS{idProduct}=="5740", ENV{ID_MM_DEVICE_IGNORE}="1"
ATTRS{idVendor}=="0483", ATTRS{idProduct}=="5740", ENV{ID_MM_TTY_BLACKLIST}="1"
ATTRS{idVendor}=="0483", ATTRS{idProduct}=="5740", ENV{MTP_NO_PROBE}="1"
ATTRS{idVendor}=="0483", ATTRS{idProduct}=="5740", ENV{ID_MM_PORT_IGNORE}="1"
ATTRS{idVendor}=="0483", ATTRS{idProduct}=="5740", ENV{ID_MM_TTY_MANUAL_SCAN_ONLY}="1"
root@hostname:/etc/udev/rules.d# udevadm control -R
root@hostname:/etc/udev/rules.d# systemctl restart ModemManager.service

Then admire the straightforward syslog :

Aug 22 23:52:20 hostname kernel: [ 302.439785] usb 1-4: new full-speed USB device number 7 using xhci_hcd
Aug 22 23:52:20 hostname kernel: [ 302.567424] usb 1-4: device descriptor read/64, error -71
Aug 22 23:52:20 hostname kernel: [ 302.803805] usb 1-4: device descriptor read/64, error -71
Aug 22 23:52:20 hostname kernel: [ 303.039832] usb 1-4: new full-speed USB device number 8 using xhci_hcd
Aug 22 23:52:20 hostname kernel: [ 303.167795] usb 1-4: device descriptor read/64, error -71
Aug 22 23:52:21 hostname kernel: [ 303.679780] usb 1-4: device descriptor read/64, error -71
Aug 22 23:52:21 hostname kernel: [ 303.787814] usb usb1-port4: attempt power cycle
Aug 22 23:52:22 hostname kernel: [ 304.439730] usb 1-4: new full-speed USB device number 9 using xhci_hcd
Aug 22 23:52:22 hostname kernel: [ 304.461363] usb 1-4: New USB device found, idVendor=0483, idProduct=5740, bcdDevice= 2.00
Aug 22 23:52:22 hostname kernel: [ 304.461368] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 22 23:52:22 hostname kernel: [ 304.461372] usb 1-4: Product: STM32 Virtual COM Port
Aug 22 23:52:22 hostname kernel: [ 304.461375] usb 1-4: Manufacturer: STMicroelectronics
Aug 22 23:52:22 hostname kernel: [ 304.461377] usb 1-4: SerialNumber: 222222222222
Aug 22 23:52:22 hostname kernel: [ 304.505735] cdc_acm 1-4:1.0: ttyACM0: USB ACM device
Aug 22 23:52:22 hostname kernel: [ 304.507894] usbcore: registered new interface driver cdc_acm
Aug 22 23:52:22 hostname kernel: [ 304.507897] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
Aug 22 23:52:22 hostname snapd[885]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug

And try connect/disconnect from btf-cfg :-1: No evolution.
I shall strace btf-cfg...

[haslinghuis]

See: https://techref.patronweb.com/io/2019/03/30/udev-rules-usb-io-serial.html

root@hostname:/etc/udev/rules.d# systemctl restart ModemManager.service ???

Did you use sudo apt remove modemmanager?

You need to use udevadm control --reload-rules && udevadm trigger without having to reboot,.

[innofocus]

following the logs I gave, I think my udev prevents ModemManager from acting here.
The problem is in usb_submit_urb that fails, may be because the device has gone ? too quickly ?

[haslinghuis]

Reboot?
(https://manpages.debian.org/testing/linux-manual-4.9/usb_submit_urb.9)

[innofocus]

the pc systematically finishes in hanging. so yes reboot is requiered to shoot again..

[haslinghuis]

I'm out of options. Reinstall from scratch?

[innofocus]

found this similar story :
https://forum.pjrc.com/threads/61675-Loader-crashes-Monitor-closed-Linux/page2?s=b0e95c4612f5daa9007c85f03a137308
and digging arround cdc_acm bugs :
https://bugzilla.kernel.org/buglist.cgi?quicksearch=cdc_acm

I'll try tomorow to compile btf-cfg with longer timing around disconnection.

[innofocus]

A hint before ending this journey :
when I plug the battery in the drone before usb connection, the entering/exiting from cli dont provoque the kernel oops bug !

It looks like rolling okay, but .. I'm experimenting other issues with other programs that hangs the pc next after and without logs unfortunately.
Also, btf-cfg con't connect the drone anymore untill program restarts... and finally another kernel oops :
Workqueue: usb_hub_wq hub_event .... RIP: 0033:0x7f2cd84cd3fb .. Code: Bad RIP value.

Ho! Damned ! Forgot to remove the battery before drawning it !
Blue Sky Of tha Drone...

[stale[bot]]

This issue / pull request has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within a week.

[stale[bot]]

Automatically closing as inactive.