diff --git a/docs/logging.md b/docs/logging.md index 327d135f..9806044f 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -76,7 +76,7 @@ Emitters: L = library, RX/TX/... = demo. Optional fields in [brackets]; ### Init / infrastructure | ev | emitter | fields | |---|---|---| -| `init.timing` | L (`src/InitTimer.h`) + demos | stage ("scope.stage", e.g. "demo.first_rx_frame", "txdemo.first_tx_submit"), ms | +| `init.timing` | L (`src/InitTimer.h`) + demos | stage ("scope.stage", e.g. "demo.first_rx_frame", "txdemo.first_tx_submit"), ms, [xfers] (register transfers the stage spent on that adapter's transport, USB only — present on the Jaguar3 `j3hal.*` / `j3init.*` stages) | | `adapter.caps` | RX, TX, doctor, txpower (`examples/common/caps_event.h`) | supported, chip, names, chip_id "0x..", gen, variant, transport, tx_chains, rx_chains, n_ss, stbc, ldpc, sgi, bw_max, bw[] (MHz), txpwr_max, txpwr_step_qdb, txpwr_step_measured, txpwr_min_qdb, txpwr_max_qdb, txpwr_rate_diffs, txpwr_rate_diffs_hw, txpwr_rate_diffs_measured, tune_2g4[]\|null, tune_5g[]\|null, char_2g4[]\|null, char_5g[]\|null, ldpc_rx_ht, ldpc_rx_vht, ldpc_rx_flag, vht_2g4, per_pkt_txpwr, per_pkt_txpwr_steps, per_pkt_txpwr_step_qdb, per_pkt_txpwr_min_qdb, per_pkt_txpwr_max_qdb, per_pkt_txpwr_measured, narrowband, fastretune, ack_responder, tx_retry_limit, he_er_su, per_chain_rssi, hw_rx_tsf, hw_beacon_txtsf, tsf_write, xtal_cap_max, xtal_cap_default | | `debug.wreg` | L (`DEVOURER_LOG_WRITES`) | addr "0x0nnn", width, val "0x…" | | `hop.prof` | L (`DEVOURER_HOP_PROF`) | gen, ch, `_us`…, total_us | diff --git a/examples/chipstate/main.cpp b/examples/chipstate/main.cpp index 0e3ea62d..0b2d0372 100644 --- a/examples/chipstate/main.cpp +++ b/examples/chipstate/main.cpp @@ -49,7 +49,7 @@ namespace { /* Same list the other demos' open loop iterates; --pid narrows to one. */ const uint16_t kRealtekPids[] = {0x8812, 0x8813, 0x881a, 0x0811, 0xa811, 0x0820, 0x0821, 0x8822, 0x0120, 0x012d, - 0xb82c, 0xc811, 0xc812, 0xa81a}; + 0xb82c, 0xb812, 0xc811, 0xc812, 0xa81a}; /* One --peek/--poke, kept in argv order so a poke-then-peek verifies the * write inside a single claim. */ @@ -58,7 +58,7 @@ struct RegOp { uint16_t addr = 0; uint16_t end = 0; /* peek range: inclusive last addr (== addr if single) */ uint32_t val = 0; /* poke */ - int width = 1; /* poke: 1/2/4 */ + int width = 1; /* poke: 1/2/4; peek: 1 (bytes) or 4 (aligned words) */ }; struct Args { @@ -74,13 +74,16 @@ void usage() { std::fprintf(stderr, "usage: chipstate [--vid 0xNNNN] [--pid 0xNNNN] [--init] " "[--channel N]\n" - " [--peek 0xA[-0xB]]... [--poke 0xA=0xV[:W]]...\n" + " [--peek 0xA[-0xB][:4]]... [--poke 0xA=0xV[:W]]...\n" " default: attach read-only, no USB reset, no bring-up.\n" " --init : run a full bring-up first (for a healthy reference\n" - " dump on a freshly power-cycled adapter).\n" + " dump on a freshly power-cycled adapter). With\n" + " --peek/--poke the ops run AFTER the bring-up.\n" " --peek : dump register byte(s) over the vendor-control path\n" " (range inclusive, 16 bytes/row) instead of the\n" " canary set. Bypasses chip dispatch — any die.\n" + " `:4` reads aligned 32-bit words instead (the BB/RF\n" + " windows answer 32-bit reads only).\n" " --poke : write a register (width W = 1/2/4, default from the\n" " value magnitude). The bench-bisection intervention\n" " lever; ops run in argv order, so a trailing --peek\n" @@ -111,6 +114,14 @@ bool parse_peek(const char *s, RegOp &op) { if (!parse_reg_addr(end + 1, &end, op.end) || op.end < op.addr) return false; } + if (*end == ':') { + if (end[1] != '4' || end[2] != '\0') + return false; + op.width = 4; + op.addr &= ~3u; + op.end |= 3u; + return true; + } return *end == '\0'; } @@ -159,6 +170,17 @@ int run_reg_ops(libusb_device_handle *handle, Logger_t logger, else adapter.rtw_write8(op.addr, static_cast(op.val)); std::printf("poke 0x%04x = 0x%0*x\n", op.addr, op.width * 2, op.val); + } else if (op.width == 4) { + for (uint32_t row = op.addr & ~0xfu; row <= op.end; row += 16) { + std::printf("0x%04x:", row); + for (uint32_t i = row; i < row + 16; i += 4) { + if (i < op.addr || i > op.end) + std::printf(" "); + else + std::printf(" %08x", adapter.rtw_read32(static_cast(i))); + } + std::printf("\n"); + } } else { for (uint32_t row = op.addr & ~0xfu; row <= op.end; row += 16) { std::printf("0x%04x:", row); @@ -281,7 +303,7 @@ int main(int argc, char **argv) { /* --peek/--poke: raw transport-level register access, no device * construction at all — the chip is not even identified, let alone * configured, so this works mid-experiment on any die. */ - if (!a.ops.empty()) + if (!a.ops.empty() && !a.init) return run_reg_ops(handle, logger, ctx, lock, a.ops); devourer::DeviceConfig cfg; @@ -303,6 +325,16 @@ int main(int argc, char **argv) { dev->InitWrite(SelectedChannel{.Channel = static_cast(a.channel), .ChannelOffset = 0, .ChannelWidth = CHANNEL_WIDTH_20}); + /* --init + ops: the question is what the bring-up left in a register, + * so the ops run on the configured chip. The device object is released + * first: its destructor joins the Jaguar3 coex thread (and does not + * de-init the chip — that is Stop(), which this tool never calls), so + * the raw-adapter ops below cannot interleave with a background + * register write. Same handle, interface still claimed. */ + if (!a.ops.empty()) { + session.adopt_device(nullptr); + return run_reg_ops(handle, logger, ctx, lock, a.ops); + } } else { logger->info("chipstate: read-only attach (no USB reset, no bring-up) — " "the chip is being read exactly as the last session left it"); diff --git a/src/InitTimer.h b/src/InitTimer.h index 133c36b8..49e13a48 100644 --- a/src/InitTimer.h +++ b/src/InitTimer.h @@ -5,11 +5,19 @@ #include #include +#include + #include "logger.h" /* Stage timer for init-path profiling. Emits one event per checkpoint: * - * {"ev":"init.timing","stage":".","ms":N} + * {"ev":"init.timing","stage":".","ms":N[,"xfers":K]} + * + * `xfers` is emitted only when the timer was given a transfer counter: the + * number of register transfers (reads + writes) that stage spent on that one + * adapter's transport (ITransport::ctrl_xfers, via RtlAdapter::ctrl_xfers), + * which is the unit a USB bring-up is actually paid in. Per adapter, so two + * devices brought up in one process do not cross-attribute; 0 on PCIe. * * `stage()` reports time since the previous checkpoint (or construction); * `total()` reports time since construction. Always-on: a handful of events @@ -19,25 +27,36 @@ class InitTimer { using clock = std::chrono::steady_clock; public: - InitTimer(Logger_t logger, const char *scope) - : _logger{std::move(logger)}, _scope{scope}, _start{clock::now()}, - _last{_start} {} + using XferCounter = std::function; + + InitTimer(Logger_t logger, const char *scope, XferCounter xfers = {}) + : _logger{std::move(logger)}, _scope{scope}, _xfers{std::move(xfers)}, + _start{clock::now()}, _last{_start}, _x_start{count()}, + _x_last{_x_start} {} void stage(const char *name) { const auto now = clock::now(); - emit(name, ms(_last, now)); + const auto x = count(); + emit(name, ms(_last, now), static_cast(x - _x_last)); _last = now; + _x_last = x; } - void total() { emit("total", ms(_start, clock::now())); } + void total() { + emit("total", ms(_start, clock::now()), + static_cast(count() - _x_start)); + } private: - void emit(const char *name, long long millis) { + uint64_t count() const { return _xfers ? _xfers() : 0; } + + void emit(const char *name, long long millis, long long nx) { char stage[96]; std::snprintf(stage, sizeof(stage), "%s.%s", _scope, name); - devourer::Ev(_logger->events(), "init.timing") - .f("stage", stage) - .f("ms", millis); + devourer::Ev ev(_logger->events(), "init.timing"); + ev.f("stage", stage).f("ms", millis); + if (_xfers) + ev.f("xfers", nx); } static long long ms(clock::time_point from, clock::time_point to) { @@ -47,8 +66,11 @@ class InitTimer { Logger_t _logger; const char *_scope; + XferCounter _xfers; clock::time_point _start; clock::time_point _last; + uint64_t _x_start; + uint64_t _x_last; }; #endif /* INIT_TIMER_H */ diff --git a/src/RtlAdapter.h b/src/RtlAdapter.h index 74efa7f3..45e0ef29 100644 --- a/src/RtlAdapter.h +++ b/src/RtlAdapter.h @@ -88,6 +88,11 @@ class RtlAdapter { /* Pre-power-on HCI programming (rtw88 rtw_hci_setup slot): PCIe TRX ring * registers; no-op on USB. Call per bring-up attempt, before power-on. */ void hci_setup() { _transport->hci_setup(); } + /* Pipelined register writes — see ITransport::write_batch_begin. */ + void write_batch_begin() { _transport->write_batch_begin(); } + void write_batch_end() { _transport->write_batch_end(); } + void flush_writes() { _transport->flush_writes(); } + uint64_t ctrl_xfers() const { return _transport->ctrl_xfers(); } /* Kernel-style async RX: keep n_urbs concurrent bulk-IN transfers in flight * (USB) or reap the RX buffer-descriptor ring (PCIe), invoking diff --git a/src/Transport.h b/src/Transport.h index 82c63154..b54d46ec 100644 --- a/src/Transport.h +++ b/src/Transport.h @@ -68,6 +68,25 @@ class ITransport { return read32(static_cast(addr)); } + /* ---- pipelined register writes ---- + * Inside a write batch, register writes are submitted as asynchronous + * in-order transfers and only a read (or a bulk transfer, or flush_writes) + * waits for them. Bring-up is ~14k synchronous EP0 round trips at ~80 us + * each on an embedded host; pipelined, a write costs ~27 us (measured, + * ssc338q + RTL8812EU, depth >= 8). Correctness rests on EP0 completing + * URBs in submission order, so a read that follows a write still sees it. + * Single-threaded by contract: open a batch only while no other thread + * touches the transport (the Jaguar3 InitWrite/Init bring-up), and close + * it before any worker thread starts. Defaults are no-ops (PCIe). */ + virtual void write_batch_begin() {} + virtual void write_batch_end() {} + virtual void flush_writes() {} + /* Register transfers (reads + writes) this transport instance has issued + * so far — the unit a USB bring-up is paid in. InitTimer differences it + * per stage. Per instance, never process-wide. 0 where the notion does + * not apply (PCIe MMIO). */ + virtual uint64_t ctrl_xfers() const { return 0; } + /* ---- frame plane ---- */ /* Fire-and-forget data TX (the send_packet hot path). `ep` is the USB * bulk-OUT endpoint choice; the PCIe transport ignores it (the ring is diff --git a/src/UsbTransport.cpp b/src/UsbTransport.cpp index 4cf2aece..1c472827 100644 --- a/src/UsbTransport.cpp +++ b/src/UsbTransport.cpp @@ -336,6 +336,23 @@ UsbTransport::UsbTransport(libusb_device_handle *dev_handle, Logger_t logger, } UsbTransport::~UsbTransport() { + flush_writes(); + int leaked = 0; + for (auto *w : _aw_all) { + /* libusb forbids freeing an active transfer, and its callback still + * writes through `w`. If the drain above could not reap it (dead event + * loop / yanked device), leaking the slot is the lesser evil: a callback + * that somehow fires later touches leaked memory, whereas freeing here + * hands libusb a dangling transfer it is still holding. */ + if (w->inflight) { + ++leaked; /* keeps its shared AsyncPool alive for a late callback */ + continue; + } + libusb_free_transfer(w->t); + delete w; + } + if (leaked) + _logger->error("USB: leaked {} unreaped pipelined transfer slot(s)", leaked); /* Backstop only. The device's Stop()/destructor quiesces TX while every * owner is alive, which is the path that makes teardown safe; reaching the * transport destructor with transfers still in flight means the caller tore @@ -352,7 +369,208 @@ UsbTransport::~UsbTransport() { quiesce_tx(); } +/* ---- pipelined register writes ------------------------------------------ + * Submission order == completion order on EP0, so a pending queue of writes + * followed by a read behaves exactly like the synchronous sequence; the win + * is that the host does not sit through a full URB round trip per write. */ +void UsbTransport::write_batch_begin() { + if (_batch) + return; + /* A session that already failed to reap its transfers has a short pool and + * a suspect event loop; stay synchronous rather than pipeline into it. */ + if (_aw_abandoned) + return; + if (_aw_all.empty()) { + /* Built transactionally: a slot whose transfer allocation failed must + * never reach fill/submit, so on any failure the pool is torn back + * down and the session stays synchronous. */ + std::vector slots; + for (int i = 0; i < kAsyncWriteDepth; ++i) { + auto *w = new AsyncWrite{}; + w->t = libusb_alloc_transfer(0); + if (!w->t) { + delete w; + for (auto *s : slots) { + libusb_free_transfer(s->t); + delete s; + } + _logger->error("USB: libusb_alloc_transfer failed; register writes " + "stay synchronous"); + return; + } + w->pool = _aw; + slots.push_back(w); + } + _aw_all = slots; + _aw->free = slots; + } + _aw->errors = 0; + _batch = true; +} + +void UsbTransport::write_batch_end() { + flush_writes(); + if (_batch && _aw->errors) + _logger->error("USB: {} pipelined register write(s) failed in this batch", + _aw->errors); + _batch = false; +} + +void LIBUSB_CALL UsbTransport::async_write_cb(libusb_transfer *t) { + auto *w = static_cast(t->user_data); + /* Only the shared pool is touched here — never the transport, which a + * leaked slot can outlive (AsyncPool). */ + AsyncPool &pool = *w->pool; + pool.inflight--; + pool.completed++; + w->inflight = false; + w->done = true; + w->status = t->status; + w->actual = t->actual_length; + if (t->status != LIBUSB_TRANSFER_COMPLETED || + t->actual_length != t->length - LIBUSB_CONTROL_SETUP_SIZE) + pool.errors++; + /* The slot goes back on the free list here; a reader that is waiting on + * this very slot copies its data out before it submits anything else + * (single-threaded by contract), so the buffer is still intact. */ + pool.free.push_back(w); +} + +UsbTransport::AsyncWrite *UsbTransport::async_take_slot() { + while (_aw->free.empty()) { + if (!async_wait_progress()) { + flush_writes(); /* recovers the pool on a stuck queue */ + if (_aw->free.empty()) + return nullptr; + } + } + AsyncWrite *w = _aw->free.back(); + _aw->free.pop_back(); + w->done = false; + w->inflight = false; + w->status = -1; + w->actual = 0; + return w; +} + +bool UsbTransport::async_read(uint16_t wvalue, uint16_t windex, void *data, + size_t n) { + if (n > kAsyncMaxPayload) + return false; + AsyncWrite *w = async_take_slot(); + if (!w) + return false; + libusb_fill_control_setup(w->buf, REALTEK_USB_VENQT_READ, 5, wvalue, windex, + static_cast(n)); + libusb_fill_control_transfer(w->t, _dev_handle, w->buf, async_write_cb, w, + USB_TIMEOUT); + const int rc = libusb_submit_transfer(w->t); + if (rc != 0) { + _aw->free.push_back(w); + _aw->errors++; + _logger->error("USB: pipelined read submit failed ({})", rc); + return false; + } + w->inflight = true; + _aw->inflight++; + while (!w->done) { + if (!async_wait_progress()) { + flush_writes(); /* cancels + recovers; w->done is set by the cancel */ + break; + } + } + if (!w->done || w->status != LIBUSB_TRANSFER_COMPLETED || + w->actual != static_cast(n)) + return false; + std::memcpy(data, w->buf + LIBUSB_CONTROL_SETUP_SIZE, n); + return true; +} + +bool UsbTransport::async_wait_progress() { + const uint64_t before = _aw->completed; + for (int turns = 0; turns < 8 && _aw->completed == before; ++turns) { + struct timeval tv {0, 250 * 1000}; + const int rc = libusb_handle_events_timeout_completed(_ctx, &tv, nullptr); + if (rc < 0) { + _logger->error("USB: event loop error {} while draining pipelined writes", + rc); + return false; + } + } + return _aw->completed != before; +} + +void UsbTransport::flush_writes() { + while (_aw->inflight > 0) { + if (async_wait_progress()) + continue; + /* No completion in ~2 s of pumping. USB_TIMEOUT is 500 ms, so libusb + * itself times a stuck transfer out and completes it through the + * callback long before this; reaching here means the event loop is not + * delivering completions at all (context torn down, device gone). + * Cancel what is still submitted so the caller's next synchronous + * transfer is not queued behind it. */ + _logger->error("USB: pipelined write drain timed out ({} in flight)", + _aw->inflight); + for (auto *w : _aw_all) + if (w->inflight) + libusb_cancel_transfer(w->t); + /* A cancellation still completes through the callback, which is what + * clears `inflight` and returns the slot. Keep pumping for it: the count + * must never be zeroed by hand, or a late callback decrements it below + * zero (silently disabling every later drain), pushes its slot onto the + * free list a second time, and races the destructor's free. */ + for (int i = 0; i < kFlushCancelTurns && _aw->inflight > 0; ++i) + async_wait_progress(); + if (_aw->inflight > 0) { + /* The event loop itself is gone (a yanked device reports the error + * immediately, so the turns above cost nothing). Leave the slots + * submitted and off the free list; the destructor leaks them. The + * batch is closed here too: with those slots never returning, the + * in-flight count can never reach zero again, and every later + * register access would otherwise walk take-slot -> wait -> drain + * (seconds each) for the rest of the bring-up. Synchronous from + * here on. */ + _aw->errors += _aw->inflight; + _aw_abandoned = true; + _batch = false; + _logger->error("USB: {} pipelined transfer(s) could not be reaped; " + "their slots are retired for this session", + _aw->inflight); + } + return; + } +} + +bool UsbTransport::async_write(uint16_t wvalue, uint16_t windex, + const void *data, size_t n) { + if (n > kAsyncMaxPayload) + return false; + AsyncWrite *w = async_take_slot(); + if (!w) + return false; + libusb_fill_control_setup(w->buf, REALTEK_USB_VENQT_WRITE, 5, wvalue, windex, + static_cast(n)); + std::memcpy(w->buf + LIBUSB_CONTROL_SETUP_SIZE, data, n); + libusb_fill_control_transfer(w->t, _dev_handle, w->buf, async_write_cb, w, + USB_TIMEOUT); + const int rc = libusb_submit_transfer(w->t); + if (rc != 0) { + _aw->free.push_back(w); + _aw->errors++; + _logger->error("USB: pipelined write submit failed ({})", rc); + return false; + } + w->inflight = true; + _aw->inflight++; + return true; +} + bool UsbTransport::write_bytes(uint16_t reg_num, const uint8_t *ptr, size_t n) { + /* A vendor control transfer like any other -- counted so an InitTimer stage + * that downloads firmware this way reports what it actually spent. */ + _ctrl_xfers.fetch_add(1, std::memory_order_relaxed); + flush_writes(); return libusb_control_transfer(_dev_handle, REALTEK_USB_VENQT_WRITE, 5, reg_num, 0, const_cast(ptr), n, USB_TIMEOUT) == static_cast(n); @@ -854,6 +1072,7 @@ void UsbTransport::quiesce_tx() { bool UsbTransport::tx_async(uint8_t tx_ep, uint8_t *packet, size_t length, unsigned timeout_ms) { + flush_writes(); /* Reap completed async-TX transfers before submitting the next one — in the * caller's own thread, so there is no background pump to race libusb * teardown. A non-blocking handle_events (timeout 0) processes every ready @@ -1001,6 +1220,7 @@ bool UsbTransport::tx_async(uint8_t tx_ep, uint8_t *packet, size_t length, int UsbTransport::tx_sync(uint8_t ep, uint8_t *packet, size_t length, int timeout_ms) { + flush_writes(); /* No libusb_clear_halt here. rtw88_8814au's usbmon shows the first bulk * OUT is preceded by 0 CLEAR_FEATUREs; later CLEAR_FEATUREs happen during * normal TX-queue operation, not the per-send hot path. Resetting the diff --git a/src/UsbTransport.h b/src/UsbTransport.h index 9bb02319..c284a5a1 100644 --- a/src/UsbTransport.h +++ b/src/UsbTransport.h @@ -51,6 +51,10 @@ class UsbTransport final : public ITransport { /* Realtek USB register addressing: wValue = addr[15:0], wIndex = * addr[31:16]. Lets the BB/RF window (addr + 0x10000) reach wIndex=1 * instead of colliding with the MAC/system space at wIndex=0. */ + _ctrl_xfers.fetch_add(1, std::memory_order_relaxed); + if (_batch) + return async_write(static_cast(addr & 0xFFFF), + static_cast(addr >> 16), &v, sizeof(v)); return libusb_control_transfer( _dev_handle, REALTEK_USB_VENQT_WRITE, 5, static_cast(addr & 0xFFFF), @@ -59,6 +63,17 @@ class UsbTransport final : public ITransport { } uint32_t read32_wide(uint32_t addr) override { uint32_t data = 0; + _ctrl_xfers.fetch_add(1, std::memory_order_relaxed); + if (_batch) { + if (async_read(static_cast(addr & 0xFFFF), + static_cast(addr >> 16), &data, sizeof(data))) + return data; + /* Logged, unlike the synchronous path below: a failed pipelined read + * is a queue problem, not a register problem, and must not be + * mistaken for a register that genuinely reads all-ones. */ + _logger->error("USB: pipelined read32_wide(0x{:05x}) failed", addr); + return 0xFFFFFFFFu; + } if (libusb_control_transfer(_dev_handle, REALTEK_USB_VENQT_READ, 5, static_cast(addr & 0xFFFF), static_cast(addr >> 16), @@ -68,6 +83,12 @@ class UsbTransport final : public ITransport { return 0xFFFFFFFFu; /* INVALID_RF_DATA-style sentinel on a failed read */ } bool write_bytes(uint16_t reg, const uint8_t *p, size_t n) override; + void write_batch_begin() override; + void write_batch_end() override; + void flush_writes() override; + uint64_t ctrl_xfers() const override { + return _ctrl_xfers.load(std::memory_order_relaxed); + } bool tx_async(uint8_t ep, uint8_t *buf, size_t len, unsigned timeout_ms) override; @@ -85,6 +106,59 @@ class UsbTransport final : public ITransport { private: template T ctrl_read(uint16_t reg); template bool ctrl_write(uint16_t reg, T value); + /* Pipelined-write machinery (see ITransport::write_batch_begin). */ + /* Register transfers are 1/2/4 bytes; async_write/async_read refuse a + * larger payload rather than overrun the inline setup buffer. */ + static constexpr size_t kAsyncMaxPayload = 4; + /* Bookkeeping the completion callback writes to. It is owned jointly by + * the transport and every slot (shared_ptr), not by the transport alone: + * a slot that could not be reaped outlives the transport (see the + * destructor), and its callback may still fire later through a libusb + * context another adapter in the process keeps pumping. It then updates + * this block, which the leaked slot keeps alive, instead of a freed + * UsbTransport. */ + struct AsyncWrite; + struct AsyncPool { + std::vector free; + int inflight = 0; + uint64_t completed = 0; + int errors = 0; + }; + struct AsyncWrite { + libusb_transfer *t; + uint8_t buf[LIBUSB_CONTROL_SETUP_SIZE + kAsyncMaxPayload]; + std::shared_ptr pool; + bool done; + /* Submitted and not yet reaped: libusb owns `t` and `buf` while set, so + * the slot must not be reused, freed, or handed back to the free list. */ + bool inflight; + int status; + int actual; + }; + static constexpr int kAsyncWriteDepth = 8; + /* Extra event-loop turns spent reaping cancellations after a drain times + * out. A live loop reports each cancellation promptly; a dead one fails + * every turn immediately, so this costs nothing in the case that matters. */ + static constexpr int kFlushCancelTurns = 8; + bool async_write(uint16_t wvalue, uint16_t windex, const void *data, + size_t n); + /* Read queued behind the pending writes (EP0 order) and waited for on its + * own completion only: a read-modify-write pair costs one wakeup, not two. + * Returns false on failure (data untouched). */ + bool async_read(uint16_t wvalue, uint16_t windex, void *data, size_t n); + AsyncWrite *async_take_slot(); + bool async_wait_progress(); /* one event-loop turn; false on timeout/error */ + static void LIBUSB_CALL async_write_cb(libusb_transfer *t); + bool _batch = false; + std::shared_ptr _aw = std::make_shared(); + std::vector _aw_all; + /* Set when a drain gave up with transfers still submitted: the destructor + * then leaks those slots instead of freeing a transfer libusb still owns. */ + bool _aw_abandoned = false; + /* Vendor control transfers (register reads + writes) this transport has + * issued; per instance, so two adapters in one process do not + * cross-attribute their InitTimer stage counts. */ + std::atomic _ctrl_xfers{0}; void discover_endpoints(); /* was InitDvObj */ const char *speed_str() const; static void transfer_callback(struct libusb_transfer *transfer); @@ -158,6 +232,13 @@ class UsbTransport final : public ITransport { template T UsbTransport::ctrl_read(uint16_t reg_num) { T data = 0; + _ctrl_xfers.fetch_add(1, std::memory_order_relaxed); + if (_batch) { + if (async_read(reg_num, 0, &data, sizeof(T))) + return data; + _logger->error("rtw_read({:04x}) pipelined, sizeof(T) = {}", reg_num, sizeof(T)); + throw std::ios_base::failure("rtw_read"); + } if (libusb_control_transfer(_dev_handle, REALTEK_USB_VENQT_READ, 5, reg_num, 0, (uint8_t *)&data, sizeof(T), USB_TIMEOUT) == sizeof(T)) { @@ -169,6 +250,9 @@ template T UsbTransport::ctrl_read(uint16_t reg_num) { } template bool UsbTransport::ctrl_write(uint16_t reg_num, T value) { + _ctrl_xfers.fetch_add(1, std::memory_order_relaxed); + if (_batch) + return async_write(reg_num, 0, &value, sizeof(T)); return libusb_control_transfer(_dev_handle, REALTEK_USB_VENQT_WRITE, 5, reg_num, 0, (uint8_t *)&value, sizeof(T), USB_TIMEOUT) == sizeof(T); diff --git a/src/jaguar3/CLAUDE.md b/src/jaguar3/CLAUDE.md index e44ebee0..d02453c6 100644 --- a/src/jaguar3/CLAUDE.md +++ b/src/jaguar3/CLAUDE.md @@ -36,6 +36,35 @@ narrowband dividers, RF18 encoding), strategy interfaces `Jaguar3Calibration` single-path 1SS TX, spur channels, LCK, the 2.4 GHz TX kernel-parity limitation) live in `docs/8822e-quirks.md`. +## Bring-up cost and the pipelined register writes + +`InitWrite` is ~14k USB register transfers and nothing else. The stage +timing (`InitTimer` events `j3hal.*` / `j3init.*`, each carrying `ms` and +the `xfers` it spent; `bench_init.py` parses these events but reports only +`ms`) is what shows it. The batching contract itself — ordering, what +waits, single-threadedness — is documented once, at +`ITransport::write_batch_begin` (`src/Transport.h`) and in `UsbTransport`; +this file carries only how Jaguar3 uses it: + +- `InitWrite` runs its whole bring-up inside one `WriteBatchScope` + (`RtlJaguar3Device.cpp`), ended before the coex thread starts because that + thread shares the transport. `Init` (RX-only) opens no batch yet — not + measured on a ground-station card. +- Every settle delay drains the queue first, µs ones included, on both + dies: the `write_bb` / `rf_writer` table delay markers, `delay_us` and + `delay_ms` on `Halrf8822c` and `Halrf8822e`, the efuse power-cut. A settle + that sleeps while its writes are still queued is no settle; the drain is + free on an empty queue and bounded by its depth otherwise. +- Measured: 1.30 → 0.65 s warm, 2.04 → ~0.7 s cold on one drone-side + 8812EU (ssc338q host). The transfer-count reduction is deterministic; the + wall-clock figure is one unit, one host. + +The RF radio-table load is write-only: bits [31:20] of the direct window +(`0x3c00`/`0x4c00 + addr*4`) read back 0 for every table entry, so the +vendor's `MASK20BITS` read-modify-write preserved nothing at the price of a +synchronous read per entry. Measured on one 8812EU (cold and warm) and one +8812CU (`tests/j3_rf_window_readback.sh`). + ## TX power Both dies drive the SAME TXAGC block (`set_tx_power_ref` is the port of diff --git a/src/jaguar3/HalJaguar3.cpp b/src/jaguar3/HalJaguar3.cpp index ba938e18..95f50447 100644 --- a/src/jaguar3/HalJaguar3.cpp +++ b/src/jaguar3/HalJaguar3.cpp @@ -1,4 +1,5 @@ #include "HalJaguar3.h" +#include "InitTimer.h" #include #include @@ -41,12 +42,17 @@ void retry_cal(Logger_t &logger, const char *what, F &&step, int tries = 3) { * write. */ void write_bb(RtlAdapter &dev, uint32_t addr, uint32_t data) { switch (addr) { - case 0xfe: std::this_thread::sleep_for(std::chrono::milliseconds(50)); return; - case 0xfd: std::this_thread::sleep_for(std::chrono::milliseconds(5)); return; - case 0xfc: std::this_thread::sleep_for(std::chrono::milliseconds(1)); return; - case 0xfb: std::this_thread::sleep_for(std::chrono::microseconds(50)); return; - case 0xfa: std::this_thread::sleep_for(std::chrono::microseconds(5)); return; - case 0xf9: std::this_thread::sleep_for(std::chrono::microseconds(1)); return; + /* The table delays exist to let the preceding writes settle, so every + * one of them drains the pipelined-write queue before sleeping — a + * settle measured from a write that is still queued is no settle. The + * drain is free when the queue is empty and bounded by its depth when + * not. */ + case 0xfe: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(50)); return; + case 0xfd: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(5)); return; + case 0xfc: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(1)); return; + case 0xfb: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(50)); return; + case 0xfa: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(5)); return; + case 0xf9: dev.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(1)); return; default: dev.phy_set_bb_reg(static_cast(addr), MASKDWORD, data); } } @@ -87,11 +93,16 @@ void HalJaguar3::run_iqk(SelectedChannel channel) { * Every step is ported from vendor source. */ void HalJaguar3::rtw_hal_init(SelectedChannel channel) { ChannelWidth_t bw = channel.ChannelWidth; + InitTimer timer(_logger, "j3hal", [this] { return _device.ctrl_xfers(); }); _macinit.pre_init_system_cfg(); + timer.stage("pre_init_system_cfg"); power_on(); /* mac_power_switch(on) — card_en_flow */ + timer.stage("power_on"); read_chip_version(); /* needs MAC alive; supplies cut for system_cfg */ + timer.stage("chip_version"); cache_efuse_8822e(); /* one-shot OTP decode while access is reliable */ + timer.stage("efuse_cache"); if (_variant == ChipVariant::C8822E && _efuse_cache_valid) /* Efuse thermal baseline (0xd0/0xd1) + channel for pwr_track thermal tracking. */ _cal->set_pwr_track_ctx(_efuse_cache[0xd0], _efuse_cache[0xd1], @@ -109,35 +120,46 @@ void HalJaguar3::rtw_hal_init(SelectedChannel channel) { (_phy_ctx.rfe_type == 0 || _phy_ctx.rfe_type == 0xff)) _phy_ctx.rfe_type = 21; _logger->info("Jaguar3: rfe_type=0x{:02x}", _phy_ctx.rfe_type); + timer.stage("efuse_rfe"); _macinit.init_system_cfg(bw, _ver.cut); + timer.stage("init_system_cfg"); if (!_fw.download_default_firmware()) { _logger->error("Jaguar3: firmware download FAILED (structured)"); return; } _logger->info("Jaguar3: firmware booted (structured)"); + timer.stage("dlfw"); if (!_macinit.init_mac_cfg(bw)) { _logger->error("Jaguar3: init_mac_cfg FAILED (structured)"); return; } + timer.stage("init_mac_cfg"); /* Propagate the queue-init reserved-page boundary to the FW downloader — it * was 0 during the pre-queue-init FW stage, so a beacon rsvd-page download * would otherwise target page 0 instead of the real boundary. */ _fw.set_rsvd_boundary(_macinit.rsvd_boundary()); _macinit.init_usb_cfg(); /* USB RX-DMA mode — RX delivery to bulk-IN */ _macinit.enable_bb_rf(true); /* set_hw_value(EN_BB_RF) */ - apply_bb_rf_agc_tables(); /* init_phy: BB + AGC + RF tables */ + timer.stage("usb_cfg_bbrf"); + apply_bb_rf_agc_tables(&timer); /* init_phy: BB + AGC + RF tables */ config_pa_bias_8822e(); /* kfree: efuse PA-bias trim -> RF 0x60 */ + timer.stage("pa_bias"); config_phydm_parameter_init(); /* POST_SETTING: 3-wire + OFDM/CCK block + bb-reset */ + timer.stage("phydm_param_init"); init_rfk(); /* RF cal_init (0x1B00); IQK runs via run_iqk */ + timer.stage("rfk_init"); /* halrf DACK — DAC cal before IQK. Retry-wrapped: its status-poll loops issue * tens of thousands of USB reads and an intermittent glitch was aborting * bring-up (rtw_read iostream error, seen on 8822EU). */ retry_cal(_logger, "DACK", [this] { _cal->dac_calibrate(); }); + timer.stage("dack"); bf_init(); /* rtl8822c_phy_bf_init (rtl8822c_halinit.c) */ monitor_rx_cfg(); /* devourer monitor-mode RX enable */ enable_tx_path(); /* enable OFDM/CCK TX block (gates on-air TX) */ + timer.stage("bf_rx_tx_cfg"); + timer.total(); _logger->info("Jaguar3: bring-up complete"); } @@ -543,6 +565,7 @@ void HalJaguar3::efuse_pwr_cut_8822e(bool on) { if (on) { _device.rtw_write8(PMC, static_cast(_device.rtw_read8(PMC) | kWrMsk)); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) | kPwcS)); + _device.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(1)); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) | kPwcB)); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) & ~kEbCore)); @@ -555,6 +578,7 @@ void HalJaguar3::efuse_pwr_cut_8822e(bool on) { _device.rtw_write32(EFC1, _device.rtw_read32(EFC1) & ~kBurst); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) | kEbCore)); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) & ~kPwcB)); + _device.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(1)); _device.rtw_write16(SYS_ISO, static_cast(_device.rtw_read16(SYS_ISO) & ~kPwcS)); _device.rtw_write8(PMC, static_cast(_device.rtw_read8(PMC) & ~kWrMsk)); @@ -965,7 +989,7 @@ void HalJaguar3::power_on() { _logger->info("Jaguar3: power-on sequence complete (card active)"); } -void HalJaguar3::apply_bb_rf_agc_tables() { +void HalJaguar3::apply_bb_rf_agc_tables(InitTimer *timer) { /* BB + AGC baseline via the validated halbb walker (src/jaguar3/ * PhyTableLoaderJaguar3). _phy_ctx must be populated from the chip-version + * EFUSE read (done earlier in rtw_hal_init) before the tables are walked. */ @@ -976,8 +1000,10 @@ void HalJaguar3::apply_bb_rf_agc_tables() { const auto agc_tab = _tables->agc_tab(); _logger->info("Jaguar3: applying BB phy_reg table ({} words)", phy_reg.len); PhyTableLoaderJaguar3::Load(phy_reg.data, phy_reg.len, _phy_ctx, bb); + if (timer) timer->stage("table_phy_reg"); _logger->info("Jaguar3: applying AGC table ({} words)", agc_tab.len); PhyTableLoaderJaguar3::Load(agc_tab.data, agc_tab.len, _phy_ctx, bb); + if (timer) timer->stage("table_agc"); /* RF radio tables. On 8822C an RF register write is a direct BB write to a * per-path window: BB[base + (rf_addr&0xff)*4], 20-bit mask, base 0x3c00 @@ -987,9 +1013,9 @@ void HalJaguar3::apply_bb_rf_agc_tables() { auto rf_writer = [this](uint16_t base) { return [this, base](uint32_t addr, uint32_t data) { switch (addr) { - case 0xffe: std::this_thread::sleep_for(std::chrono::milliseconds(50)); return; - case 0xfe: std::this_thread::sleep_for(std::chrono::microseconds(100)); return; - case 0xffff: std::this_thread::sleep_for(std::chrono::microseconds(1)); return; + case 0xffe: _device.flush_writes(); std::this_thread::sleep_for(std::chrono::milliseconds(50)); return; + case 0xfe: _device.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(100)); return; + case 0xffff: _device.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(1)); return; case 0x0: /* RF reg 0x0 (mode register) can't be written through the direct * window — it silently no-ops (hardware-observed on the 8822e). The @@ -1000,8 +1026,16 @@ void HalJaguar3::apply_bb_rf_agc_tables() { _device.rtw_write32(base == 0x4c00 ? 0x4108 : 0x1808, data & RFREG_MASK); return; default: - _device.phy_set_bb_reg(static_cast(base + ((addr & 0xff) << 2)), - RFREG_MASK, data); + /* Plain 20-bit write, not the vendor's read-modify-write under + * MASK20BITS: the direct window's bits [31:20] read back 0 for every + * word of both path windows after a bring-up, on an 8812EU (cold + * and warm) and on an 8812CU (tests/j3_rf_window_readback.sh), so + * an RMW that reads 0 writes exactly `data` and preserving those + * bits is a no-op that cost a synchronous read per entry -- half + * the RF table stage, ~80 ms on the ssc338q. Write-only also + * pipelines (ITransport::write_batch_begin). */ + _device.rtw_write32(static_cast(base + ((addr & 0xff) << 2)), + data & RFREG_MASK); } }; }; @@ -1017,6 +1051,7 @@ void HalJaguar3::apply_bb_rf_agc_tables() { _device.phy_set_bb_reg(0x1c90, 1u << 8, 1); _device.phy_set_bb_reg(0x1830, 1u << 29, 1); _device.phy_set_bb_reg(0x4130, 1u << 29, 1); + if (timer) timer->stage("table_rf_ab"); _logger->info("Jaguar3: BB/AGC/RF tables applied"); } diff --git a/src/jaguar3/HalJaguar3.h b/src/jaguar3/HalJaguar3.h index c160356a..637aa9a7 100644 --- a/src/jaguar3/HalJaguar3.h +++ b/src/jaguar3/HalJaguar3.h @@ -14,6 +14,7 @@ #include "HalmacJaguar3MacInit.h" #include "PhyTableLoaderJaguar3.h" +class InitTimer; /* src/InitTimer.h — stage timer for the bring-up */ namespace jaguar3 { /* HalJaguar3 — Jaguar3 chip bring-up: power sequencing, queue/page/LLT init, BB / @@ -99,7 +100,7 @@ class HalJaguar3 { void power_off(); /* card-disable PWR_SEQ — reset from active state */ void power_on(); /* card-enable PWR_SEQ */ void init_rfk(); /* RF-calibration init (0x1B00 cal_init block) */ - void apply_bb_rf_agc_tables(); /* phydm BB/AGC/RF tables via PhyTableLoader */ + void apply_bb_rf_agc_tables(::InitTimer *timer = nullptr); /* phydm BB/AGC/RF tables via PhyTableLoader; stage checkpoints when given */ void bf_init(); /* rtl8822c_phy_bf_init: BF/MU + NDPA sounding */ void config_phydm_parameter_init(); /* POST_SETTING: 3-wire + OFDM/CCK block */ void enable_tx_path(); /* OFDM/CCK TX block + AGC/path enable (on-air TX) */ diff --git a/src/jaguar3/Halrf8822c.cpp b/src/jaguar3/Halrf8822c.cpp index 2ff581ef..d4409e4c 100644 --- a/src/jaguar3/Halrf8822c.cpp +++ b/src/jaguar3/Halrf8822c.cpp @@ -175,9 +175,14 @@ void Halrf8822c::restore_rf(const uint32_t rf[][2]) { } void Halrf8822c::delay_us(uint32_t us) { + /* A settle is measured from the write reaching the chip, so drain the + * pipelined queue first (free when it is empty; bounded by the queue + * depth when not). The µs sites include 2 ms and 10 ms waits. */ + _device.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(us)); } void Halrf8822c::delay_ms(uint32_t ms) { + _device.flush_writes(); /* the settle time must follow the writes */ std::this_thread::sleep_for(std::chrono::milliseconds(ms)); } diff --git a/src/jaguar3/Halrf8822c.h b/src/jaguar3/Halrf8822c.h index 2c1e5df5..7f9e058a 100644 --- a/src/jaguar3/Halrf8822c.h +++ b/src/jaguar3/Halrf8822c.h @@ -110,8 +110,8 @@ class Halrf8822c : public Jaguar3Calibration { uint8_t mac_read8(uint16_t addr) { return _device.rtw_read8(addr); } uint32_t rf_read(uint8_t path, uint16_t addr, uint32_t mask); void rf_write(uint8_t path, uint16_t addr, uint32_t mask, uint32_t val); - static void delay_us(uint32_t us); - static void delay_ms(uint32_t ms); + void delay_us(uint32_t us); /* drains pipelined writes first */ + void delay_ms(uint32_t ms); /* drains pipelined writes first */ /* --- BTC/GNT indirect-register + IQK trigger/poll primitives --- */ uint32_t btc_wait_ready(); diff --git a/src/jaguar3/Halrf8822e.cpp b/src/jaguar3/Halrf8822e.cpp index b1c08b6f..4191ec0a 100644 --- a/src/jaguar3/Halrf8822e.cpp +++ b/src/jaguar3/Halrf8822e.cpp @@ -84,9 +84,14 @@ void Halrf8822e::rf_write(uint8_t path, uint16_t addr, uint32_t mask, /* --- calibration (Phase C: ported incrementally, hardware-iterated) --- */ void Halrf8822e::delay_us(uint32_t us) { + /* A settle is measured from the write reaching the chip, so drain the + * pipelined queue first (free when it is empty; bounded by the queue + * depth when not). The µs sites include 2 ms and 10 ms waits. */ + _device.flush_writes(); std::this_thread::sleep_for(std::chrono::microseconds(us)); } void Halrf8822e::delay_ms(uint32_t ms) { + _device.flush_writes(); /* the settle time must follow the writes */ std::this_thread::sleep_for(std::chrono::milliseconds(ms)); } diff --git a/src/jaguar3/Halrf8822e.h b/src/jaguar3/Halrf8822e.h index 7b5c2807..c7fe4ce9 100644 --- a/src/jaguar3/Halrf8822e.h +++ b/src/jaguar3/Halrf8822e.h @@ -52,8 +52,8 @@ class Halrf8822e : public Jaguar3Calibration { void mac_write8(uint16_t addr, uint8_t val) { _device.rtw_write8(addr, val); } uint32_t rf_read(uint8_t path, uint16_t addr, uint32_t mask); void rf_write(uint8_t path, uint16_t addr, uint32_t mask, uint32_t val); - static void delay_us(uint32_t us); - static void delay_ms(uint32_t ms); + void delay_us(uint32_t us); /* drains pipelined writes first */ + void delay_ms(uint32_t ms); /* drains pipelined writes first */ /* --- DAC calibration (port of halrf_dac_cal_8822e / halrf_8822e.c) --- * 8822e DACK uses the AFE S0/S1 banks (0x3800/0x3900) rather than 8822c's BB diff --git a/src/jaguar3/RtlJaguar3Device.cpp b/src/jaguar3/RtlJaguar3Device.cpp index e4af4531..2cdf4d6e 100644 --- a/src/jaguar3/RtlJaguar3Device.cpp +++ b/src/jaguar3/RtlJaguar3Device.cpp @@ -1,4 +1,5 @@ #include "RtlJaguar3Device.h" +#include "InitTimer.h" #include #include /* INT_MIN — "no radiotap DBM_TX_POWER" sentinel */ @@ -55,10 +56,23 @@ RtlJaguar3Device::RtlJaguar3Device(RtlAdapter device, Logger_t logger, variant == jaguar3::ChipVariant::C8822E ? "8822E/EU" : "8822C/CU"); } +/* Pipelined register writes for the whole bring-up (ITransport:: + * write_batch_begin): ends on scope exit so a throw never leaves the + * transport in batch mode for the threads that start afterwards. */ +struct WriteBatchScope { + RtlAdapter &dev; + explicit WriteBatchScope(RtlAdapter &d) : dev(d) { dev.write_batch_begin(); } + void end() { dev.write_batch_end(); } + ~WriteBatchScope() { dev.write_batch_end(); } +}; + void RtlJaguar3Device::Init(Action_ParsedRadioPacket packetProcessor, SelectedChannel channel) { _channel = channel; _rx_wanted = true; + /* No WriteBatchScope here (yet): the pipelined bring-up is validated on + * the TX path (InitWrite, cold + warm); the RX-only + * Init path has not been measured with it on a ground-station card. */ _hal.rtw_hal_init(channel); /* full vendor-source bring-up */ /* Tune the channel/bandwidth (5/10 MHz ChannelWidth re-clocks to narrowband), * then run IQK calibration (it reads RF18 for the tuned channel). @@ -735,7 +749,10 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { * race the running TX). */ const bool want_rx = _cfg.rx.enable_with_tx; _rx_wanted = want_rx; + InitTimer timer(_logger, "j3init", [this] { return _device.ctrl_xfers(); }); + WriteBatchScope batch(_device); _hal.rtw_hal_init(channel); /* full vendor-source bring-up */ + timer.stage("hal_init"); /* 8822C at 40/80 MHz: IQK at 20 MHz, then retune — see Init. */ const bool iqk_at_20 = _variant == jaguar3::ChipVariant::C8822C && (channel.ChannelWidth == CHANNEL_WIDTH_40 || @@ -746,7 +763,9 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { SelectedChannel iqk_ch = channel; if (iqk_at_20) iqk_ch.ChannelWidth = CHANNEL_WIDTH_20; /* IQK command set follows the RF */ + timer.stage("set_channel"); _hal.run_iqk(iqk_ch); + timer.stage("iqk"); if (iqk_at_20) _radioManagement.set_channel_bwmode(channel.Channel, channel.ChannelOffset, channel.ChannelWidth); @@ -755,6 +774,7 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { _hal.dpk_force_bypass_8822e(); /* 8822e rfe 21/22: kernel bypasses DPK (after IQK) */ _hal.config_rfe(channel.Channel); /* 8822e RFE/PAPE antenna-switch pins (PA enable) */ _hal.config_channel_8822e(channel.Channel); /* 8822e band TX scaling/backoff + shaping */ + timer.stage("rx_path_rfe_channel"); /* DEVOURER_CW_TONE — a bare RF LO carrier. Armed HERE (before the FW power-mode * / coex H2C steps below, which on the 8812EU at 5 GHz leave the chip NAKing @@ -801,10 +821,12 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { * re-apply at the end of this function; this early one just keeps the * intermediate bring-up steps on sane references. */ apply_tx_power_current(/*full=*/true); + timer.stage("txpower_pre"); _brought_up = true; /* WiFi-only coex bring-up: disable the BT/LTE antenna arbitration and lock the * antenna to WLAN so on-air TX is not killed by the coex firmware. */ _hal.coex_wlan_only_init(); + timer.stage("coex_wlan_only_init"); /* RFE GPIO/pad pinmux — the HalMAC "Config PIN Mux" (halmac_init_8822e) that * devourer's hand-rolled MAC init skips: route + drive the RFE PA-enable / * antenna-switch control pins. Without it the 8822e's PA pins are never driven @@ -825,9 +847,13 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { _device.rtw_write(0x0064, v64 & ~0x02040000u); /* PAD_CTRL1: RFE pads */ } + timer.stage("rfe_pinmux"); _hal.fw_set_pwr_mode_active(); /* keep all FW power domains on (no auto-PS) */ + timer.stage("fw_pwr_mode"); _hal.fw_coex_query_bt_info(); /* make the FW confirm BT is absent */ + timer.stage("fw_coex_query"); _hal.fw_coex_tdma_off(); /* disable coex time-division (WL keeps antenna) */ + timer.stage("fw_coex_tdma_off"); /* DEVOURER_BF_ARM_SOUNDER=1 — beamforming self-sounding probe (beamformer * side): arm the MAC's hardware sounding engine so a TX-descriptor-marked * NDPA (DEVOURER_TX_NDPA=1) is followed by a hardware-generated NDP. The MAC @@ -892,6 +918,7 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { * Applied before the coex thread starts so the writes don't contend. */ if (_cfg.tuning.disable_cca) SetCcaMode(true); + timer.stage("filters_cca"); /* DEVOURER_XTAL_CAP — crystal-cap trim (issue #217); before the coex thread * so the AFE write doesn't contend with the periodic coex re-apply. */ if (_cfg.tuning.xtal_cap) @@ -902,6 +929,7 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { * TX-power state (flat override / offset) only sticks when applied after * them. The coex thread's ~2 s ticks do not rewrite the refs. */ apply_tx_power_current(/*full=*/true); + timer.stage("txpower_post"); /* Per-packet power banks: the BB init table reset 0x1e70 (0x00001000, all * banks disabled) and may have cleared the per-STA RAM — re-sync the * hardware to the planner state (a pre-bring-up SetTxPacketPowerOffsetQdb @@ -931,6 +959,8 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { _device.rtw_read32(a), _device.rtw_read32(a + 4), _device.rtw_read32(a + 8), _device.rtw_read32(a + 12)); } + timer.stage("dpdt_ack_misc"); + batch.end(); /* sync writes from here: the coex thread shares the transport */ _coex_thread = std::thread([this] { coex_runtime_loop(); }); if (_cfg.rx.ack_responder && !SetAckResponder(*_cfg.rx.ack_responder)) /* DEVOURER_ACK_RESPONDER */ @@ -938,6 +968,8 @@ void RtlJaguar3Device::InitWrite(SelectedChannel channel) { "Jaguar3: configured ACK responder could not be armed"); if (_cfg.tx.ampdu) SetAmpduMode(*_cfg.tx.ampdu); /* DEVOURER_TX_AMPDU_MODE */ + timer.stage("coex_thread_ampdu"); + timer.total(); _logger->info("Jaguar3: ready for TX (monitor inject)"); } diff --git a/tests/j3_rf_window_readback.sh b/tests/j3_rf_window_readback.sh new file mode 100755 index 00000000..ca7e3287 --- /dev/null +++ b/tests/j3_rf_window_readback.sh @@ -0,0 +1,70 @@ +#!/usr/bin/env bash +# Does the Jaguar3 RF direct window hold anything above bit 19? +# +# The RF radio tables are applied as plain 20-bit writes to BB[0x3c00/0x4c00 +# + (rf_addr & 0xff) * 4] instead of the vendor's MASK20BITS read-modify- +# write. That is bit-identical to the RMW only if bits [31:20] of every +# window word are not storage the RMW could have preserved. Two legs, per +# die, both through `chipstate --init` (ops run on the configured chip): +# +# 1. histogram: dump both path windows after a bring-up and histogram the +# high 12 bits of every word (expected all 0). On its own this proves +# little, because the write-only load itself clears those bits. +# 2. write-back: for a sample of words in each window, poke the word with +# its high 12 bits SET (low 20 bits unchanged, so the RF register keeps +# its value), read it back, then restore. If the bits are storage they +# read back set and the RMW was preserving real state; if they read back +# 0 the RMW could never have preserved anything. This leg is what +# decides, and it does not depend on which bring-up ran first. +# +# Exit 0 only when both legs say the bits are not storage. +# +# sudo tests/j3_rf_window_readback.sh 0xc812 # 8812CU +# sudo tests/j3_rf_window_readback.sh 0xa81a # 8812EU +set -euo pipefail +PID=${1:?usage: $0 } +ROOT=$(cd "$(dirname "$0")/.." && pwd) +CS=$ROOT/build/chipstate +OUT=${OUT:-/tmp/j3_rf_window_readback}; mkdir -p "$OUT" +SAMPLE=${SAMPLE:-8} # words sampled per path window for the write-back leg +dump=$OUT/pid${PID}.peek +"$CS" --pid "$PID" --init --peek 0x3c00-0x3fff:4 --peek 0x4c00-0x4fff:4 \ + >"$dump" 2>"$dump.err" || { echo "FAIL: chipstate exited non-zero (leg 1)"; tail -5 "$dump.err"; exit 1; } +# leg 1 + the op list for leg 2 (poke set / peek / poke restore per word) +ops=$(python3 - "$dump" "$PID" "$SAMPLE" <<'PY' +import re, sys, collections +words = {} +for line in open(sys.argv[1]): + m = re.match(r'^0x([0-9a-fA-F]{4}):((?:\s+[0-9a-fA-F]{8}){1,4})\s*$', line) + if not m: continue + base = int(m.group(1), 16) + for i, w in enumerate(m.group(2).split()): + words[base + 4 * i] = int(w, 16) +if not words: + print("FAIL: no register rows parsed", file=sys.stderr); sys.exit(1) +hi = collections.Counter(w >> 20 for w in words.values()) +print(f"leg1 pid={sys.argv[2]} words={len(words)} hi12_histogram={dict(sorted(hi.items()))}", file=sys.stderr) +n = int(sys.argv[3]); ops = [] +for base in (0x3c00, 0x4c00): + for a in range(base, base + 4 * n, 4): + v = words[a] + ops += [f"--poke 0x{a:04x}=0x{(v | 0xFFF00000):08x}:4", f"--peek 0x{a:04x}-0x{a+3:04x}:4", f"--poke 0x{a:04x}=0x{v:08x}:4"] +print(" ".join(ops)) +PY +) || exit 1 +wb=$OUT/pid${PID}.writeback +# shellcheck disable=SC2086 +"$CS" --pid "$PID" --init $ops >"$wb" 2>"$wb.err" || { echo "FAIL: chipstate exited non-zero (leg 2)"; tail -5 "$wb.err"; exit 1; } +python3 - "$wb" "$PID" <<'PY' +import re, sys +rows = [(int(m.group(1), 16), int(m.group(2), 16)) for m in + (re.match(r'^0x([0-9a-fA-F]{4}):\s+([0-9a-fA-F]{8})\s*$', l) for l in open(sys.argv[1])) if m] +if not rows: + print("FAIL: no read-back rows parsed"); sys.exit(1) +bad = [(a, v) for a, v in rows if v >> 20] +print(f"leg2 pid={sys.argv[2]} words_poked_with_hi_bits_set={len(rows)} read_back_nonzero_hi={len(bad)}") +for a, v in bad: print(f" 0x{a:04x} -> 0x{v:08x}") +if bad: + print("VERDICT: bits [31:20] ARE storage on this die — keep the MASK20BITS RMW"); sys.exit(1) +print("VERDICT: bits [31:20] are not storage (written 1s read back 0) — the write-only load is bit-identical to the RMW") +PY diff --git a/tests/j3_tx_flood_ab.sh b/tests/j3_tx_flood_ab.sh new file mode 100755 index 00000000..d86fe0e7 --- /dev/null +++ b/tests/j3_tx_flood_ab.sh @@ -0,0 +1,26 @@ +#!/usr/bin/env bash +# TX-side A/B of two devourer trees on one Jaguar3 DUT: N reps of a timed +# txdemo flood per tree, reporting per rep the frames submitted, the bulk-OUT +# failures and the failed synchronous register reads. Alternates trees rep by +# rep so a slow drift in the unit (warm state, ambient) lands on both sides. +# +# sudo tests/j3_tx_flood_ab.sh [reps] [secs] +set -euo pipefail +PID=${1:?pid}; CH=${2:?channel}; A=${3:?treeA}; B=${4:?treeB}; REPS=${5:-3}; SECS=${6:-15} +OUT=${OUT:-/tmp/j3_tx_flood_ab/pid${PID}_ch${CH}}; mkdir -p "$OUT" +run() { + local tree=$1 rep=$2 n; n=$(basename "$tree") + local log=$OUT/${n}_rep${rep} + local rc=0 + env DEVOURER_PID="$PID" DEVOURER_CHANNEL="$CH" DEVOURER_LOG_LEVEL=info \ + timeout -s INT "$SECS" "$tree/build/txdemo" >"$log.jsonl" 2>"$log.err" || rc=$? + # 124 = timeout fired (the normal end), 0/130 = txdemo took the INT itself. + case $rc in 0|124|130) ;; *) echo "$n rep$rep: txdemo exited rc=$rc"; tail -3 "$log.err";; esac + local tx fail rd first + tx=$(grep -cF '"ev":"tx.' "$log.jsonl" || true) + fail=$(grep -c 'bulk_send EP .* FAIL' "$log.err" || true) + rd=$(grep -c 'rtw_read(' "$log.err" || true) + first=$(grep -oE 'first_tx_submit","ms":[0-9]+' "$log.jsonl" | grep -oE '[0-9]+$' || echo '?') + echo "$n rep$rep: first_tx_ms=$first tx_events=$tx bulk_fail=$fail read_fail=$rd" +} +for r in $(seq 1 "$REPS"); do run "$A" "$r"; run "$B" "$r"; done diff --git a/tests/regress.py b/tests/regress.py index 4b10f8d1..b18552c2 100755 --- a/tests/regress.py +++ b/tests/regress.py @@ -217,6 +217,7 @@ def _mediatek_duts() -> dict[str, str]: "0bda:b811": "RTL8811AU", "2357:012d": "RTL8822BU (TP-Link T3U, Jaguar2)", "0bda:b82c": "RTL8822BU (Jaguar2)", + "0bda:b812": "RTL8822BU (CF-924AC V2, Jaguar2)", "0bda:c811": "RTL8821CU (Jaguar2)", "0bda:c812": "RTL8812CU (Jaguar3)", "0bda:c82c": "RTL8822CU (Jaguar3)",