Record each node's radio counters in every experiment cell

docs/verb-reference.md

@@ -3569,7 +3569,7 @@ Write the whole experiment to a file, its definition beside every cell's raw num
 |---|---|---|---|
 | `path` | string | optional, primary | where to write it; empty writes meshbench-experiment.json in the system temporary directory, and a path that cannot be written is refused |
 
-**Answers** `path`, `bytes`. JSON, holding the arms, seeds, senders and timings alongside `results`, which is every cell including the per-second histogram and the at-risk shares, and `summary`, which is the means. It will write an empty one before anything has run.
+**Answers** `path`, `bytes`. JSON, holding the arms, seeds, senders and timings alongside `results`, which is every cell including the per-second histogram, the at-risk shares and `chip`, each node's radio counters at the end of the cell, and `summary`, which is the means. It will write an empty one before anything has run.
 
 **Example** - keep the sweep, wherever the machine puts temporary files
 

internal/app/session/experiment/cell.go

@@ -443,6 +443,7 @@ func runArm(ctx context.Context, s *session.Sim, e *experiment, arm session.ExpA
 	for i := range engine.MarginEdgesDB {
 		out.AtRisk[i] = sens.AtRisk(i)
 	}
+	out.Chip = chipStats(eng)
 	return out
 }
 

internal/app/session/experiment/chipstats.go

@@ -0,0 +1,73 @@
+package experiment
+
+import (
+	"github.com/MeshBench/meshbench/internal/firmware"
+	"github.com/MeshBench/meshbench/internal/sim/engine"
+)
+
+// ChipStats is what each node's chip saw during a cell, summed and per node.
+//
+// Delivery totals say what the mesh did; these say what the firmware was told.
+// They are the only way to tell a busy channel from a radio that cries busy,
+// and - on a chip that applies IrqMask - a firmware that never enabled an
+// interrupt from one that never had cause to see it. Two builds whose radio
+// drivers differ and whose totals agree are not shown to behave alike until
+// these agree too.
+type ChipStats struct {
+	IRQReads      uint64 `json:"irq_reads"`
+	BusyReads     uint64 `json:"busy_reads"`
+	BusyMs        uint64 `json:"busy_ms"`
+	Spurious      uint64 `json:"spurious"`
+	IRQSuppressed uint64 `json:"irq_suppressed"`
+	// Reporting is how many nodes sent a suppressed count at all. A chip that
+	// ignores the mask sends none, and its total of zero means unknown.
+	Reporting int        `json:"suppressed_reporting"`
+	Nodes     []NodeChip `json:"nodes"`
+}
+
+// NodeChip is one node's counters at the end of the cell.
+type NodeChip struct {
+	Name          string `json:"name"`
+	Kind          string `json:"kind"`
+	IRQReads      uint32 `json:"irq_reads"`
+	BusyReads     uint32 `json:"busy_reads"`
+	BusyMs        uint32 `json:"busy_ms"`
+	Spurious      uint32 `json:"spurious"`
+	IRQSuppressed uint32 `json:"irq_suppressed"`
+	Reported      bool   `json:"suppressed_reported"`
+	IRQMask       uint16 `json:"irq_mask"`
+	SF            uint8  `json:"sf"`
+	BandwidthHz   uint32 `json:"bandwidth_hz"`
+}
+
+// chipStats reads every running node's chip. Called before the engine closes,
+// while the bridges still hold the last record each node sent.
+func chipStats(eng *engine.Engine) *ChipStats {
+	out := &ChipStats{}
+	for _, n := range eng.Nodes() {
+		if n.Firmware == nil {
+			continue
+		}
+		out.add(n.Spec().Name, string(n.Spec().Kind), n.Firmware.Bridge.Stats())
+	}
+	return out
+}
+
+// add folds one node's radio record into the cell's counters.
+func (c *ChipStats) add(name, kind string, r firmware.RadioStats) {
+	c.IRQReads += uint64(r.IRQReads)
+	c.BusyReads += uint64(r.BusyReads)
+	c.BusyMs += uint64(r.BusyMs)
+	c.Spurious += uint64(r.SpuriousUp)
+	if r.SuppressedReported {
+		c.IRQSuppressed += uint64(r.IRQSuppressed)
+		c.Reporting++
+	}
+	c.Nodes = append(c.Nodes, NodeChip{
+		Name: name, Kind: kind,
+		IRQReads: r.IRQReads, BusyReads: r.BusyReads, BusyMs: r.BusyMs,
+		Spurious: r.SpuriousUp, IRQSuppressed: r.IRQSuppressed,
+		Reported: r.SuppressedReported, IRQMask: r.IRQMask,
+		SF: r.SF, BandwidthHz: r.BandwidthHz,
+	})
+}

internal/app/session/experiment/chipstats_test.go

@@ -0,0 +1,63 @@
+package experiment
+
+import (
+	"encoding/json"
+	"testing"
+
+	"github.com/MeshBench/meshbench/internal/firmware"
+)
+
+// A cell sums every node's radio counters and keeps one row per node, so two
+// arms whose delivery totals agree can still be told apart by what each
+// firmware was told.
+func TestACellSumsEveryNodesChipAndKeepsEachRow(t *testing.T) {
+	var c ChipStats
+	c.add("A", "companion", firmware.RadioStats{
+		IRQReads: 100, BusyReads: 10, BusyMs: 500, IRQMask: 0x0272,
+		IRQSuppressed: 7, SuppressedReported: true, SF: 8, BandwidthHz: 62500,
+	})
+	c.add("B", "simple-repeater", firmware.RadioStats{
+		IRQReads: 50, BusyReads: 5, BusyMs: 250, IRQMask: 0x0276,
+		IRQSuppressed: 3, SuppressedReported: true, SF: 8, BandwidthHz: 62500,
+	})
+	if c.IRQReads != 150 || c.BusyReads != 15 || c.BusyMs != 750 {
+		t.Errorf("sums: reads %d busy %d busy_ms %d, want 150 15 750", c.IRQReads, c.BusyReads, c.BusyMs)
+	}
+	if c.IRQSuppressed != 10 || c.Reporting != 2 {
+		t.Errorf("suppressed %d from %d nodes, want 10 from 2", c.IRQSuppressed, c.Reporting)
+	}
+	if len(c.Nodes) != 2 || c.Nodes[1].Name != "B" || c.Nodes[1].IRQMask != 0x0276 {
+		t.Errorf("per-node rows: %+v", c.Nodes)
+	}
+}
+
+// A chip that does not count suppressed events adds nothing to the total and
+// is not counted as reporting, so a total of zero is not mistaken for a count
+// of zero.
+func TestAChipThatDoesNotCountIsNotCountedAsReporting(t *testing.T) {
+	var c ChipStats
+	c.add("old", "simple-repeater", firmware.RadioStats{IRQReads: 20, IRQSuppressed: 9})
+	if c.IRQSuppressed != 0 || c.Reporting != 0 {
+		t.Errorf("suppressed %d from %d nodes, want 0 from 0", c.IRQSuppressed, c.Reporting)
+	}
+	if c.Nodes[0].Reported {
+		t.Error("the row says the chip reported a count it does not keep")
+	}
+}
+
+// The counters reach the export under "chip", beside the cell's other numbers.
+func TestTheExportCarriesEachCellsChipCounters(t *testing.T) {
+	r := Result{Arm: "a", Chip: &ChipStats{IRQReads: 1, Nodes: []NodeChip{{Name: "A"}}}}
+	raw, err := json.Marshal(r)
+	if err != nil {
+		t.Fatal(err)
+	}
+	var back map[string]any
+	if err := json.Unmarshal(raw, &back); err != nil {
+		t.Fatal(err)
+	}
+	chip, ok := back["chip"].(map[string]any)
+	if !ok || chip["irq_reads"] != float64(1) {
+		t.Errorf("export row: %s", raw)
+	}
+}

internal/app/session/experiment/matrix.go

@@ -69,6 +69,9 @@ type Result struct {
 	// actually made, so it needs no second arm to compare against and no
 	// assumption about what boosted gain is worth.
 	AtRisk []float64 `json:"at_risk,omitempty"`
+
+	// Chip is what every node's radio reported at the end of the cell.
+	Chip *ChipStats `json:"chip,omitempty"`
 }
 
 // BuildRef identifies one firmware a cell ran: the version the arm asked for

internal/app/session/experiment/results.verbs.json

@@ -45,7 +45,7 @@
       "path",
       "bytes"
     ],
-    "answers": "JSON, holding the arms, seeds, senders and timings alongside `results`, which is every cell including the per-second histogram and the at-risk shares, and `summary`, which is the means. It will write an empty one before anything has run.",
+    "answers": "JSON, holding the arms, seeds, senders and timings alongside `results`, which is every cell including the per-second histogram, the at-risk shares and `chip`, each node's radio counters at the end of the cell, and `summary`, which is the means. It will write an empty one before anything has run.",
     "example": {
       "params": {},
       "what": "keep the sweep, wherever the machine puts temporary files",

internal/app/session/nodestats.go

@@ -161,6 +161,7 @@ func (s *Sim) nodeStats(events []state.Event) []state.NodeStat {
 			r := n.Firmware.Bridge.Stats()
 			st.IRQReads, st.BusyReads = r.IRQReads, r.BusyReads
 			st.BusyMs, st.Spurious = r.BusyMs, r.SpuriousUp
+			st.IRQSuppressed, st.SuppressedReported = r.IRQSuppressed, r.SuppressedReported
 			// The board's own screen, where it has one and has drawn. A board
 			// with no display and one that has drawn nothing both leave this
 			// nil - which of the two it is comes from the board's declaration,

internal/app/session/statrows.go

@@ -41,11 +41,23 @@ func statRows(stats []state.NodeStat) []map[string]any {
 			// a radio that cries busy too readily.
 			"irq_reads": n.IRQReads, "busy_reads": n.BusyReads,
 			"busy_ms": n.BusyMs, "spurious": n.Spurious,
+			// Absent from a chip that ignores IrqMask, for the same reason
+			// the costs above are: it did not count, so there is no zero.
+			"irq_suppressed": suppressedOrNil(n),
 		})
 	}
 	return out
 }
 
+// suppressedOrNil is the chip's masked-event count, or nothing from a chip
+// that does not keep one.
+func suppressedOrNil(n state.NodeStat) any {
+	if !n.SuppressedReported {
+		return nil
+	}
+	return n.IRQSuppressed
+}
+
 // costOrNil is a reading, or nothing where there was no reading to take.
 func costOrNil(measured bool, v float64) any {
 	if !measured {

internal/app/state/network.go

@@ -157,6 +157,11 @@ type NodeStat struct {
 	// a radio that cries busy too readily.
 	IRQReads, BusyReads uint32
 	BusyMs, Spurious    uint32
+	// What the firmware's IrqMask kept out, and whether the chip said:
+	// without the second, a chip too old to count reads as one that counted
+	// nothing.
+	IRQSuppressed      uint32
+	SuppressedReported bool
 
 	// Board is which hardware this node is, empty for a node running a host
 	// build. It is what decides the shape of the Hardware tab: a board's

internal/firmware/bridge.go

@@ -247,6 +247,12 @@ func (b *Bridge) read(c net.Conn) {
 				if n >= 43 {
 					st.ConsoleBaud = binary.BigEndian.Uint32(buf[39:])
 				}
+				// What the firmware's IrqMask kept out, from a chip new enough
+				// to apply the mask at all.
+				if n >= 47 {
+					st.IRQSuppressed = binary.BigEndian.Uint32(buf[43:])
+					st.SuppressedReported = true
+				}
 				b.mu.Lock()
 				b.stats = st
 				b.mu.Unlock()

internal/firmware/radiostats.go

@@ -85,6 +85,17 @@ type RadioStats struct {
 	// sends a shorter record, and a zero DIO1 mask is a legal thing for a chip to
 	// be holding before the firmware has configured it.
 	DIO1Reported bool
+
+	// IRQSuppressed counts events the chip had to raise and the firmware's
+	// IrqMask kept out of the status register. A masked event is silence, and
+	// silence reads exactly like a quiet channel: a firmware that never
+	// enabled PREAMBLE_DETECTED and one that never heard a preamble report the
+	// same busy figures, and only this separates them.
+	//
+	// SuppressedReported is false for a chip older than the count, which
+	// ignored the mask and so had nothing to suppress - not zero, unknown.
+	IRQSuppressed      uint32
+	SuppressedReported bool
 }
 
 // FemState is whether a board's front-end module was in circuit when the node

internal/firmware/radiostats_test.go

@@ -0,0 +1,64 @@
+package firmware
+
+import (
+	"encoding/binary"
+	"testing"
+	"time"
+)
+
+// statsRecord is a kRadioStats payload of n bytes with IRQReads set to 7 and,
+// where the record is long enough to carry it, a suppressed count of 41.
+func statsRecord(n int) []byte {
+	p := make([]byte, n)
+	binary.BigEndian.PutUint32(p[0:], 7)
+	if n >= 47 {
+		binary.BigEndian.PutUint32(p[43:], 41)
+	}
+	return p
+}
+
+// statsAfter sends one stats record and waits for the bridge to have read it.
+func statsAfter(t *testing.T, record []byte) RadioStats {
+	t.Helper()
+	b, err := Listen("127.0.0.1:0", "GB7XYZ")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer func() { _ = b.Close() }()
+	c := fakeRadio(t, b.Addr())
+	defer func() { _ = c.Close() }()
+
+	hdr := []byte{kindRadioStats, byte(len(record) >> 8), byte(len(record))}
+	if _, err := c.Write(append(hdr, record...)); err != nil {
+		t.Fatal(err)
+	}
+	deadline := time.Now().Add(2 * time.Second)
+	for time.Now().Before(deadline) {
+		if st := b.Stats(); st.IRQReads == 7 {
+			return st
+		}
+		time.Sleep(5 * time.Millisecond)
+	}
+	t.Fatal("the stats record never reached the bridge")
+	return RadioStats{}
+}
+
+// A chip that applies IrqMask says how much it kept out. A masked event is
+// silence, so without the count a firmware that never enabled an interrupt
+// and one that never had cause to see it report the same busy figures.
+func TestTheSuppressedCountIsReadFromAChipThatKeepsOne(t *testing.T) {
+	st := statsAfter(t, statsRecord(47))
+	if !st.SuppressedReported || st.IRQSuppressed != 41 {
+		t.Errorf("suppressed = %d, reported %v; want 41, true",
+			st.IRQSuppressed, st.SuppressedReported)
+	}
+}
+
+// An older chip ignored the mask and sends the shorter record. Its count is
+// unknown rather than zero, because it had nothing to suppress.
+func TestAnOlderChipLeavesTheSuppressedCountUnreported(t *testing.T) {
+	st := statsAfter(t, statsRecord(43))
+	if st.SuppressedReported {
+		t.Errorf("a 43-byte record reported a suppressed count of %d", st.IRQSuppressed)
+	}
+}

pkg/client-python/meshbench/types.py

@@ -119,6 +119,10 @@ class NodeStat:
     busy_reads: int = 0
     busy_ms: int = 0
     spurious: int = 0
+    #: Events the firmware's IrqMask kept out of the chip's status register.
+    #: None from a chip that does not count them, which is not the same as
+    #: counting none.
+    irq_suppressed: int | None = None
 
     @classmethod
     def parse(cls, raw: dict[str, Any]) -> NodeStat:

pkg/client-python/tests/test_client.py

@@ -456,6 +456,15 @@ def test_scheduling_and_asserting(wb):
     assert "best case" in str(report)
 
 
+def test_a_suppressed_count_is_none_unless_the_chip_kept_one():
+    """Absent is unknown, not zero: an older chip ignored the mask entirely."""
+    counted = meshbench.types.NodeStat.parse({"name": "a", "irq_suppressed": 41})
+    assert counted.irq_suppressed == 41
+    uncounted = meshbench.types.NodeStat.parse({"name": "b", "irq_suppressed": None})
+    assert uncounted.irq_suppressed is None
+    assert meshbench.types.NodeStat.parse({"name": "c"}).irq_suppressed is None
+
+
 def test_no_assertions_is_not_a_pass():
     """A green tick that checked nothing is the worst outcome available."""
     empty = meshbench.Report()
@@ -513,6 +522,9 @@ def test_node_stats_carry_the_rows(wb):
     assert stats[0].name
     assert not stats[0].running
     assert stats[0].state == "stopped"
+    # A node with no chip running has counted nothing, and says so as None
+    # rather than as a zero.
+    assert stats[0].irq_suppressed is None
 
 
 def test_the_clock_advances_and_stops(wb):