CircuitPython 9.0.3 Hard Faults when connected to KVM and enabling usb_hid

[braye]

CircuitPython version

Adafruit CircuitPython 9.0.3-dirty on 2024-04-10; SparkFun Pro Micro RP2040 with rp2040

Code/REPL

# code.py:

import board
import keypad
import busio
import usb_hid
from adafruit_hid.keyboard import Keyboard
from adafruit_hid.keycode import Keycode

#
# matrix/keymap setup
#
cols = [board.A1, board.A0, board.SCK, board.D20, board.D23, board.D21]
rows = [board.D5, board.D6, board.D7, board.D8, board.D9]
rowcol_map = {}
layer = 0

matrix = keypad.KeyMatrix(
    row_pins=rows,
    column_pins=cols,
)

print('Hello World!')

#
# main loop
#

kbd = Keyboard(usb_hid.devices)
i2c = busio.I2C(board.D3, board.D2)
while True:
    event = matrix.events.get()
    if event:
        print(event)

# boot.py:
import usb_hid
import board
import digitalio
import storage
import usb_cdc
import supervisor

supervisor.runtime.autoreload = False

row0 = digitalio.DigitalInOut(board.D5)
col0 = digitalio.DigitalInOut(board.A1)

row0.direction = digitalio.Direction.INPUT
col0.direction = digitalio.Direction.OUTPUT
col0.value = True

if row0.value:
     usb_cdc.enable()
     storage.enable_usb_drive()
     usb_hid.enable([usb_hid.Device.KEYBOARD])
else:
    usb_cdc.disable()
    storage.disable_usb_drive()
    usb_hid.enable([usb_hid.Device.KEYBOARD])

Behavior

Serial console setup
Adafruit CircuitPython 9.0.3-dirty on 2024-04-10; SparkFun Pro Micro RP2040 with rp2040
Board ID:sparkfun_pro_micro_rp2040
UID:E462D4644B52352B
boot.py output:
0;🐍Done | 9.0.3-dirty
Auto-reload is off.
code.py output:
0;🐍code.py | 9.0.3-dirtyHello World!
Serial console setup
safemode.py output:
0;🐍safemode.py | 9.0.3-dirty0;🐍Done | 9.0.3-dirty0;🐍Done | 9.0.3-dirty
Auto-reload is off.
Running in safe mode! Not running saved code.

You are in safe mode because:
CircuitPython core code crashed hard. Whoops!
Hard fault: memory access or instruction error.
Please file an issue with your program at github.com/adafruit/circuitpython/issues.
Press reset to exit safe mode.

Press any key to enter the REPL. Use CTRL-D to reload.

Description

No response

Additional information

As mentioned in the title, this hard fault only happens when I connect the board to the "HID" input of a Level1Techs KVM. I think that the KVM is misbehaving - I took a USB packet capture with a sniffer and it seems like the KVM makes an IN request before a SETUP request. I've attached two pcaps - one of the connection directly to a USB port on my computer, and one of the connection to the computer through the KVM.

The reason I think this is a CircuitPython bug is that I think that the board sends back a garbled ACK in response to the first IN packet. My wireshark skills are poor so I might be interpreting this incorrectly. The alternative is that the board is getting a garbled ACK. Regardless, a garbled ACK shouldn't be causing hard faults, I think.

The reason that the version is dirty is that I needed to enable the REPL/console over UART pins. This is because the KVM didn't like exposing the CDC console and mass storage endpoints over its HID connection.

I set:

#define CIRCUITPY_CONSOLE_UART_RX (&pin_GPIO17)
#define CIRCUITPY_CONSOLE_UART_TX (&pin_GPIO16)

To output the console over the qwiic connector.

Here are the pcaps: captures.zip

[tannewt]

Since you setup the UART already, try setting CIRCUITPY_DEBUG_TINYUSB to 3. That will log USB activity from the device side.

[braye]

Sure thing, here's the output of the terminal with that option enabled. This one crashed real quick - usually it takes a couple seconds. minicom.txt

[braye]

Here's one that took an average amount of time: minicom.txt

[tannewt]

Looks like the crash is in a similar place. Unfortunately it doesn't show exactly where. A debugger would allow to you to catch the hard fault and (hopefully) get a backtrace. It'll be hard for me to reproduce if it requires your specific kvm.

[braye]

Breakpoint 5, HardFault_Handler () at supervisor/port.c:321
321         if (get_core_num() == 0) {
(gdb) backtrace
#0  HardFault_Handler () at supervisor/port.c:321
#1  <signal handler called>
#2  0x1003059a in tud_hid_set_report_cb (itf=itf@entry=0 '\000', 
    report_id=report_id@entry=0 '\000', 
    report_type=report_type@entry=HID_REPORT_TYPE_INVALID, 
    buffer=0x200097b9 <_hidd_itf+73> "", buffer@entry=0x200097b8 <_hidd_itf+72> "", 
    bufsize=63) at ../../shared-module/usb_hid/Device.c:313
#3  0x1002f7fe in hidd_xfer_cb (rhport=0 '\000', ep_addr=<optimized out>, 
    result=<optimized out>, xferred_bytes=<optimized out>)
    at ../../lib/tinyusb/src/class/hid/hid_device.c:408
#4  0x1002dae2 in tud_task_ext (timeout_ms=timeout_ms@entry=4294967295, 
    in_isr=in_isr@entry=false) at ../../lib/tinyusb/src/device/usbd.c:531
#5  0x1002ecfa in tud_task () at ../../lib/tinyusb/src/device/usbd.h:54
#6  usb_background () at ../../supervisor/shared/usb/usb.c:170
#7  usb_background () at ../../supervisor/shared/usb/usb.c:167
#8  usb_background_do (unused=<optimized out>) at ../../supervisor/shared/usb/usb.c:194
#9  0x2000681c in background_callback_run_all ()
    at ../../supervisor/shared/background_callback.c:102
#10 0x2000583a in mp_execute_bytecode (code_state=code_state@entry=0x2000ce00, 
    inject_exc=inject_exc@entry=0x0) at ../../py/vm.c:1352
#11 0x20005172 in fun_bc_call (self_in=0x2000d540, n_args=0, n_kw=0, args=0x0)
    at ../../py/objfun.c:273
#12 0x1001268c in mp_call_function_n_kw (n_kw=0, args=0x0, n_args=0, fun_in=0x2000d540)
    at ../../py/runtime.c:725
#13 mp_call_function_0 (fun=fun@entry=0x2000d540) at ../../py/runtime.c:699
#14 0x10076be2 in parse_compile_execute (result=0x20009738 <_exec_result>, exec_flags=32, 
    input_kind=MP_PARSE_FILE_INPUT, source=<optimized out>)
    at ../../shared/runtime/pyexec.c:152
#15 pyexec_file (filename=<optimized out>, result=result@entry=0x20009738 <_exec_result>)
    at ../../shared/runtime/pyexec.c:759
#16 0x1002a178 in maybe_run_list (filenames=<optimized out>, n_filenames=<optimized out>)
    at ../../main.c:310
#17 maybe_run_list (filenames=<optimized out>, n_filenames=<optimized out>)
    at ../../main.c:294
#18 0x1002acae in run_code_py (simulate_reset=<synthetic pointer>, safe_mode=SAFE_MODE_NONE)
    at ../../main.c:489
#19 main () at ../../main.c:1112

I think I grabbed this backtrace from the right place? Not sure what I should be looking for.

[dhalbert]

@hathach This may be of interest to you.

[dhalbert]

@braye I looked at the stack trace and thought that perhaps something was being set up incorrectly or not set up. Here is a UF2 that has some logging printouts in tud_hid_set_report_cb() and also has CIRCUITPY_CONSOLE_UART... set up as you did. Could you try this and send the output? Thanks very much. This is build on 9.1.0-beta.2.

[wrong file]

[braye]

@dhalbert , I think this firmware was built for the wrong board. I'm using the sparkfun_pro_micro_rp2040, and it looks like this was built for the sparkfun_micromod_rp2040. It throws an error about referencing board.NEOPIXEL when I flash it to my device.

[dhalbert]

Whoops, sorry! That was a copy/paste error. Here is a build for sparkfun_pro_micro_rp2040: logging-sparkfun_pro_micro_rp2040.uf2.zip

[braye]

Thanks for the quick response! Some bad news, though... With this firmware it's not hard faulting at all when plugged into the KVM! I've had it plugged in for about 15 minutes at this point with no issues at all. It's not quite working correctly but that was the case beforehand, so I think that's unrelated to the crashes I was experiencing.

Oddly, I'm also not seeing any output besides the normal output from boot.py and code.py. Not sure if that's what you would expect.

[dhalbert]

Hmm, I'm not sure if this is a Heisenbug or something else. Could you try the regular 9.1.0-beta.3 build for your board and see if it makes any difference? I see you were testing with 9.0.3, and there have been various changes since then, including an update to TinyUSB.

[braye]

It definitely seems to be the case that 9.0.5 exhibits the crashing behavior, and 9.1.0-beta.3 does not. (both your version and the version hosted on circuitpython.org)

[dhalbert]

OK, sounds great! I'll declare this "fixed" in 9.1.0. I hope that works for you, and that the KVM is usable now.

[braye]

Not crashing is enough for me :) Thanks for the help!