search

zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.51k stars 6.44k forks source link

LPC55xx USB not working with SPEED_OPTIMIZATIONS=y #78268

Closed maximevince closed 1 day ago

maximevince commented 1 week ago

Describe the bug When using the USB stack on an LPC55x16, the USB device does not enumerate on the host, when using SPEED_OPTIMIZATIONS=y (gcc -O2 flag)

To Reproduce Steps to reproduce the behavior:

  1. cd zephyr/samples/subsys/usb/cdc_acm
  2. echo "CONFIG_SPEED_OPTIMIZATIONS=y" >> speedopt.conf
  3. west build -p always -b lpcxpresso55s16 -- -DEXTRA_CONF_FILE=speedopt.conf
  4. west flash
  5. No USB device shows up on the host

Expected behavior USB device enumerates and shows up on the host. E.g. when building the same cdc_acm sample without speed optimizations:

[169450.377321] usb 3-4.3: new high-speed USB device number 86 using xhci_hcd
[169450.469603] usb 3-4.3: New USB device found, idVendor=2fe3, idProduct=0001, bcdDevice= 3.07
[169450.469607] usb 3-4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[169450.469609] usb 3-4.3: Product: Zephyr CDC ACM sample
[169450.469610] usb 3-4.3: Manufacturer: ZEPHYR
[169450.469612] usb 3-4.3: SerialNumber: AB7FB49B66CBCA73

Impact Cannot use the speed optimizations in my application, which are crucial to get good performance.

Environment (please complete the following information):

maximevince commented 1 week ago

I got some additional context for the cdc_acm sample app:

When running with SPEED_OPTIMIZATIONS=y, the log gets stuck at cdc_acm_echo: Wait for DTR:

*** Booting Zephyr OS build v3.7.0-2536-gccc4357f0a2c ***
[00:00:00.000,000] <dbg> usb_device: usb_enable: lock usb_enable_lock mutex
[00:00:00.000,000] <dbg> usb_descriptor: usb_get_device_descriptor: __usb_descriptor_start 0x20002480
[00:00:00.000,000] <dbg> usb_descriptor: usb_get_device_descriptor: __usb_descriptor_end 0x2000253f
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Device descriptor 0x20002480
[00:00:00.000,000] <dbg> usb_descriptor: usb_desc_update_mps0: Set bMaxPacketSize0 64
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Configuration descriptor 0x20002492
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Association descriptor 0x2000249b
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Interface descriptor 0x200024a3
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024bf
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 80 -> 81
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x81
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Interface descriptor 0x200024c6
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024cf
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 80 -> 82
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x82
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024d6
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x1
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Now the wTotalLength is 75
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 11, ascii_idx_max 5, buf 0x200024e3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char R : 52, idx 5 -> 11
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Y : 59, idx 4 -> 9
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char H : 48, idx 3 -> 7
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char P : 50, idx 2 -> 5
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char E : 45, idx 1 -> 3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Z : 5a, idx 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 41, ascii_idx_max 20, buf 0x200024f1
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char e : 65, idx 20 -> 41
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char l : 6c, idx 19 -> 39
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char p : 70, idx 18 -> 37
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char m : 6d, idx 17 -> 35
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char a : 61, idx 16 -> 33
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char s : 73, idx 15 -> 31
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 14 -> 29
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char M : 4d, idx 13 -> 27
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 12 -> 25
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 11 -> 23
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 10 -> 21
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 9 -> 19
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char D : 44, idx 8 -> 17
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 7 -> 15
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 6 -> 13
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char r : 72, idx 5 -> 11
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char y : 79, idx 4 -> 9
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char h : 68, idx 3 -> 7
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char p : 70, idx 2 -> 5
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char e : 65, idx 1 -> 3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Z : 5a, idx 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: usb_update_sn_string_descriptor: Serial Number
                                         ab 7f b4 9b 66 cb ca 73                          |....f..s         
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 31, ascii_idx_max 15, buf 0x2000251d
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 3 : 33, idx 15 -> 31
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 14 -> 29
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 13 -> 27
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 12 -> 25
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 11 -> 23
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 10 -> 21
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 6 : 36, idx 9 -> 19
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 6 : 36, idx 8 -> 17
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 7 -> 15
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 9 : 39, idx 6 -> 13
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 4 : 34, idx 5 -> 11
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 4 -> 9
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char F : 46, idx 3 -> 7
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 2 -> 5
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 1 -> 3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 0 -> 1
[00:00:00.000,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x81
[00:00:00.001,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x1
[00:00:00.001,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x82
[00:00:00.001,000] <dbg> usb_device: usb_enable: unlock usb_enable_lock mutex
[00:00:00.001,000] <inf> cdc_acm_echo: Wait for DTR

When building without speed optimizations, the full boot + enumeration looks like this:

*** Booting Zephyr OS build v3.7.0-2536-gccc4357f0a2c ***
[00:00:00.000,000] <dbg> usb_device: usb_enable: lock usb_enable_lock mutex
[00:00:00.000,000] <dbg> usb_descriptor: usb_get_device_descriptor: __usb_descriptor_start 0x20002480
[00:00:00.000,000] <dbg> usb_descriptor: usb_get_device_descriptor: __usb_descriptor_end 0x2000253f
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Device descriptor 0x20002480
[00:00:00.000,000] <dbg> usb_descriptor: usb_desc_update_mps0: Set bMaxPacketSize0 64
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Configuration descriptor 0x20002492
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Association descriptor 0x2000249b
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Interface descriptor 0x200024a3
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024bf
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 80 -> 81
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x81
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Interface descriptor 0x200024c6
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024cf
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 80 -> 82
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x82
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Endpoint descriptor 0x200024d6
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: Fixing EP address 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: usb_validate_ep_cfg_data: endpoint 0x1
[00:00:00.000,000] <dbg> usb_descriptor: usb_fix_descriptor: Now the wTotalLength is 75
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 11, ascii_idx_max 5, buf 0x200024e3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char R : 52, idx 5 -> 11
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Y : 59, idx 4 -> 9
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char H : 48, idx 3 -> 7
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char P : 50, idx 2 -> 5
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char E : 45, idx 1 -> 3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Z : 5a, idx 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 41, ascii_idx_max 20, buf 0x200024f1
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char e : 65, idx 20 -> 41
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char l : 6c, idx 19 -> 39
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char p : 70, idx 18 -> 37
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char m : 6d, idx 17 -> 35
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char a : 61, idx 16 -> 33
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char s : 73, idx 15 -> 31
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 14 -> 29
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char M : 4d, idx 13 -> 27
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 12 -> 25
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 11 -> 23
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 10 -> 21
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 9 -> 19
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char D : 44, idx 8 -> 17
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 7 -> 15
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char   : 20, idx 6 -> 13
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char r : 72, idx 5 -> 11
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char y : 79, idx 4 -> 9
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char h : 68, idx 3 -> 7
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char p : 70, idx 2 -> 5
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char e : 65, idx 1 -> 3
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char Z : 5a, idx 0 -> 1
[00:00:00.000,000] <dbg> usb_descriptor: usb_update_sn_string_descriptor: Serial Number
                                         ab 7f b4 9b 66 cb ca 73                          |....f..s         
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: idx_max 31, ascii_idx_max 15, buf 0x2000251d
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 3 : 33, idx 15 -> 31
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 14 -> 29
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 13 -> 27
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 12 -> 25
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 11 -> 23
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 10 -> 21
[00:00:00.000,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 6 : 36, idx 9 -> 19
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 6 : 36, idx 8 -> 17
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 7 -> 15
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 9 : 39, idx 6 -> 13
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 4 : 34, idx 5 -> 11
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 4 -> 9
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char F : 46, idx 3 -> 7
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 2 -> 5
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 1 -> 3
[00:00:00.001,000] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 0 -> 1
[00:00:00.001,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x81
[00:00:00.001,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x1
[00:00:00.001,000] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x82
[00:00:00.001,000] <dbg> usb_device: usb_enable: unlock usb_enable_lock mutex
[00:00:00.001,000] <inf> cdc_acm_echo: Wait for DTR
[00:00:00.264,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.264,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:00.264,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.264,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.264,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.337,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.337,000] <dbg> usb_device: custom_handler: bRequest 0x05, wIndex 0x0000
[00:00:00.337,000] <dbg> usb_device: usb_handle_std_device_req: Set Address 9 request
[00:00:00.337,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.354,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:00.354,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.354,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:00.354,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.354,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:00.354,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.354,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.355,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:00.355,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.355,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:00.355,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.355,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:00.355,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.355,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.355,000] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:00.355,000] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:00.356,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.356,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.408,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.408,000] <dbg> usb_device: custom_handler: bRequest 0x09, wIndex 0x0000
[00:00:00.408,000] <dbg> usb_device: usb_set_configuration: Set Configuration 1 request
[00:00:00.408,000] <dbg> usb_device: set_endpoint: Set endpoint 0x81 type 3 MPS 16
[00:00:00.408,000] <dbg> usb_device: set_endpoint: Set endpoint 0x82 type 2 MPS 512
[00:00:00.408,000] <dbg> usb_device: set_endpoint: Set endpoint 0x1 type 2 MPS 512
[00:00:00.408,000] <inf> usb_cdc_acm: Device configured
[00:00:00.408,000] <wrn> cbprintf_package: (unsigned) char * used for %p argument. It's recommended to cast it to void * because it may cause misbehavior in certain configurations. String:"%s: Transfer start, ep 0x%02x, data %p, dlen %zd" argument:2
[00:00:00.408,000] <dbg> usb_transfer: usb_transfer: Transfer start, ep 0x01, data 0x2000210c, dlen 512
[00:00:00.408,000] <wrn> cbprintf_package: (unsigned) char * used for %p argument. It's recommended to cast it to void * because it may cause misbehavior in certain configurations. String:"%s: Transfer start, ep 0x%02x, data %p, dlen %zd" argument:2
[00:00:00.408,000] <dbg> usb_transfer: usb_transfer: Transfer start, ep 0x82, data 0, dlen 0
[00:00:00.408,000] <dbg> usb_transfer: usb_transfer_work: Transfer ZLP
[00:00:00.409,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.409,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.409,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.409,000] <dbg> usb_device: class_handler: bRequest 0x20, wIndex 0x0000
[00:00:00.409,000] <dbg> usb_device: usb_handle_control_transfer: >> usb_data_to_host(2)
[00:00:00.409,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.579,000] <dbg> usb_transfer: usb_transfer_work: Transfer done, ep 0x82, status 0, size 0
[00:00:00.579,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.579,000] <dbg> usb_device: class_handler: bRequest 0x22, wIndex 0x0000
[00:00:00.579,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.580,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:00.580,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x01
[00:00:00.580,000] <dbg> usb_device: class_handler: bRequest 0x20, wIndex 0x0000
[00:00:00.580,000] <dbg> usb_device: usb_handle_control_transfer: >> usb_data_to_host(2)
[00:00:00.580,000] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:00.601,000] <inf> cdc_acm_echo: DTR set
[00:00:00.796,000] <inf> cdc_acm_echo: Baudrate 115200
maximevince commented 6 days ago

Meanwhile I have found out that it's specifically the -fschedule-insns GCC optimization flag that's causing this issue. (https://gcc.gnu.org/onlinedocs/gcc/Optimize-Options.html#index-fschedule-insns)

Sounds like some instructions are getting reordered, which shouldn't be for the hardware to function (no USB interrupts are being generated, apart from the very first one).

maximevince commented 6 days ago

Narrowed it down to soc/nxp/lpc/lpc55xxx/soc.c

This is a workaround by patching soc/nxp/lpc/lpc55xxx/CMakeLists.txt, although I am still unsure what exactly inside of soc.c is causing the issue:

diff --git a/soc/nxp/lpc/lpc55xxx/CMakeLists.txt b/soc/nxp/lpc/lpc55xxx/CMakeLists.txt
index 4dae5afa7ee..e53408bdf57 100644
--- a/soc/nxp/lpc/lpc55xxx/CMakeLists.txt
+++ b/soc/nxp/lpc/lpc55xxx/CMakeLists.txt
@@ -7,6 +7,9 @@ zephyr_library()

 zephyr_library_sources(soc.c)

+# THIS FIXES THE USB ENUMERATION ISSUE WHEN USING SPEED_OPTIMIZATIONS=y (-O2)
+zephyr_library_compile_options(-fno-schedule-insns)
+
 zephyr_library_include_directories(
   ${ZEPHYR_BASE}/kernel/include
   ${ZEPHYR_BASE}/arch/${ARCH}/include
maximevince commented 5 days ago

Fixed here: https://github.com/zephyrproject-rtos/zephyr/pull/78377