Repository navigation
mt7612u: drain EP 4 when an MCU reply is late, so RXDCOC cannot stall bring-up - #510
Conversation
… bring-up On a channel with traffic, an MT7612U bring-up took ~27.5 s instead of ~0.87 s: from the RXDCOC calibration of the channel set on, every MCU command ran out its 3 s reply budget, and all the replies then appeared within ~7 ms of the RX ring's first EP 4 transfer. A register probe at the first timeout read MT_MAC_SYS_CTRL = 0 (MAC RX and TX off) with the USB RX bulk enable set, and the EP 4 read decoded there was a data frame from the peer's address. So received data reaches EP 4 during RXDCOC before anything reads it, and while it sits there the EP 5 replies are held back too. What in the calibration lets it through is not established. mcu_wait_resp() now drains EP 4 once per command, on its first 300 ms timeout, and only while nobody else reads EP 4. Ownership is a new mt7612u_dev::ep4_owner (NONE / RING / SYNC) rather than d->a->rx_active: it lives on the device, so the PHY tick can read it while StopRxLoop frees the ring (which it does without _mu). The ring claims it under io_lock before its first RX submit and releases it once no RX transfer is left in flight; an MT_RX_DRAIN_SYNC caller holds it until the receiver is switched off; every transition is a compare-exchange from the expected owner. A reply on time costs nothing; a late one costs one mt_rx_flush(), which now returns the bytes drained (partial reads included). The drain logs the command, length and first word. tests/mt7612u_busy_bringup.sh reproduces it with rxdemo + a txdemo peer (build with -DDEVOURER_MT7612U=ON; it runs under mt7612u_sta_lib.sh's root-run rules). One MT7612U, ch 100, an RTL8812EU peer 50 cm away at zero gap: master 09c2ff3 stalled 6 of 6 at 20 MHz and 6 of 6 at HT40 (27.5 s, 9 timeouts each); with this change 10 of 10 and 10 of 10 reached the RX ring in 1.18 s, 0.31 s over the quiet control. The odds rise with the peer's load (a 6 Mb/s peer at a 500 us gap: 1 of 6 on master). Not measured: a ring-less (TX-only) channel set under traffic, and whether the ten-read reply budget could go back to five. docs/mt7612u.md has the table and limits; src/mt7612u/CLAUDE.md replaces "bring this one up before the interferer" with the mechanism; the busy-window probe's notes that relied on that rule are updated (its loaded MediaTek arms stay skipped: not re-run with the sensor started second); tests/README.md lists the reproducer. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge
PR Summary by Qodomt7612u: Drain EP 4 when busy-channel MCU replies are late
AI Description
Diagram
High-Level Assessment
Files changed (10)
|
Code Review by Qodo
1.
|
![qodo-free-for-open-source-projects[bot]](https://avatars.githubusercontent.com/in/1068000?s=60&v=4){kind=small}
…efused claims From the review on OpenIPC#510: - mt_rx_flush() ended on a read that timed out after moving bytes, though more may be queued behind them; it now ends on an empty read, a hard error or its read budget. mcu_wait_resp() drained once per command; it drains again on a later timeout if the previous drain found data, all of a command's drains sharing one 64-read budget, so the per-command bound stays 3 s of reply reads + 0.64 s. - mt_async_start() submitted RX transfers, and mt_mac_start(MT_RX_DRAIN_SYNC) enabled RX, even when their ep4_owner claim failed. Both now refuse. The SYNC claim is taken under io_lock (the lock the drain's owner check holds) and before any register write, so a refusal leaves a running ring's receiver and filter untouched; a SYNC claimed by a call that then fails is released. - tests/mt7612u_busy_bringup.sh: the peer is checked before every loaded bring-up and every bring-up that comes up must hear it, else INCONCLUSIVE; a slow bring-up is FAIL ahead of that. - CLAUDE.md scoped: the MCU-wait drain never shares EP 4 with a ring or a synchronous drainer; the teardown/recovery flushes do not consult the owner. Hardware, same rig, master d0a9e10 as control: master 3/3 slow at each width (27.5 s); this 10/10 + 10/10 fast (1.18-1.20 s; one at 0.87 s needed no drain), and 20/20 with an RTL8812BU peer. docs/mt7612u.md has the table. ctest 86/86 with -DDEVOURER_MT7612U=ON. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge
|
Qodo's three findings are addressed in 6c84a49. There's a reply in each thread. Before pushing, two independent reviewers went over the diff. They found two more things, both fixed in the same commit:
Bound. All of one command's drains share one 64-read budget, so the per-command worst case is unchanged: 3 s of reply reads plus 0.64 s. Hardware. Same rig as before: one MT7612U, ch 100, the peer 50 cm away,
Limits.
🤖 Generated with Claude Code |
josephnef
left a comment
josephnef
left a comment
There was a problem hiding this comment.
Review: PR 510 (mt7612u: drain EP 4 when an MCU reply is late)
Verdict: request changes. The drain fixes the stall it targets, and I reproduced both the stall and the fix on this bench. But the revised mt_rx_flush exit rule (commit 6c84a49, the Qodo "partial reads" fix) adds ~2 s to EVERY MT7612U bring-up on this host, quiet channel included.
Reproduced (this bench)
One MT7612U (0e8d:7612, 4-2.3.2, USB 3 hub), peer RTL8812EU (0bda:a81a, USB 2 hub), ch 100, 20 MHz, tests/mt7612u_busy_bringup.sh from the PR branch. The 8812EU on this USB 2 hub aborts txdemo at zero gap (8 consecutive bulk-OUT timeouts), so the peer ran at PEER_GAP_US=300, MCS3/20/LDPC. Firmware had to be decompressed by hand (see nit 1).
| build | control (quiet) | loaded bring-ups |
|---|---|---|
| master d0a9e10 (fresh worktree, same configure) | 1.79 s | 3 of 3 + 1 of 1 slow: 28.3 s, 9 MCU timeouts each |
| PR 6c84a49 | 3.79–3.84 s (2 runs) | 6 of 6 + 1 of 1 fast: 4.62–4.72 s, 0 timeouts, one drain each of 243–249 kB |
| PR + candidate fix below | 1.79 s | 4 of 4 fast: 2.04–2.11 s, 0 timeouts, one drain each of 11–14 kB |
The regression
strace of a quiet-channel PR bring-up showed 320 intervals of exactly 10 ms. Instrumenting mt_rx_flush (scratch build): every call on the bring-up path reads 64 × 4096 B, 651 ms, rc = LIBUSB_ERROR_TIMEOUT, n = 4096 on every read, with the buffer returned all zeros over a 0xA5 sentinel fill. So on this host (libusb 1.0.30, kernel 6.18, xhci) a timed-out bulk-IN read of an idle EP 4 reports actual_length == len with no data. The new rule
if (n == 0 || (rc && rc != LIBUSB_ERROR_TIMEOUT))
break;treats that as "bytes moved, keep going" and runs the whole 64-read budget. Three flushes sit on bring-up (mt_init_hardware, mt_mac_stop on the previous session's state, …) → ~2 s. The loaded drains are the same thing: 243–249 kB "drained" is ~10 kB of real data plus ~50 phantom 10 ms reads, which is why the loaded bring-up sits 0.8 s above the control here instead of your 0.31 s. On your rig the timed-out read evidently reports 0, which is why your control did not move.
Candidate fix (verified above)
Keep the PR's re-drain logic and go back to "any error ends the drain":
/* A timed-out read on an idle EP 4 reports n == len with no data on
* some hosts, so n is not a safe continue condition. A drain that ended
* on a timeout with bytes is re-run by mcu_wait_resp() on its next reply
* timeout (ep4_last > 0), which covers the genuinely partial read. */
if (n > 0)
total += (size_t)n;
if (rc || n == 0)
break;The Qodo concern (partial read, more queued) is already handled by the caller's re-drain path; it does not need the loop to continue past a timeout. Please re-run your 20/40 MHz cells with this — on this bench control 1.79 s / loaded 2.04–2.11 s with 11–14 kB drains, which matches your 8.6–10.1 kB. docs/mt7612u.md and src/mt7612u/CLAUDE.md describe the "not on a timed-out read that moved bytes" rule, so they need the same edit.
Smaller points
tests/mt7612u_busy_bringup.shdoes not callsta_fw_readable/sta_fw_linklike its siblings (mt7612u_sta_identity.shetc.). On a stock linux-firmware host (*.bin.zstonly) the control dies with "firmware not found" and the script printsINCONCLUSIVE: the DUT did not come up on a quiet channel (DIED)— the sibling scripts name the real cause.docs/mt7612u.md"Bring-up on a busy channel": the "After review (…)" paragraph and "across the drain's revisions" narrate PR revision history and give two master baselines (09c2ff3,d0a9e10). Current-state docs only: one table against one master, numbers from the final code.tests/busy_window_probe.sh: "(its bring-up stall is fixed: …)" is the same historical phrasing. Say what is true now ("the MediaTek sensor can start second; these arms have not been re-run that way").- Ownership logic itself reads correctly: RING claimed under
io_lockbefore the first submit, released only withrx_inflight == 0; SYNC claimed before any register write and released bymt_mac_rx_disable/mt_mac_stop;mt_async_start's failed claim goes throughfail→mt_async_stop, whose RING→NONE CAS is a harmless no-op there.mt7612u_devisnew-constructed so thestd::atomicinitialiser runs. No findings.
…ot data 6c84a49 kept draining past a timed-out read that reported bytes. On one host (libusb 1.0.30, kernel 6.18, xhci) a timed-out read of an idle EP 4 reports n == len with no data, so every flush ran its whole 64-read budget: ~2 s on every bring-up, quiet channel included (review 5708821119). Any error now ends the drain, a timeout included; a drain that ended on a timeout with real data is re-run by mcu_wait_resp() on its next reply timeout. A timed-out read reporting a full buffer is also not counted: a read that really fills the buffer completes, and counting the artefact would make every MCU-wait drain look like data, re-drain on each later reply timeout and log bytes that were never there. docs/mt7612u.md: one table against master d0a9e10, numbers from this code. Same rig (MT7612U 8-1, RTL8812EU peer at MCS3 zero gap, ch 100): master 3 of 3 slow at 20 and at 40 MHz (27.5-27.6 s, 9 timeouts each); this code 10 of 10 at each width, 1.18-1.20 s, one drain each (8.6-10.1 kB at 20 MHz, 15.8-17.3 kB at 40 MHz), control 0.86-0.87 s. Not run on the host that shows the artefact. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge
The script never checked the MT7612U blobs, so a host with compressed
firmware only died in the control and printed a misleading INCONCLUSIVE
('did not come up on a quiet channel'). It now picks the directory the
library will load from (FW_DIR, /lib/firmware/mediatek, ./firmware, as
resolve_fw_dir and sta_client_onair.sh do) and refuses through
sta_fw_readable, which names the compressed files. No ./firmware link is
needed: rxdemo takes the directory from DEVOURER_MT7612U_FW_DIR.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge
busy_window_probe.sh said the stall 'is fixed'; it now says what is true: the MediaTek sensor can start second, and these arms have not been re-run that way. tests/README.md said 'on master', which stops being true when this merges: 'without the drain'. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge
|
Thanks. That's a real regression and a precise diagnosis. Addressed in Exit rule: your rule as given. Any error ends the drain, a timeout included, and a drain that ended on a timeout with data is re-run by One deliberate addition: a timed-out read reporting a full buffer is not counted toward the drained bytes. A read that really fills the buffer completes with rc 0, so Re-run, same rig as before (MT7612U 8-1, RTL8812EU peer at MCS3 with zero gap, ch 100, near field), against master
No bring-up needed a second drain, so that path is still unexercised on hardware. The 0.31–0.33 s over the control is the first 300 ms reply timeout. Docs: Nits:
|
|
Re-reviewed Code: the exit rule is the one I verified here, plus the full-buffer-timeout exclusion. That exclusion reads correctly to me: a read that really fills the buffer completes with Docs and nits: all three addressed as asked. The "Bring-up on a busy channel" section is current-state only now, and it says plainly that this exact code has not run on the host that shows the artefact. Hardware re-run on this host: not done yet. The MT7612U that showed the |
|
Converted to draft until the busy-bringup re-run on the host that shows the full-buffer timeout exists (its MT7612U is off the bus at the moment). Mark it ready again once that run is posted, or once you are happy to ship without it. |
|
I tried to reproduce the full-buffer timeout here, so that Setup:
The shim: an
Runs:
Results:
How to read these numbers:
libusb doesn't look like the difference.
What's left:
On this host the exclusion never fired, so these runs measure your exit rule alone. Only your host can show the exclusion catching a phantom read. It also isn't airtight on a real full read.
Limits: one adapter, one root port, one controller, one kernel. No hub, no USB 2 path, no 6.18. You said you're holding approval until that run exists, or until we're happy to ship without it. Since this bench can't produce the artefact, I'd take the second option and mark this ready, unless you'd rather wait for slot #17. If it comes back, the shim below shows the phantom reads directly on any build. inshim.c// LD_PRELOAD shim: sentinel-fill every bulk-IN buffer of a MediaTek (0e8d)
// device before submit, and log each completion: endpoint, status, length,
// actual_length, and what [0, actual) holds (data / all-zero / untouched
// sentinel). A phantom read is a non-COMPLETED status with actual == length
// and no data. Log file: $INSHIM_LOG (default /dev/stderr).
#define _GNU_SOURCE
#include <dlfcn.h>
#include <fcntl.h>
#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#include <unistd.h>
#include <libusb-1.0/libusb.h>
struct hook { libusb_transfer_cb_fn cb; void *ud; };
static int fd = -1;
static pthread_mutex_t mu = PTHREAD_MUTEX_INITIALIZER;
static unsigned long n_all, n_phantom, n_partial_to, n_data;
static double now_ms(void) { struct timespec t; clock_gettime(CLOCK_MONOTONIC, &t); return t.tv_sec * 1e3 + t.tv_nsec / 1e6; }
static const char *st(int s) {
static const char *n[] = {"COMPLETED","ERROR","TIMED_OUT","CANCELLED","STALL","NO_DEVICE","OVERFLOW"};
return s >= 0 && s <= 6 ? n[s] : "?";
}
static void LIBUSB_CALL on_done(struct libusb_transfer *t) {
struct hook *h = t->user_data;
int a = t->actual_length, zeros = 1, sent = 1;
for (int i = 0; i < a; i++) { if (t->buffer[i]) zeros = 0; if (t->buffer[i] != 0xA5) sent = 0; }
const char *what = a == 0 ? "empty" : zeros ? "ZEROS" : sent ? "SENTINEL" : "data";
int phantom = t->status != LIBUSB_TRANSFER_COMPLETED && a == t->length && (zeros || sent);
pthread_mutex_lock(&mu);
n_all++; n_phantom += phantom; n_data += what[0] == 'd';
n_partial_to += t->status != LIBUSB_TRANSFER_COMPLETED && a > 0 && !phantom;
char line[200];
int k = snprintf(line, sizeof line, "%.3f pid=%d ep=%02x st=%s len=%d act=%d %s%s\n", now_ms(), getpid(),
t->endpoint, st(t->status), t->length, a, what, phantom ? " PHANTOM" : "");
if (write(fd, line, (size_t)k) < 0) {}
pthread_mutex_unlock(&mu);
t->user_data = h->ud; t->callback = h->cb; free(h);
t->callback(t);
}
int LIBUSB_CALL libusb_submit_transfer(struct libusb_transfer *t) {
static int (*real)(struct libusb_transfer *);
if (!real) real = (int (*)(struct libusb_transfer *))dlsym(RTLD_NEXT, "libusb_submit_transfer");
if (fd < 0) {
const char *p = getenv("INSHIM_LOG"); fd = p ? open(p, O_WRONLY | O_CREAT | O_APPEND, 0644) : 2; if (fd < 0) fd = 2;
const struct libusb_version *v = libusb_get_version();
Dl_info di; dladdr((void *)real, &di);
char l[400]; int k = snprintf(l, sizeof l, "LOADED pid=%d libusb %u.%u.%u from %s\n", getpid(), v->major, v->minor, v->micro, di.dli_fname);
if (write(fd, l, (size_t)k) < 0) {}
}
struct libusb_device_descriptor dd;
if (t->type != LIBUSB_TRANSFER_TYPE_BULK || !(t->endpoint & 0x80) ||
libusb_get_device_descriptor(libusb_get_device(t->dev_handle), &dd) || dd.idVendor != 0x0e8d)
return real(t);
struct hook *h = malloc(sizeof *h);
if (!h) return real(t);
h->cb = t->callback; h->ud = t->user_data;
memset(t->buffer, 0xA5, (size_t)t->length);
t->callback = on_done; t->user_data = h;
int rc = real(t);
if (rc) { t->callback = h->cb; t->user_data = h->ud; free(h); }
return rc;
}
__attribute__((destructor)) static void fini(void) {
if (fd < 0 || !n_all) return;
char line[200];
int k = snprintf(line, sizeof line, "SUMMARY pid=%d in_completions=%lu data=%lu phantom=%lu partial_timeout=%lu\n",
getpid(), n_all, n_data, n_phantom, n_partial_to);
if (write(fd, line, (size_t)k) < 0) {}
} |
|
Code review by qodo was updated up to the latest commit 447ec95 |
josephnef
left a comment
josephnef
left a comment
There was a problem hiding this comment.
Approved at 447ec95. The exit rule is the one measured here; the full-buffer-timeout exclusion reads correct and its worst case on this host is a bounded re-drain inside the shared 64-read budget. Shipping without the slot #17 re-run as you proposed; when that adapter is back, your shim is the follow-up check.
What
On a channel that is already in use, an MT7612U bring-up takes ~27.5 s instead of ~0.87 s. The RXDCOC calibration of the channel set runs out its 3 s MCU reply budget, and so does every command after it. All the replies then turn up within ~7 ms of the RX ring's first EP 4 transfer.
A register probe at the first timeout read
MT_MAC_SYS_CTRL = 0(MAC RX and TX off) with the USB RX bulk enable on (MT_USB_U3DMA_CFG = 0x00c40020). The EP 4 read decoded there was an RX descriptor and a data frame from the peer's address. So received data reaches EP 4 during RXDCOC before anything reads it, and while it sits there the EP 5 replies are held back too. What in the calibration lets it through is not established.This is the "bring this one up BEFORE the interferer" note in
src/mt7612u/CLAUDE.md, and probably the same thing the "ten reads, not five" comment inmcu_wait_resp()describes ("the MCU answered every command, but seconds late … their nine replies then arrived together").Change
mcu_wait_resp()drains EP 4 (mt_rx_flush()) once per command, on its first 300 ms timeout, and only while nobody else reads EP 4. A reply that arrives in time costs nothing. A late one costs one flush, and its log line gives the command, length and first word.mt7612u_dev::ep4_owner(NONE/RING/SYNC), notd->a->rx_active:StopRxLoopfrees the ring (StopRxLoopdoes that without_mu).io_lockbefore its first RX submit. That is the lockmcu_wait_respholds from the check through the drain.MT_RX_DRAIN_SYNCcaller (bringupgate F) holds it until the receiver is switched off.mt_rx_flush()returns the bytes it drained, partial reads included. Existing callers ignore the return value.src/mt7612u/CLAUDE.md: a current-state "MCU replies and EP 4" section replaces the "bring it up first" rule.docs/mt7612u.md: a "Bring-up on a busy channel" section with the table and its limits.tests/busy_window_probe.*: the notes that relied on the old rule are updated. Its loaded MediaTek arms stay skipped, because they have not been re-run with the sensor started second.tests/README.mdlists the reproducer.tests/mt7612u_busy_bringup.sh, built onmt7612u_sta_lib.shand its root-run rules:txdemoloads the channel at zero gap;REPStimes under it withrxdemo, each run timed to its RX ring starting;-DDEVOURER_MT7612U=ONand says INCONCLUSIVE otherwise.Measured
One MT7612U (
0e8d:7612, USB 3) on ch 100. The peer is an RTL8812EU 50 cm away atDEVOURER_TX_PWR_OFFSET_QDB=-40(−36 dBm at the DUT). The peer was heard after every bring-up.09c2ff3ctest with
-DDEVOURER_MT7612U=ON: 86/86 pass; the two that need external reference data are skipped. No new warnings insrc/mt7612u/.Limits
Possible follow-ups (not in this PR)
mt_mac_start's "refuse rather than wedge".busy_window_probe.sh's loaded MediaTek arms with the sensor started second, and drop their skip.Found while bringing up an RTL8812EU → MT7612U video link. Before opening, this was reviewed by three independent agents over two rounds. The first revision read
d->a->rx_activeunlocked from the tick thread; that use-after-free window was caught in review and is gone.🤖 Generated with Claude Code
https://claude.ai/code/session_011dReg1L6xtBhf95NpAeuge