fix(native-usb): service masked completions and trace startup stalls

Keep native backend locking IRQ-permitting and service USB hardware from SRAM during BOOTSEL sampling. Add bounded input/control flight recording, root IN and EP0 snapshots, and masked-window handoff coverage. Record PC qualification and the remaining Switch stability limitations.
This commit is contained in:
Joey Yakimowich-Payne 2026-09-14 13:55:35 -06:00
commit d424fe0f4a
12 changed files with 884 additions and 195 deletions

140
README.md
View file

@ -966,7 +966,7 @@ Select the Wii profile owner and its active profile. With the Nunchuk connected,
Auto uses its live layout; while offline, choose **Preview · Wii Remote + Nunchuk**.
The physical Nunchuk **C** is logical `west` and **Z** is logical `north`, not the
unrelated Switch2 extra control named `c`. Both can target buttons or triggers.
For example, **Z → L**, **C → ZL**, with **Remote 2 → R**, makes **Z + 2** the
For example, **C → L**, **Z → ZL**, with **Remote 2 → R**, makes **C + 2** the
physical L+R combination. Save changes to that Wii profile, not the global
default or another controller's profile.
@ -977,11 +977,12 @@ cannot borrow child EP0 buffers; aborted/short/corrupt transfers and reset-stale
status completions cannot dispatch profile writes. Valid status ACKs preceding
a subsequent SETUP remain valid.
Qualification: 390 focused tests pass. The actual browser editor saved the
Wii C/Z example and read it back after a Pico reboot. All 80 stored profiles
were compared: only the two intended mappings changed; the other 79 profiles,
metadata and active selections were unchanged. The configuration/pairing flash
region matched the pre-update backup. Native R/L descriptors, EP0 identity,
Qualification: 390 focused tests pass. The earlier browser save/readback check
used the reverse C/Z example (**C → ZL, Z → L**); that test configuration must
not be mistaken for the requested **C → L, Z → ZL** mapping above. All 80 stored
profiles were compared: only those two mapping fields changed; the other 79
profiles, metadata and active selections were unchanged. The configuration/pairing
flash region matched the pre-update backup. Native R/L descriptors, EP0 identity,
initialization and bulk-isolation checks passed while editor traffic was active.
No physical Switch L+R button press was claimed by that transport check.
@ -1047,8 +1048,131 @@ packets and 149,567 L packets, including 113,316 and 114,276 fresh IMU packets.
USBmon measured overlapping child reads during 94.4% of the steady-state window
with no failed read completions there and no capture drops. A subsequent
15-second mixed control/bulk/input check passed 57 rounds with no errors.
This confirms the PC starvation reproduction is corrected. The user's subsequent
Switch gameplay trial also stopped reproducing the L+R disconnect.
This confirms the PC starvation reproduction is corrected. An initial Switch
trial appeared successful, but a longer run subsequently disconnected after
roughly 236,000 R / 234,000 L input reports. Bluetooth reports and USB SOF
continued while input and addressed-token counters stopped, without USB error
flags. An additional right-side firmware-version request and endpoint-halt clear
were observed. Extended Switch stability remains unresolved. Concurrent HID
polling with interleaved version reads reproduced `EPROTO` on `0.78` after about
140 seconds (`c1/02`, interface 1, requested length 64).
A synchronous shared-EP0-copy trial (`0.79`) also failed a version read after
about 17 seconds and recorded late bank switches. The trial was rejected and
the exact `0.78` image restored, with saved data, pairing inventory and profile
selections verified unchanged. A subsequent xHCI trace reproduced the failure
after 111 seconds and located USB transaction error completion code 4 on the
right controller's final OUT status-stage descriptor, not its data-stage
descriptor (`c0/02`, requested length 16). This narrows the missing handshake but
does not distinguish a missed status token, bank/IRQ handoff delay, or malformed
response. No further timing change is qualified by these results; failure-time
device-state or direct USB-wire capture is still needed.
**Flight recorder (since diagnostic 0.83):** trace-enabled hub builds retain 64 completed
records in a 65-slot SRAM ring. They record OUT selections and rejected IN/SETUP
selections; 0.87 additionally records successful root-hub IN selections. The
failure hook runs only after the original selector rejects the token. Records
include PID, address/owner, physical EP0 buffer controls, selection reason, raw
SIE state, IRQ timestamps and the Core 0 execution phase.
`pre=0` marks unavailable pre-selection observations rather than inferred values.
Phase values identify main-loop work; `0x10000 | line` identifies a held backend
state-lock region by source line in `bluepad32_input_backend.cpp`.
These are execution breadcrumbs, not a sampled program counter. The phase tags
do not change lock scope, but their instrumentation adds overhead.
After 200 ms without child IN completions following first input, the recorder
freezes and emits `HUB_FLIGHT_FREEZE`, `HUB_FLIGHT_CONTEXT`, `HUB_FLIGHT` and
`HUB_FLIGHT_END` over UART, at most one line per 50 ms. Since 0.87, a pending
control transfer with no generation/stage/position progress for 200 ms also
triggers a dump, even before input starts. `HUB_FLIGHT_CONTROL` adds the stalled
request, expected first data word and physical EP0 word/buffer state; records
also include the physical EP0 first word. Rearming requires the dump to finish
and fresh input or control progress. It never resets USB or changes selection
decisions. Logger-mask
measurements include instrumentation overhead, and hardware snapshots are not
atomic. Ordinary non-trace builds retain the 0.78 transport.
The initial 0.80 recorder selected IN rather than OUT; those logs are not OUT
evidence. Independently encoded PID checks corrected this in 0.81. Its two mixed
test failures were located in the IN data stage, so 0.82 adds rejected-IN/SETUP
coverage. Ring retention, freeze/rearm and dispatch smoke checks, both native
builds and 14 transport regressions pass; the 0.82 recorder also passed an
on-device initialization/poll/quiet-dump smoke. This is diagnostic instrumentation,
not a qualified fix for the remaining control-transfer failure.
The 0.83 concurrent-input/version-read capture failed after 15.8 seconds in the
left controller's OUT status stage (xHCI completion code 4). Four rejected tokens
spanned 30.7 microseconds with EP1 IN completion pending and unchanged USB IRQ
timestamps. All four carried `phase=00010fee`: the state-lock section beginning
at line 4078 of that build's `platform_on_controller_data()`. The phase identifies
the held critical section, not an individual instruction within it.
The 0.84 trial moves native/Wii parser snapshot reads, extra-button reads and
report-time calculation outside that interrupt-masked section. Shared-state
updates remain locked; USB bank-selection and recovery behavior are unchanged.
The concurrent USB test nevertheless failed after 34.0 seconds in the right
controller's IN data stage (xHCI completion code 4, all 16 bytes outstanding).
The final rejected tokens still showed pending EP1 completion and the
controller-data lock, now at line 4106. This trial did not qualify.
The 0.85 trial keeps a spin lock for native-hub backend state without changing
the caller's interrupt mask. Its entry point enforces Core 0 foreground access:
the hub uses the SDK's polled Bluetooth context, and USB IRQ/Core1 routing never
access backend state or dispatch protocol callbacks. Ordinary AIO retains its
interrupt-masking critical section. USB bank locking and intentionally masked
control-status commits are unchanged. A held backend phase tag therefore no
longer implies masked interrupts. Both native builds, AIO and eight focused
backend/transport test cases pass; on-device backend snapshots return real
Wii/Nunchuk motion. The concurrent test still failed after 43.3 seconds, now in
the protocol phase rather than under the backend lock: left IN data failed with
16 bytes outstanding and three rejected tokens spanning 18.35 microseconds.
The 0.86 trial addresses another masked interval in that phase: the 100 ms
BOOTSEL poll's flash-safe QSPI-CS settling loop. Interrupts remain disabled and
the 1000-iteration loop is retained, but each iteration services pending native
USB hardware status through an SRAM-only helper. It queues events without
dispatching protocol callbacks or changing NVIC pending state. The IRQ's
variable-length SRAM copy no longer calls flash-backed `memcpy`; linked trace
and non-trace call graphs contain no flash-backed calls in the sampler/IRQ path.
Nine focused tests pass, including real transport-fixture bank handoff while
interrupts remain masked and deferred completion dispatch. Native trace,
native non-trace and AIO builds pass.
**0.86 PC qualification:** the original concurrent R/L HID plus device-recipient
version-read reproduction passed 600 seconds: 2,400 control reads and
149,139 R / 149,204 L active-phase HID reads, with no reported errors.
The complete usbmon capture contains 601,718 records with zero capture drops.
Its steady-state window shows 93.98% simultaneous pending R/L reads, no HID
completion errors, and a maximum per-side completion gap below 8.07 ms.
The xHCI trace is a rolling buffer and lost older events; it is not complete-run
evidence. A subsequent 60-second matrix passed all 240 queries across both sides,
requested lengths 1/7/16/32/64 and device/interface-0/interface-1 recipients
(30 variants, eight queries each), while HID reads remained concurrent.
Captures are `usb-sram-0.86-A.*` and `usb-matrix-0.86-B.*` in the ignored native
gamepad build directory.
**0.86 Switch qualification failed at startup:** the root hub and right child
configured at addresses 5 and 6, but neither native protocol initialized and the
left child never acquired an address. Bluetooth reports continued. The last
root transaction was `a3/00`, port 2, length 4, following the port-reset ACK:
generation 39 armed `11010000` with DATA1, but no data completion followed.
The root remained in DATA_IN at position 0/4. This is an enumeration failure,
not a passed gameplay test; the PC result does not qualify console operation.
Startup trace and state are preserved as `switch-0.86-enumeration-*` in the
ignored native gamepad build directory. The existing recorder requires prior
child input, so it did not produce a flight dump for this startup failure.
The 0.87 enumeration recorder addresses that diagnostic blind spot, not the
underlying startup failure. Its pre-input timeout, root-IN recording, expected
versus physical data distinction, progress tracking and rearm smoke checks pass,
as do 11 transport/protocol regressions and both native plus AIO builds. Linked
critical paths remain in SRAM. Non-trace firmware remains at 0.86.
A subsequent 0.87 Switch startup configured and initialized both native
controllers, and the user confirmed working input. The startup trace is retained
as `switch-0.87-startup-uart.txt` in the ignored build directory. Instrumentation
changes timing; this successful run does not establish the startup failure's
root cause or qualify extended Switch gameplay.
For sensorless hardware, the checker supports `--input-only`: press real buttons
and keep changing controls on both halves during the run. Neutral fallback

File diff suppressed because it is too large Load diff

View file

@ -8,6 +8,9 @@
#if PICO_RP2350
#include "hardware/regs/sio.h"
#endif
#if SWITCH2_PROBE_HUB
#include "usb/native_hub/native_hub.h"
#endif
namespace {
@ -34,6 +37,12 @@ void __no_inline_not_in_flash_func(read_bootsel_callback)(void* parameter) {
IO_QSPI_GPIO_QSPI_SS_CTRL_OEOVER_BITS);
for (volatile uint32_t delay = 0; delay < 1000; ++delay) {
#if SWITCH2_PROBE_HUB
// Keep flash safety and the original settling delay, but do not leave
// USB completions pending throughout it. This helper is SRAM-only and
// dispatches no protocol/Bluetooth callbacks.
native_hub_service_pending_usb();
#endif
}
#if PICO_RP2350

View file

@ -101,6 +101,69 @@ static uint32_t token_hits[DEVICES], missed_lock, blocked_buffers, blocked_sie,
static uint16_t root_string[64];
static char root_serial[48];
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
#define OUT_TRACE_SLOTS 65u
#define OUT_TRACE_RETAIN 64u
#define OUT_TRACE_STALL_US 200000u
#define OUT_TRACE_LINE_US 50000u
enum {
OUT_TRACE_LOCK = 1u,
OUT_TRACE_BUFFERS = 2u,
OUT_TRACE_SETUP = 4u,
OUT_TRACE_GUARD = 8u,
OUT_TRACE_INVALID = 16u,
};
typedef struct {
uint32_t cursor, cutoff, clock_before, clock_after, sof;
uint32_t address_before, address_after, in0, out0, buffers, sie, sm, ints;
uint32_t blocked_buffers, blocked_sie, missed_lock, irq_enter, irq_exit, core0_phase;
uint32_t ep0_word;
uint8_t address, owner, owner_before, owner_after, selected, reason, pid, before_valid;
} out_trace_record_t;
typedef struct {
uint32_t time_us, quiet_us, cursor, count, input[2], cycle, sof;
uint32_t address, owner, out0, buffers, sie, sm, ints, intr, inte;
uint32_t tx_error, rx_error, irq_enter, irq_exit, core0_phase;
uint32_t log_max_us, log_max_us_bytes, log_max_bytes, log_nested;
uint32_t control_slot, control_generation, control_stage, control_position, control_length;
uint32_t control_word, in0, ep0_word;
tusb_control_request_t control_request;
} out_trace_header_t;
// All producer state is ordinary SRAM/BSS. Only Core1 writes the records.
// Cursor low 7 bits name the NEXT slot (0..64); upper bits count ring laps.
// Skipping unused low-bit values keeps each publication monotonic without a
// division on Core1, and slot adjacency survives uint32_t generation rollover.
// Freeze and cursor accesses below are SC (publication includes release,
// snapshot includes acquire). In their common total order, a producer's final
// freeze=false load precedes Core0's freeze=true store. Every earlier record
// has already been published, and at most that one iteration can still write.
// Core0 therefore reads only the 64 slots BEFORE its acquired cursor, never
// the possible in-flight 65th slot. Ordinary record reads/writes cannot race.
// No rearm occurs until the dump reader has finished; cursors are never reset.
static out_trace_record_t out_trace_records[OUT_TRACE_SLOTS];
static uint32_t out_trace_cursor, out_trace_frozen;
static uint32_t out_trace_irq_enter, out_trace_irq_exit;
static uint32_t out_trace_last_missed_lock; // Core1, updated after every rejected selection.
static uint32_t out_trace_core0_phase;
// Core0 alone owns logger metrics and dump/IN-progress state. IRQ code never
// logs, and Core1 does not read these fields, so they need no cross-core atomics.
static uint32_t out_trace_log_max_us, out_trace_log_max_us_bytes;
static uint32_t out_trace_log_max_bytes, out_trace_log_nested;
static out_trace_header_t out_trace_header;
static uint32_t out_trace_input[2], out_trace_last_input_us, out_trace_last_line_us;
static uint32_t out_trace_dump_line, out_trace_dump_slot;
static bool out_trace_seen_input, out_trace_dumping;
typedef struct {
uint32_t generation, since_us;
stage_t stage;
uint16_t position;
} control_trace_watch_t;
static control_trace_watch_t out_trace_controls[DEVICES];
#endif
static const uint8_t hub_device[] = {
18,1,0x10,1,9,0,0,64,0x7e,5,0x68,0x20,0,1,1,2,3,1
};
@ -220,6 +283,116 @@ bool __not_in_flash_func(native_hub_select_device)(uint8_t address, uint8_t owne
spin_unlock_unsafe(bank_lock);
return true;
}
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
static __force_inline out_trace_record_t* out_trace_begin_record(void) {
if (__atomic_load_n(&out_trace_frozen,__ATOMIC_SEQ_CST)) return NULL;
const uint32_t cursor = __atomic_load_n(&out_trace_cursor,__ATOMIC_SEQ_CST);
out_trace_record_t* record = &out_trace_records[cursor & 127u];
record->cursor = cursor;
return record;
}
static __force_inline void out_trace_finish_record(out_trace_record_t* record) {
// Post-decision observations are sequential, NOT an atomic hardware image.
// Never inspect unlocked software control stages or shadow banks.
record->address_after = usb_hw->dev_addr_ctrl;
record->owner_after = active_device;
record->sof = usb_hw->sof_rd;
record->in0 = usb_dpram->ep_buf_ctrl[0].in;
record->out0 = usb_dpram->ep_buf_ctrl[0].out;
record->buffers = usb_hw->buf_status;
record->sie = usb_hw->sie_status;
record->sm = usb_hw->sm_state;
record->ints = usb_hw->ints;
record->missed_lock = missed_lock;
record->core0_phase = __atomic_load_n(&out_trace_core0_phase,__ATOMIC_ACQUIRE);
record->irq_enter = __atomic_load_n(&out_trace_irq_enter,__ATOMIC_ACQUIRE);
record->irq_exit = __atomic_load_n(&out_trace_irq_exit,__ATOMIC_ACQUIRE);
record->ep0_word = *(const volatile uint32_t*)usb_dpram->ep0_buf_a;
const uint32_t cursor = record->cursor;
const uint32_t next = (cursor & 127u) == OUT_TRACE_SLOTS-1u ? cursor+64u : cursor+1u;
__atomic_store_n(&out_trace_cursor,next,__ATOMIC_SEQ_CST);
}
bool __no_inline_not_in_flash_func(native_hub_select_device_traced)(
uint8_t address, uint8_t owner, uint32_t cutoff, uint8_t pid) {
if (__atomic_load_n(&out_trace_frozen,__ATOMIC_SEQ_CST))
return native_hub_select_device(address,owner,cutoff);
const uint32_t clock_before = sio_hw->mtime;
const uint32_t address_before = usb_hw->dev_addr_ctrl;
const uint8_t owner_before = active_device;
const bool selected = native_hub_select_device(address,owner,cutoff);
const uint32_t clock_after = sio_hw->mtime;
// The router records all failures through the post-rejection hook below.
if (!selected) return false;
out_trace_record_t* record = out_trace_begin_record();
if (!record) return true;
record->cutoff = cutoff;
record->clock_before = clock_before;
record->clock_after = clock_after;
record->address = address;
record->owner = owner;
record->address_before = address_before;
record->owner_before = owner_before;
record->selected = true;
record->reason = 0;
record->pid = pid;
record->before_valid = true;
record->blocked_buffers = record->blocked_sie = 0;
out_trace_finish_record(record);
return true;
}
void __no_inline_not_in_flash_func(native_hub_note_failed_select)(
uint8_t address, uint8_t owner, uint32_t cutoff, uint8_t pid) {
// Every rejection reaches this hook, even while frozen. A changed lock
// counter therefore identifies THIS attempt, not an older rejected token.
const bool lock_failed = missed_lock != out_trace_last_missed_lock;
out_trace_last_missed_lock = missed_lock;
const uint32_t clock_after = sio_hw->mtime;
out_trace_record_t* record = out_trace_begin_record();
if (!record) return;
record->cutoff = cutoff;
record->clock_before = 0;
record->clock_after = clock_after;
record->address = address;
record->owner = owner;
record->address_before = 0;
record->owner_before = NONE;
record->selected = false;
record->pid = pid;
record->before_valid = false; // No added work before normal IN/SETUP selection.
record->blocked_buffers = record->blocked_sie = 0;
if (lock_failed) record->reason = OUT_TRACE_LOCK;
else if (owner >= DEVICES || bank_lock == NULL) record->reason = OUT_TRACE_INVALID;
else {
record->reason = OUT_TRACE_GUARD;
record->blocked_buffers = blocked_buffers;
record->blocked_sie = blocked_sie;
if (blocked_buffers) record->reason |= OUT_TRACE_BUFFERS;
if (blocked_sie & USB_SIE_STATUS_SETUP_REC_BITS) record->reason |= OUT_TRACE_SETUP;
}
out_trace_finish_record(record);
}
uint32_t __no_inline_not_in_flash_func(native_hub_trace_phase)(uint32_t phase) {
// All setters run on Core0; IRQ instrumentation does not modify this tag.
const uint32_t previous = __atomic_load_n(&out_trace_core0_phase,__ATOMIC_RELAXED);
__atomic_store_n(&out_trace_core0_phase,phase,__ATOMIC_RELEASE);
return previous;
}
void __no_inline_not_in_flash_func(native_hub_note_log_mask)(
uint32_t elapsed_us, uint32_t bytes, bool already_masked) {
if (elapsed_us > out_trace_log_max_us) {
out_trace_log_max_us = elapsed_us;
out_trace_log_max_us_bytes = bytes;
}
if (bytes > out_trace_log_max_bytes) out_trace_log_max_bytes = bytes;
if (already_masked) ++out_trace_log_nested;
}
#endif
// Section placement alone permits inlining into the flash-backed task. Keep
// bank-lock ownership independent of XIP instruction-cache refill latency.
static void __no_inline_not_in_flash_func(restore_selected_bank)(void) {
@ -268,7 +441,12 @@ static __force_inline bool push_event(uint8_t device, uint8_t channel, uint8_t k
devices[device].endpoint_generation[channel]) : 0;
event->reset_generation = device < DEVICES ? devices[device].reset_generation : 0;
if (kind == 2 && (channel & 1u) && channel != 1) copy_from_usb(event->data,data,length);
else if (length) memcpy(event->data,data,length);
else {
// SRAM sources may be unaligned. Volatile byte reads keep this copy
// inline instead of calling flash-backed memcpy during BOOTSEL sampling.
const volatile uint8_t* source = data;
for (uint16_t i = 0; i < length; ++i) event->data[i] = source[i];
}
__dmb(); event_head = next;
return true;
}
@ -370,6 +548,26 @@ static void __not_in_flash_func(usb_interrupt)(void) {
spin_unlock(bank_lock, flags);
}
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
static void __no_inline_not_in_flash_func(usb_interrupt_traced)(void) {
__atomic_store_n(&out_trace_irq_enter,sio_hw->mtime,__ATOMIC_RELEASE);
usb_interrupt();
__atomic_store_n(&out_trace_irq_exit,sio_hw->mtime,__ATOMIC_RELEASE);
}
#endif
void __no_inline_not_in_flash_func(native_hub_service_pending_usb)(void) {
// BOOTSEL sampling keeps IRQs disabled while QSPI CSn is floated. Drain
// real hardware completions so Core1 can route the next device's token.
// Do not touch NVIC pending state: a later IRQ safely observes cleared flags.
if (!started || !usb_hw->ints) return;
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
usb_interrupt_traced();
#else
usb_interrupt();
#endif
}
static void stall(uint8_t slot) {
uint32_t flags = spin_lock_blocking(bank_lock);
if (devices[slot].control.generation != devices[slot].generation) {
@ -882,7 +1080,11 @@ bool native_hub_init(void) {
while ((int32_t)(time_us_32()-deadline) < 0);
if (!observer.ready) return false;
publish_addresses(); probe_router_enable(true);
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
irq_set_exclusive_handler(USBCTRL_IRQ,usb_interrupt_traced);
#else
irq_set_exclusive_handler(USBCTRL_IRQ,usb_interrupt);
#endif
irq_set_priority(USBCTRL_IRQ,0);
irq_set_enabled(USBCTRL_IRQ,true);
hw_set_bits(&usb_hw->sie_ctrl,USB_SIE_CTRL_PULLUP_EN_BITS);
@ -890,6 +1092,166 @@ bool native_hub_init(void) {
probe_debug_printf("[NATIVE_HUB] stock USB, SIO phase=%u, 240MHz; hub2068 R2066 L2067; isolated EP0/1/2 banks\n",NATIVE_HUB_SAMPLE_PHASE);
return true;
}
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
static void out_trace_freeze(uint32_t now, uint8_t control_slot) {
__atomic_store_n(&out_trace_frozen,1u,__ATOMIC_SEQ_CST);
out_trace_header_t* h = &out_trace_header;
h->cursor = __atomic_load_n(&out_trace_cursor,__ATOMIC_SEQ_CST);
h->count = h->cursor < OUT_TRACE_RETAIN ? h->cursor : OUT_TRACE_RETAIN;
h->time_us = now;
h->quiet_us = now - (control_slot < DEVICES
? out_trace_controls[control_slot].since_us : out_trace_last_input_us);
h->input[0] = input_count[1];
h->input[1] = input_count[2];
h->cycle = sio_hw->mtime;
h->sof = usb_hw->sof_rd;
h->address = usb_hw->dev_addr_ctrl;
h->owner = active_device;
h->out0 = usb_dpram->ep_buf_ctrl[0].out;
h->buffers = usb_hw->buf_status;
h->sie = usb_hw->sie_status;
h->sm = usb_hw->sm_state;
h->ints = usb_hw->ints;
h->intr = usb_hw->intr;
h->inte = usb_hw->inte;
h->tx_error = usb_hw->ep_tx_error;
h->rx_error = usb_hw->ep_rx_error;
h->irq_enter = __atomic_load_n(&out_trace_irq_enter,__ATOMIC_ACQUIRE);
h->irq_exit = __atomic_load_n(&out_trace_irq_exit,__ATOMIC_ACQUIRE);
h->core0_phase = __atomic_load_n(&out_trace_core0_phase,__ATOMIC_ACQUIRE);
h->log_max_us = out_trace_log_max_us;
h->log_max_us_bytes = out_trace_log_max_us_bytes;
h->log_max_bytes = out_trace_log_max_bytes;
h->log_nested = out_trace_log_nested;
h->in0 = usb_dpram->ep_buf_ctrl[0].in;
h->ep0_word = *(const volatile uint32_t*)usb_dpram->ep0_buf_a;
h->control_slot = control_slot;
h->control_generation = h->control_stage = h->control_position = h->control_length = 0;
h->control_word = 0;
memset(&h->control_request,0,sizeof(h->control_request));
if (control_slot < DEVICES) {
const control_t* c = &devices[control_slot].control;
h->control_generation = c->generation;
h->control_stage = c->stage;
h->control_position = c->position;
h->control_length = c->length;
h->control_request = c->request;
if (c->position < c->length) {
unsigned length = c->length-c->position;
if (length > sizeof(h->control_word)) length = sizeof(h->control_word);
memcpy(&h->control_word,c->data+c->position,length);
}
}
// Snapshot EVERYTHING printed in the header before enqueueing its first
// byte. Later lines must not accidentally describe the act of dumping.
out_trace_dump_slot = (h->cursor & 127u)+OUT_TRACE_SLOTS-h->count;
if (out_trace_dump_slot >= OUT_TRACE_SLOTS) out_trace_dump_slot -= OUT_TRACE_SLOTS;
out_trace_dump_line = 0;
out_trace_last_line_us = now-OUT_TRACE_LINE_US;
out_trace_dumping = true;
}
static bool out_trace_task(uint32_t now) {
const bool progress = input_count[1] != out_trace_input[0] ||
input_count[2] != out_trace_input[1];
if (progress) {
out_trace_input[0] = input_count[1];
out_trace_input[1] = input_count[2];
out_trace_last_input_us = now;
out_trace_seen_input = true;
}
bool control_progress = false;
uint8_t stalled_control = NONE;
for (uint8_t slot = 0; slot < DEVICES; ++slot) {
const control_t* c = &devices[slot].control;
control_trace_watch_t* watch = &out_trace_controls[slot];
const bool pending = c->stage == DATA_IN || c->stage == DATA_OUT ||
c->stage == STATUS_IN || c->stage == STATUS_OUT;
const bool changed = c->generation != watch->generation ||
c->stage != watch->stage || c->position != watch->position;
if (changed || !pending) {
watch->since_us = now;
watch->generation = c->generation;
watch->stage = c->stage;
watch->position = c->position;
}
control_progress |= changed;
if (pending && (uint32_t)(now-watch->since_us) >= OUT_TRACE_STALL_US &&
stalled_control == NONE) stalled_control = slot;
}
if (__atomic_load_n(&out_trace_frozen,__ATOMIC_SEQ_CST)) {
if (!out_trace_dumping) {
// A fresh completion after the dump permits diagnostic rearm.
// Never reset the producer cursor or touch controller/protocol state.
if (progress || control_progress) __atomic_store_n(&out_trace_frozen,0u,__ATOMIC_SEQ_CST);
return false;
}
} else if (stalled_control != NONE || (out_trace_seen_input &&
(uint32_t)(now-out_trace_last_input_us) >= OUT_TRACE_STALL_US)) {
out_trace_freeze(now,stalled_control);
} else return false;
// At most one <512-byte logger line per 50ms, below UART line capacity;
// no ring copying, waiting for Core1, masking, or formatting on Core1/IRQ.
if ((uint32_t)(now-out_trace_last_line_us) < OUT_TRACE_LINE_US) return true;
out_trace_last_line_us = now;
const out_trace_header_t* h = &out_trace_header;
if (out_trace_dump_line == 0) {
probe_debug_printf("[HUB_FLIGHT_FREEZE] us=%"PRIu32" quiet=%"PRIu32
" next=%08"PRIx32" n=%"PRIu32" in=%"PRIu32"/%"PRIu32
" cycle=%08"PRIx32" sof=%08"PRIx32" addr=%08"PRIx32" owner=%"PRIu32
" out0=%08"PRIx32" bs=%08"PRIx32" sie=%08"PRIx32" sm=%08"PRIx32
" ints=%08"PRIx32" intr=%08"PRIx32" inte=%08"PRIx32"\n",
h->time_us,h->quiet_us,h->cursor,h->count,h->input[0],h->input[1],
h->cycle,h->sof,h->address,h->owner,h->out0,h->buffers,h->sie,h->sm,
h->ints,h->intr,h->inte);
} else if (out_trace_dump_line == 1) {
probe_debug_printf("[HUB_FLIGHT_CONTEXT] next=%08"PRIx32" irq=%08"PRIx32"/%08"PRIx32
" phase=%08"PRIx32" txerr=%08"PRIx32" rxerr=%08"PRIx32" log_us=%"PRIu32
" bytes_at_max=%"PRIu32" max_bytes=%"PRIu32" nested=%"PRIu32"\n",
h->cursor,h->irq_enter,h->irq_exit,h->core0_phase,h->tx_error,h->rx_error,
h->log_max_us,h->log_max_us_bytes,h->log_max_bytes,h->log_nested);
} else if (out_trace_dump_line == 2) {
probe_debug_printf("[HUB_FLIGHT_CONTROL] slot=%"PRIu32" gen=%"PRIu32
" stage=%"PRIu32" pos=%"PRIu32"/%"PRIu32
" setup=%02x/%02x v=%04x i=%04x n=%u"
" expected=%08"PRIx32" ep0=%08"PRIx32" in0=%08"PRIx32"\n",
h->control_slot,h->control_generation,h->control_stage,
h->control_position,h->control_length,
h->control_request.bmRequestType,h->control_request.bRequest,
h->control_request.wValue,h->control_request.wIndex,h->control_request.wLength,
h->control_word,h->ep0_word,h->in0);
} else if (out_trace_dump_line < h->count+3u) {
const out_trace_record_t* r = &out_trace_records[out_trace_dump_slot];
// Hex except owner/ok/lock; req=address/owner, addr/owner=before/after.
// pre=0 means before-clock/address/owner are unavailable; all HW/IRQ fields are POST.
// reason bits: 01 lock, 02 saved BUF_STATUS, 04 saved SETUP_REC,
// 08 original guard, 10 invalid selector arguments; 00 means selected.
// Guard snapshots can race hardware; absence of 02/04 alone does not
// prove cutoff was the cause. Keep raw cutoff and clocks for analysis.
probe_debug_printf("[HUB_FLIGHT] n=%08"PRIx32" pid=%02x pre=%u cutoff=%08"PRIx32
" clock=%08"PRIx32"/%08"PRIx32" sof=%08"PRIx32
" req=%02x/%u addr=%08"PRIx32"/%08"PRIx32" owner=%u/%u ok=%u why=%02x"
" in0=%08"PRIx32" out0=%08"PRIx32" bs=%08"PRIx32" sie=%08"PRIx32" sm=%08"PRIx32
" ints=%08"PRIx32" block=%08"PRIx32"/%08"PRIx32
" lock=%"PRIu32" irq=%08"PRIx32"/%08"PRIx32" phase=%08"PRIx32
" ep0=%08"PRIx32"\n",
r->cursor,r->pid,r->before_valid,r->cutoff,r->clock_before,r->clock_after,r->sof,
r->address,r->owner,r->address_before,r->address_after,
r->owner_before,r->owner_after,r->selected,r->reason,
r->in0,r->out0,r->buffers,r->sie,r->sm,r->ints,r->blocked_buffers,
r->blocked_sie,r->missed_lock,r->irq_enter,r->irq_exit,r->core0_phase,r->ep0_word);
if (++out_trace_dump_slot == OUT_TRACE_SLOTS) out_trace_dump_slot = 0;
} else {
probe_debug_printf("[HUB_FLIGHT_END] next=%08"PRIx32" n=%"PRIu32"\n",h->cursor,h->count);
out_trace_dumping = false;
}
++out_trace_dump_line;
return true;
}
#endif
void native_hub_task(void) {
if (!started) return;
if (failed) {
@ -926,6 +1288,9 @@ void native_hub_task(void) {
}
}
static uint32_t last_log;
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
if (out_trace_task(now)) last_log = now;
#endif
if ((uint32_t)(now-last_log) >= 1000000u) {
last_log = now;
probe_debug_printf("[NATIVE_HUB] addr=%u/%u/%u cfg=%u/%u/%u setup=%"PRIu32"/%"PRIu32"/%"PRIu32

View file

@ -3,6 +3,7 @@
#include <stdbool.h>
#include <stdint.h>
#include "tusb.h"
#include "native_hub_trace.h"
#ifdef __cplusplus
extern "C" {
@ -15,6 +16,9 @@ extern "C" {
void native_hub_startup_guard(void);
bool native_hub_init(void);
void native_hub_task(void);
// Core0, with IRQs disabled and bank_lock not held: service hardware status
// while flash is unavailable. SRAM-only; queues events, never runs callbacks.
void native_hub_service_pending_usb(void);
bool native_hub_mounted(uint8_t instance);
bool native_hub_suspended(uint8_t instance);
bool native_hub_hid_ready(uint8_t instance);
@ -31,6 +35,7 @@ bool native_hub_control_xfer(uint8_t device_slot,
bool native_hub_control_status(uint8_t device_slot,
const tusb_control_request_t* request);
// Supplied by the existing native Joy-Con protocol engine. Each returned
// descriptor is the standalone model, with interfaces 0/1 and EPs 1/2.
const uint8_t* native_joycon_device_descriptor(uint8_t instance);

View file

@ -0,0 +1,34 @@
#pragma once
#include <stdbool.h>
#include <stdint.h>
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
#ifdef __cplusplus
extern "C" {
#endif
// Core1: selected token wrapper; the original selector owns every hardware decision.
bool native_hub_select_device_traced(uint8_t address, uint8_t owner, uint32_t cutoff, uint8_t pid);
// Core1: call after EVERY failed selection, including OUT and while frozen.
// Observes the completed decision; never retries or changes the bank.
void native_hub_note_failed_select(uint8_t address, uint8_t owner, uint32_t cutoff, uint8_t pid);
// Core0: call only AFTER restoring the logger's saved interrupt state.
void native_hub_note_log_mask(uint32_t elapsed_us, uint32_t bytes, bool already_masked);
// Core0 execution tags. Backend lock tags include the source line.
enum {
NATIVE_HUB_TRACE_PHASE_NONE = 0,
NATIVE_HUB_TRACE_PHASE_LOG_COPY = 1,
NATIVE_HUB_TRACE_PHASE_RADIO_POLL = 2,
NATIVE_HUB_TRACE_PHASE_USB_TASK = 3,
NATIVE_HUB_TRACE_PHASE_LOG_DRAIN = 4,
NATIVE_HUB_TRACE_PHASE_PROTOCOL = 5,
NATIVE_HUB_TRACE_PHASE_SLEEP = 6,
NATIVE_HUB_TRACE_PHASE_BACKEND_LOCK = 0x10000,
};
uint32_t native_hub_trace_phase(uint32_t phase);
#ifdef __cplusplus
}
#endif
#endif

View file

@ -192,7 +192,11 @@ size_t encode_transaction(uint8_t* output, size_t output_size) {
size_t encode_info(uint8_t* output, size_t output_size) {
uint8_t payload[8] = {
#if SWITCH2_PROBE_HUB
0, 78, 0, 2,
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
0, 87, 0, 2,
#else
0, 86, 0, 2,
#endif
kNativeHubActiveMode,
USB_OUTPUT_CAPABILITY_INPUT | USB_OUTPUT_CAPABILITY_RUMBLE |
USB_OUTPUT_CAPABILITY_MOTION,

View file

@ -20,6 +20,7 @@ void native_test_bus_reset(bool);
void native_test_hold_abort(bool);
bool native_test_select(uint8_t);
bool native_test_private_in(uint8_t, uint8_t, uint8_t*, uint16_t*);
extern uint32_t native_test_interrupt_mask;
}
namespace {
@ -332,6 +333,44 @@ void test_private_transmit_survives_round_robin_tokens() {
native_test_drain();
native_test_initialize();
}
void test_masked_irq_completion_handoff() {
native_test_initialize();
tusb_control_request_t configuration{};
configuration.bRequest = TUSB_REQ_SET_CONFIGURATION;
configuration.wValue = 1;
for (uint8_t slot : {1, 2}) {
require(native_test_setup(slot, &configuration, true), "child configuration failed");
acknowledge(slot);
}
const uint8_t payloads[2][3] = {{0x12, 0x34, 0x56}, {0x78, 0x9a, 0xbc}};
for (uint8_t instance : {0, 1})
require(native_hub_hid_report(instance, 8, payloads[instance], 3),
"could not queue masked-window HID packet");
uint8_t packet[64];
uint16_t length = 0;
native_test_interrupt_mask = 1;
require(native_test_private_in(1, 0x81, packet, &length),
"first controller did not complete during masked window");
require(!native_test_select(2),
"pending completion must prevent overwriting the active bank");
native_hub_service_pending_usb();
require(native_test_interrupt_mask == 1,
"SRAM service must preserve the caller's interrupt mask");
require(native_test_private_in(2, 0x81, packet, &length) && length == 4 &&
packet[0] == 8 && std::memcmp(packet + 1, payloads[1], 3) == 0,
"SRAM service did not permit the other controller's real packet");
native_hub_service_pending_usb();
require(!native_hub_hid_ready(0) && !native_hub_hid_ready(1),
"SRAM service must defer protocol callbacks to foreground dispatch");
native_test_interrupt_mask = 0;
native_test_drain();
require(native_hub_hid_ready(0) && native_hub_hid_ready(1),
"deferred completions did not release both controller queues");
require(!native_test_private_in(1, 0x81, packet, &length),
"later IRQ dispatch duplicated a serviced completion");
native_test_initialize();
}
void test_private_bootsel() {
const auto bytes = envelope(Operation::kBootselReboot, {});
@ -430,6 +469,7 @@ int main() {
test_pending_control_buffer_ownership();
test_read_ack_allows_usb_progress();
test_private_transmit_survives_round_robin_tokens();
test_masked_irq_completion_handoff();
test_private_bootsel();
std::cout << "native root management packet and persistence regressions passed\n";
}

View file

@ -41,6 +41,7 @@ typedef struct {
volatile uint32_t pwr, main_ctrl, sie_ctrl, ep_nak_stall_status;
volatile uint32_t ep_tx_error, ep_rx_error;
volatile uint32_t abort, abort_done;
volatile uint32_t sm_state, sof_rd, intr, dev_sm_watchdog, nak_poll;
} usb_hw_t;
typedef struct { volatile uint32_t in, out; } usb_pair_t;
typedef struct {

View file

@ -9,6 +9,9 @@
#if defined(SWITCH2_PROBE_HUB) && SWITCH2_PROBE_HUB
extern bool native_hub_select_device(uint8_t address, uint8_t owner, uint32_t cutoff);
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
#include "usb/native_hub/native_hub_trace.h"
#endif
#endif
#if !PICO_RP2350 || defined(__riscv)
@ -30,6 +33,10 @@ extern bool native_hub_select_device(uint8_t address, uint8_t owner, uint32_t cu
#define PID_OUT 0xe1u
#define PID_IN 0x69u
#define PID_SETUP 0x2du
// NRZI SYNC+PID words, with K=2 and J=1 packed into two-bit samples.
#define TOKEN_OUT_SIGNATURE 0xaa66a666u
#define TOKEN_IN_SIGNATURE 0x95a6a666u
#define TOKEN_SETUP_SIGNATURE 0x9a56a666u
#define NO_READER 2u
#define SETUP_SEQUENCE_MASK 0x3fffffffu
#define SETUP_SLOT_SHIFT 30u
@ -175,9 +182,9 @@ static void build_table(routing_table* table,
void probe_router_init(uint32_t system_clock_hz) {
// Explicit SRAM data: Core1 must never fetch flash during durable saves.
token_words[6] = 0xaa66a666u;
token_words[10] = 0x95a6a666u;
token_words[5] = 0x9a56a666u;
token_words[6] = TOKEN_OUT_SIGNATURE;
token_words[10] = TOKEN_IN_SIGNATURE;
token_words[5] = TOKEN_SETUP_SIGNATURE;
const uint8_t addresses[PROBE_ROUTER_SLOTS] = {0u, PROBE_ROUTER_UNASSIGNED,
PROBE_ROUTER_UNASSIGNED};
memset(&counters, 0, sizeof(counters));
@ -295,7 +302,7 @@ static __force_inline bool sample_line(uint32_t* deadline, uint32_t* line) {
}
static __force_inline void route_header(const routing_table* table, uint32_t address,
bool setup, uint32_t initial_address,
uint32_t signature, uint32_t initial_address,
uint32_t cutoff, raw_packet* packet) {
// TinyUSB clears SETUP_REC only AFTER copying the hardware-validated SETUP
// into its event callback. Until then, preserve both address and owner.
@ -306,8 +313,21 @@ static __force_inline void route_header(const routing_table* table, uint32_t add
return;
#if defined(SWITCH2_PROBE_HUB) && SWITCH2_PROBE_HUB
if (atomic_read(&enabled) != 0u) {
if (!native_hub_select_device((uint8_t)address, table->owner[address], cutoff))
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
const uint8_t pid = signature == TOKEN_OUT_SIGNATURE ? PID_OUT :
signature == TOKEN_IN_SIGNATURE ? PID_IN : PID_SETUP;
const bool selected = (pid == PID_OUT || (pid == PID_IN && table->owner[address] == 0))
? native_hub_select_device_traced((uint8_t)address, table->owner[address], cutoff, pid)
: native_hub_select_device((uint8_t)address, table->owner[address], cutoff);
#else
const bool selected = native_hub_select_device((uint8_t)address, table->owner[address], cutoff);
#endif
if (!selected) {
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_note_failed_select((uint8_t)address, table->owner[address], cutoff, pid);
#endif
return;
}
if (initial_address != address) ++packet->retargets;
}
#else
@ -324,7 +344,7 @@ static __force_inline void route_header(const routing_table* table, uint32_t add
// Candidate observations qualify calibration only. Runtime ownership
// comes from the hardware address frozen by SETUP_REC. A missed software
// candidate must not reject a correctly addressed, hardware-accepted SETUP.
if (setup)
if (signature == TOKEN_SETUP_SIGNATURE)
publish_setup(table->owner[address]);
}
@ -438,7 +458,7 @@ edge:
if ((base) + (bit) == 19u && decoder != NULL) { \
uint8_t candidate = early_decoder[word1 & 0xffu]; \
if (candidate < 128u) \
route_header(table, candidate, word0 == 0x9a56a666u, initial_address, \
route_header(table, candidate, word0, initial_address, \
deadline + 11u * FS_BIT_CYCLES, &result); \
} \
} while (0)
@ -465,7 +485,7 @@ edge:
address_wire = (address_wire | (address_wire >> 1u)) & 0x3333u; \
address_wire = (address_wire | (address_wire >> 2u)) & 0x0f0fu; \
address_wire = (address_wire | (address_wire >> 4u)) & 0xffu; \
route_header(table, decoder[address_wire], word0 == 0x9a56a666u, \
route_header(table, decoder[address_wire], word0, \
initial_address, deadline + 7u * FS_BIT_CYCLES, &result); \
if (result.late) { result.count = (base) + (bit) + 1u; goto done; } \
} \

View file

@ -124,6 +124,10 @@ int probe_debug_printf(const char* format, ...) {
if (result <= 0) return result;
const size_t size = (size_t)result < sizeof(message) ? (size_t)result : sizeof(message) - 1;
const uint32_t interrupts = save_and_disable_interrupts();
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
const uint32_t mask_started = time_us_32();
const uint32_t trace_parent = native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_LOG_COPY);
#endif
if (LOG_CAPACITY - (log_written - log_read) >= size) {
for (size_t i = 0; i < size; ++i)
log_bytes[(log_written + i) % LOG_CAPACITY] = message[i];
@ -132,7 +136,14 @@ int probe_debug_printf(const char* format, ...) {
} else {
log_dropped += (uint32_t)result;
}
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(trace_parent);
const uint32_t mask_elapsed = time_us_32() - mask_started;
#endif
restore_interrupts(interrupts);
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_note_log_mask(mask_elapsed, (uint32_t)size, interrupts != 0);
#endif
return result;
}
@ -847,12 +858,24 @@ int main(void) {
uint32_t last_heartbeat = 0;
while (true) {
#if SWITCH2_PROBE_HUB
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_RADIO_POLL);
#endif
probe_controller_input_task();
#if defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_USB_TASK);
#endif
native_hub_task();
#else
tud_task();
#endif
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_LOG_DRAIN);
#endif
drain_log();
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_PROTOCOL);
#endif
const uint32_t now = to_ms_since_boot(get_absolute_time());
#ifdef SWITCH_PICO_SWITCH2_USB_BRIDGE
probe_bootsel_task(now);
@ -917,6 +940,9 @@ int main(void) {
}
#endif
}
#if SWITCH2_PROBE_HUB && defined(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
native_hub_trace_phase(NATIVE_HUB_TRACE_PHASE_SLEEP);
#endif
sleep_us(100);
}
}

View file

@ -369,12 +369,16 @@ function(switch2_usb_probe_configure target)
endif()
if(SWITCH2_PROBE_HUB AND SWITCH2_BRIDGE_FULL_INPUT)
if(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
pico_set_program_version(${target} "0.78-native-tx-bank-trace")
pico_set_program_version(${target} "0.87-native-enumeration-flight")
else()
pico_set_program_version(${target} "0.78-native-gamepad")
pico_set_program_version(${target} "0.86-native-flash-service")
endif()
elseif(SWITCH2_PROBE_HUB)
pico_set_program_version(${target} "0.78-native-hub-tx-bank")
if(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
pico_set_program_version(${target} "0.87-native-hub-enumeration-flight")
else()
pico_set_program_version(${target} "0.86-native-hub-flash-service")
endif()
elseif(SWITCH2_PROBE_JOIN_CHORD_GATE)
if(SWITCH2_PROBE_TRACE_NATIVE_INPUT)
pico_set_program_version(${target} "0.37-pair-chord-trace")