[RP2040] First byte of X52 Pro HID report is zero, unless CFG_TUSB_DEBUG >= 2.

[TheAllTinker]

Operating System

Others

Board

RP2040-Zero

Firmware

Minimal example code which demonstrates my issue:

#include <stdlib.h>
#include "pico/stdlib.h"
#include "tusb.h"
#include "bsp/board.h"
void tuh_hid_mount_cb(uint8_t dev_addr, uint8_t instance, uint8_t const* desc_report, uint16_t desc_len) {
    tuh_hid_receive_report(dev_addr, instance);
}
void tuh_hid_umount_cb(uint8_t dev_addr, uint8_t instance) {
}
void tuh_hid_report_received_cb(uint8_t dev_addr, uint8_t instance, uint8_t const* report, uint16_t len) {
    for(uint32_t i = 0; i < len; ++i) {
        printf("%02X ", report[i]);
    }
    printf("\r\n");
    tuh_hid_receive_report(dev_addr, instance);
}
int main() {
    uart_init(uart0, 115200);
    gpio_set_function(0, GPIO_FUNC_UART);
    gpio_set_function(1, GPIO_FUNC_UART);
    uart_set_hw_flow(uart0, false, false);
    uart_set_format(uart0, 8, 1, UART_PARITY_NONE);
    uart_set_fifo_enabled(uart0, true);
    stdio_init_all();
    tusb_init();
    for(;;) {
        tuh_task();
        tight_loop_contents();
    }
    return 0;
}

The content of tusb_config.h is:

#define CFG_TUSB_MCU                OPT_MCU_RP2040
#define CFG_TUSB_RHPORT0_MODE       OPT_MODE_HOST
#define CFG_TUSB_MEM_ALIGN          TU_ATTR_ALIGNED(4)
#define CFG_TUSB_DEBUG              1 // 2 works

#define CFG_TUH_ENUMERATION_BUFSIZE 512
#define CFG_TUH_HUB                 1
#define CFG_TUH_DEVICE_MAX          4
#define CFG_TUH_HID                 4
#define CFG_TUH_HID_EPIN_BUFSIZE    64
#define CFG_TUH_HID_EPOUT_BUFSIZE   64

What happened ?

I'm trying to read data from USB joysticks/gamepads on the RP2040. Every other HID device I have tried has worked perfectly, except the Saitek/Logitech X52 Pro. Its HID reports are 15 bytes long, and the first byte of the report in tuh_hid_report_received_cb is always zero, which is not the expected result.

This is where it gets pretty strange:

1. If I set CFG_TUSB_DEBUG to 2, the first byte is now reported correctly.
2. If I detach stdio from the UART (i.e. preventing the actual printout of the debug messages), then it again stops working, even if CFG_TUSB_DEBUG >= 2.

Perhaps this indicates some kind of timing issue? I've been looking a bit at the TinyUSB code today, but I haven't noticed anything yet which might explain it; then again I'm not very familiar with deeper USB implementation details at present...

I have tried both 0.14.0 and the latest git commit with no change.

How to reproduce ?

The X52 Pro is the only device I've found which has the issue. I'm not sure if this is due to the large(?) report size, or some other factor. I'm providing separate +5V power to the joystick itself, and everything seems fine electrically.

Running the code I posted and using an X52 Pro (or perhaps a similarly complex HID joystick) may be the only way to reproduce...

Debug Log as txt file

When working (CFG_TUSB_DEBUG >= 2 and stdio output attached to UART), report log output is like so:

HID xfer callback
  Get Report callback (1, 0)
24 77 08 80 01 00 00 00 00 00 00 08 00 00 88 
  Queue EP 81 with 16 bytes ... OK
Buffer complete
on EP 81 with 15 bytes
HID xfer callback
  Get Report callback (1, 0)
C3 72 08 80 01 00 00 00 00 00 00 08 00 00 88 
  Queue EP 81 with 16 bytes ... OK
Buffer complete
on EP 81 with 15 bytes

When not working (CFG_TUSB_DEBUG < 2 or stdio output detached), log output is like this:

00 16 08 80 00 00 00 00 00 00 00 08 00 00 88 
00 12 08 80 01 00 00 00 00 00 00 08 00 00 88 

Screenshots

No response

I have checked existing issues, dicussion and documentation

• I confirm I have checked existing issues, dicussion and documentation.

[TheAllTinker]

Well, it's not a solution at all, but if I change the main loop in my test to be:

    for(;;) {
        tuh_task();
        sleep_ms(10);
    }

It appears to "work" without CFG_TUSB_DEBUG being set to 2 or higher... I haven't verified the actual data yet, but it looks vaguely how I'd expect it to.

This was after determining that the log line which seemed to affect the timing enough for things to work was in hidh_xfer_cb() (in class/hid/hid_host.c); specifically:

TU_LOG2("  Get Report callback (%u, %u)\r\n", dev_addr, instance);

Replacing that with sleep_ms(10); also "works".

I haven't made much progress on figuring out what the actual problem is beyond tracing out the code-path, but it's clearly affected by the timing of the callback. A buffer or value being overwritten/cleared with the wrong timing or... something?

[hathach]

• can you try with the stock example host/cdc_msc_hid to see if that works for you.
• Also please upload txt contain log=2 and log=1 as txt file for analysis as well.

[TheAllTinker]

OK tried that; exactly the same issue.

Here are the log reports from the cdc_msc_hid example, at three different debug levels - the last one so you can see the HID report bytes.

With each run I move the joystick in a way which should affect the first byte (containing part of the 10-bit X axis), but the first byte is always zero.

EDIT: Removed inline logs, attached as text files to next message.

Thanks for looking into it!

[hathach]

please ATTACHED log as txt file for readibitly

[TheAllTinker]

Sure, here you go:

debug-1.txt
debug-2.txt
debug-999.txt

EDIT: Here's another max debug one; plugging in the X52 Pro, taking the X/Y axes through their range, and then unplugging it. Stating the obvious but with this cdc_msc_hid test it seems the debug level doesn't matter - the first byte is always zero (or rarely 0xFF).
debug-999-full.txt

[FalcoPilgrim]

Setup : Logitech G940 ; rp2040 boards : raspberry pi pico & waveshare One ;
Adafruit teenyUSB port library on secondary USB port, teenyUSB native lib on main USB port.
120 & 240 Mhz. Code is example from lib.
First byte is always 0x01. Delay, sleep, DEBUG - no effects.
Only need - is last two bits in report[0x0000]

[XZCE]

dump.txt

This is a ShanWan (PS3) wireless controller, it configures EP 0x81 & 0x02 as 32 bytes longs, but by my calculations the HID report is 35 bytes long and I suspect those extra 3 bytes make the Pico's USB device hold the EP inactive...

Normally, it crashes the Pico on these assert &| panic lines (which I've disabled for this dump, because I don't want my Pico to crash if a user plugs in such a device, and in the logging it gets a bit further):

tinyusb/src/portable/raspberrypi/rp2040/hcd_rp2040.c

Lines 101 to 105 in 46f7cf4

	static void __tusb_irq_path_func(_handle_buff_status_bit)(uint bit, struct hw_endpoint *ep)
	{
	usb_hw_clear->buf_status = bit;
	// EP may have been stalled?
	assert(ep->active);

...and...

tinyusb/src/portable/raspberrypi/rp2040/rp2040_usb.c

Lines 338 to 346 in 46f7cf4

	bool __tusb_irq_path_func(hw_endpoint_xfer_continue)(struct hw_endpoint *ep)
	{
	hw_endpoint_lock_update(ep, 1);
	// Part way through a transfer
	if (!ep->active)
	{
	panic("Can't continue xfer on inactive ep %d %s", tu_edpt_number(ep->ep_addr), ep_dir_string[tu_edpt_dir(ep->ep_addr)]);
	}

With these lines enabled the log only gets as far as:

HID has 1 reports
Info: Found a Game Controller!
Queue DEV 1 EP 81 with 32 bytes ... hcd_edpt_xfer dev_addr 1, ep_addr 0x81, len 32
Prepare BufCtrl: [0] = 0x5420 [1] = 0x0000
OK
Buffer complete
buf_status 0x00000004

And the Pico dies. Commenting them out, I don't actually get a report, but the Pico doesn't crash and I can unplug the wireless dongle and plug it back in to see it go through the same setup process. Something is amiss.

[BillPlunkett]

@AllTinker-Lance, were you able to get this issue resolved?

[TheAllTinker]

@BillPlunkett - I'm afraid not; it's pretty much stalled my project. I never found a workaround which was consistent enough to use, and not enough time/domain expertise to track down the actual issue. 😞 I'm not aware of any alternative libraries for the Pico, so I'm pretty much stuck.

[BillPlunkett]

@hathach, could you please comment on this? This and some other host/hub issues seem to be stalled.

[hathach]

sorry, I don't manage to have time fixing my own issues as well and therefore haven't looked at this.