diff --git a/docs/verb-reference.md b/docs/verb-reference.md index 3ded8759..8824c4b8 100644 --- a/docs/verb-reference.md +++ b/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 diff --git a/internal/app/session/experiment/cell.go b/internal/app/session/experiment/cell.go index 47456d7e..b61a3a48 100644 --- a/internal/app/session/experiment/cell.go +++ b/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 } diff --git a/internal/app/session/experiment/chipstats.go b/internal/app/session/experiment/chipstats.go new file mode 100644 index 00000000..b606c5a4 --- /dev/null +++ b/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, + }) +} diff --git a/internal/app/session/experiment/chipstats_test.go b/internal/app/session/experiment/chipstats_test.go new file mode 100644 index 00000000..7c27704a --- /dev/null +++ b/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) + } +} diff --git a/internal/app/session/experiment/matrix.go b/internal/app/session/experiment/matrix.go index dcf22ad1..364d22a4 100644 --- a/internal/app/session/experiment/matrix.go +++ b/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 diff --git a/internal/app/session/experiment/results.verbs.json b/internal/app/session/experiment/results.verbs.json index 31f1f3d3..c880ed79 100644 --- a/internal/app/session/experiment/results.verbs.json +++ b/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", diff --git a/internal/app/session/nodestats.go b/internal/app/session/nodestats.go index 540bac12..edd0a142 100644 --- a/internal/app/session/nodestats.go +++ b/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, diff --git a/internal/app/session/statrows.go b/internal/app/session/statrows.go index 2957ff05..bc405719 100644 --- a/internal/app/session/statrows.go +++ b/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 { diff --git a/internal/app/state/network.go b/internal/app/state/network.go index 959f9ca7..57113260 100644 --- a/internal/app/state/network.go +++ b/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 diff --git a/internal/firmware/bridge.go b/internal/firmware/bridge.go index a9f1f994..13be433b 100644 --- a/internal/firmware/bridge.go +++ b/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() diff --git a/internal/firmware/radiostats.go b/internal/firmware/radiostats.go index bb2ea22c..b0f84981 100644 --- a/internal/firmware/radiostats.go +++ b/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 diff --git a/internal/firmware/radiostats_test.go b/internal/firmware/radiostats_test.go new file mode 100644 index 00000000..2ea83cb5 --- /dev/null +++ b/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) + } +} diff --git a/pkg/client-python/meshbench/types.py b/pkg/client-python/meshbench/types.py index fdaa7c54..6cda3f69 100644 --- a/pkg/client-python/meshbench/types.py +++ b/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: diff --git a/pkg/client-python/tests/test_client.py b/pkg/client-python/tests/test_client.py index 4a27c2b9..e931502e 100644 --- a/pkg/client-python/tests/test_client.py +++ b/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):