drivers/usb/device/usb_dc_native_posix_adapt.c sees weird commands and aborts

[holgerschurig]

Describe the bug
After applying a local modifcation to fix #29034, I tried CDC ACM and had partial success:

• I saw the device appear in the Linux dmesg
• I could "usbip attach"
• a /dev/ttyACM0 appeard and
• I could open it

But sending "a" followed by enter using a simple terminal program ("picocom") showed an error in the dmesg log.

To Reproduce

1. cd samples/subsys/usb/cdc_acm
2. sed -i '/CONFIG_GPIO/d' prj.conf
3. west build --pristine -b native_posix
4. build/zephyr/zephyr.elf
5. usbip attach -r localhost -b 1-1
6. picocom /dev/ttyACM0

So far so good, this is the relevant output from dmesg:

[ 7537.211068] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
[ 7537.211072] vhci_hcd vhci_hcd.0: devid(65538) speed(2) speed_str(full-speed)
[ 7537.384598] vhci_hcd: vhci_device speed not set
[ 7537.444575] usb 3-1: new full-speed USB device number 13 using vhci_hcd
[ 7537.604578] vhci_hcd: vhci_device speed not set
[ 7537.664584] usb 3-1: SetAddress Request (13) to port 0
[ 7538.792701] usb 3-1: New USB device found, idVendor=2fe3, idProduct=0001, bcdDevice= 2.04
[ 7538.792704] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 7538.792705] usb 3-1: Product: Zephyr CDC ACM sample
[ 7538.792706] usb 3-1: Manufacturer: ZEPHYR
[ 7538.792707] usb 3-1: SerialNumber: 0123456789ABCDEF
[ 7538.860285] cdc_acm 3-1:1.0: ttyACM0: USB ACM device

7. pressing "a" and ENTER
8. Error in dmesg:

[ 7638.630238] vhci_hcd: connection reset by peer
[ 7638.630260] vhci_hcd: stop threads
[ 7638.630262] vhci_hcd: release socket
[ 7638.630265] vhci_hcd: disconnect device
[ 7638.630301] usb 3-1: USB disconnect, device number 13
[ 7638.630348] cdc_acm 3-1:1.0: failed to set dtr/rts

I then tried to debug this further. I added these two lines to prj.conf and changes some debug log calls into warning calls:

@@ -10,3 +9,5 @@ CONFIG_USB_DEVICE_LOG_LEVEL_ERR=y
 CONFIG_SERIAL=y
 CONFIG_UART_INTERRUPT_DRIVEN=y
 CONFIG_UART_LINE_CTRL=y
+CONFIG_LOG_BACKEND_UART=n
+CONFIG_LOG_BACKEND_NATIVE_POSIX=y

After a rebuild, this can be seen:

$ build/zephyr/zephyr.elf 
UART_0 connected to pseudotty: /dev/pts/2
*** Booting Zephyr OS build zephyr-v2.4.0-388-g5bda586c64ae  ***
[00:00:00.000,000] <inf> cdc_acm_echo: Wait for DTR
[00:00:08.470,000] <inf> usb_cdc_acm: Device configured
[00:00:13.200,000] <inf> cdc_acm_echo: DTR set
[00:00:14.310,000] <inf> cdc_acm_echo: Baudrate detected: 9600
[00:00:15.400,000] <err> native_posix_adapt: Unknown command: 0xe5000100

Expected behavior
I expect the simulated serial port to not crash :-)

Environment (please complete the following information):

• OS: Linux, Kernel 4.19.0-11-686-pae from Debian Buster (Debian package " linux-image-4.19.0-10-686-pae", version "4.19.132-1")
• Toolchain: native, from Debian Buster (gcc version: "gcc (Debian 8.3.0-6) 8.3.0")
• Zephyr from git HEAD

[github-actions]

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.