usb: pipelined register writes for the bring-up; Jaguar3 stage timing

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, `<stage>_us`…, total_us |

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';
 }
 
@@ -145,20 +156,43 @@ int run_reg_ops(libusb_device_handle *handle, Logger_t logger,
                 libusb_context *ctx,
                 std::shared_ptr<devourer::UsbDeviceLock> lock,
                 const std::vector<RegOp> &ops) {
-  RtlAdapter adapter(handle, logger, ctx, lock);
   /* A failed vendor-control read throws (UsbTransport::ctrl_read) — on a
    * powered-down or wedged chip that is a real answer about the chip, so
-   * report which op died and exit nonzero instead of terminating. */
+   * report which op died and exit nonzero instead of terminating. The
+   * adapter is built inside the try too: its constructor already reads a
+   * register, and after --init that read is the first thing that can fail. */
   try {
+    RtlAdapter adapter(handle, logger, ctx, lock);
     for (const RegOp &op : ops) {
       if (op.write) {
+        bool ok;
         if (op.width == 4)
-          adapter.rtw_write32(op.addr, op.val);
+          ok = adapter.rtw_write32(op.addr, op.val);
         else if (op.width == 2)
-          adapter.rtw_write16(op.addr, static_cast<uint16_t>(op.val));
+          ok = adapter.rtw_write16(op.addr, static_cast<uint16_t>(op.val));
         else
-          adapter.rtw_write8(op.addr, static_cast<uint8_t>(op.val));
+          ok = adapter.rtw_write8(op.addr, static_cast<uint8_t>(op.val));
+        if (!ok) {
+          /* A write the chip did not take must not print as a poke, or a
+           * following peek reads as a verdict about bits that were never
+           * written. */
+          std::fflush(stdout);
+          logger->error("poke 0x{:04x} (width {}) FAILED — vendor-control "
+                        "write rejected", op.addr, op.width);
+          return 4;
+        }
         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<uint16_t>(i)));
+          }
+          std::printf("\n");
+        }
       } else {
         for (uint32_t row = op.addr & ~0xfu; row <= op.end; row += 16) {
           std::printf("0x%04x:", row);
@@ -254,9 +288,11 @@ int main(int argc, char **argv) {
    * need the interface, so peeks/pokes work while another process (a live
    * armed rxdemo) owns it — the concurrent-intervention mode. */
   if (a.no_claim) {
-    if (a.ops.empty()) {
-      logger->error("--no-claim is peek/poke-only (the canary dump needs the "
-                    "claimed device)");
+    if (a.ops.empty() || a.init) {
+      logger->error(a.init ? "--init needs the claimed-device path; drop "
+                             "--no-claim"
+                           : "--no-claim is peek/poke-only (the canary dump "
+                             "needs the claimed device)");
       session.adopt_handle(handle);
       return 2;
     }
@@ -281,7 +317,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 +339,16 @@ int main(int argc, char **argv) {
     dev->InitWrite(SelectedChannel{.Channel = static_cast<uint8_t>(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");

src/InitTimer.h

@@ -5,11 +5,19 @@
 #include <cstdio>
 #include <utility>
 
+#include <functional>
+
 #include "logger.h"
 
 /* Stage timer for init-path profiling. Emits one event per checkpoint:
  *
- *   {"ev":"init.timing","stage":"<scope>.<stage>","ms":N}
+ *   {"ev":"init.timing","stage":"<scope>.<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,53 @@ 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<uint64_t()>;
+  using Drain = std::function<void()>;
+
+  /* `drain`, when given, runs at the start of every checkpoint: a transport
+   * that queues writes (ITransport::write_batch_begin) completes the stage's
+   * own writes before the stage is measured, so their tail latency is billed
+   * to the stage that issued them, not to the next one. */
+  InitTimer(Logger_t logger, const char *scope, XferCounter xfers = {},
+            Drain drain = {})
+      : _logger{std::move(logger)}, _scope{scope}, _xfers{std::move(xfers)},
+        _drain{std::move(drain)}, _start{clock::now()}, _last{_start},
+        _x_start{count()}, _x_last{_x_start} {}
 
   void stage(const char *name) {
+    if (_drain)
+      _drain();
     const auto now = clock::now();
-    emit(name, ms(_last, now));
+    const auto x = count();
+    emit(name, ms(_last, now), static_cast<long long>(x - _x_last));
     _last = now;
+    _x_last = x;
   }
 
-  void total() { emit("total", ms(_start, clock::now())); }
+  /* Reports the total once. An early return or a throw out of the timed
+   * scope still gets its total from the destructor, so a failed bring-up
+   * carries its cost too; a scope that called total() emits exactly one. */
+  void total() {
+    if (_finalized)
+      return;
+    _finalized = true;
+    if (_drain)
+      _drain();
+    emit("total", ms(_start, clock::now()),
+         static_cast<long long>(count() - _x_start));
+  }
+  ~InitTimer() { total(); }
 
 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 +83,13 @@ class InitTimer {
 
   Logger_t _logger;
   const char *_scope;
+  XferCounter _xfers;
+  Drain _drain;
   clock::time_point _start;
   clock::time_point _last;
+  uint64_t _x_start;
+  uint64_t _x_last;
+  bool _finalized = false;
 };
 
 #endif /* INIT_TIMER_H */

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(); }
+  bool write_batch_end() { return _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

src/Transport.h

@@ -68,6 +68,30 @@ class ITransport {
     return read32(static_cast<uint16_t>(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. The Jaguar3 bring-up is ~14k EP0 round trips; on the
+   * one unit and host measured (an RTL8812EU on an ssc338q) a synchronous
+   * write cost ~80 us and a pipelined one ~27 us at depth >= 8 — one device,
+   * one host, so a scale rather than a number to plan by; the measured
+   * bring-up figures and their limits are in src/jaguar3/CLAUDE.md.
+   * 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.
+   * write_batch_end drains and reports whether every queued write completed
+   * (a failed or short completion is only known after the fact); the caller
+   * decides what an incomplete batch means. Defaults are no-ops (PCIe). */
+  virtual void write_batch_begin() {}
+  virtual bool write_batch_end() { return true; }
+  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