From fdcbe80056b628dd5bc5eae3138b546273848215 Mon Sep 17 00:00:00 2001 From: MCKero Date: Sat, 29 Aug 2026 08:00:27 +0100 Subject: [PATCH] Model TIM2, so millis() advances and timeouts can expire Second finding from the audit. TIM2 was covered by the catch-all stub, which returns the last value written, so uint32_t millis(void) { return LL_TIM_GetCounter(TIM2); } returned 0 forever. All 17 call sites that measure elapsed milliseconds could never see time pass -- a silent wrong answer rather than a hang, which is harder to notice and was not noticed. The counter is derived on read from QEMU_CLOCK_VIRTUAL rather than stored, with CR1.CEN starting and freezing it and a CNT write rebasing it. Guest time here is not proportional to wall time anyway, and code measuring elapsed milliseconds wants something advancing at roughly the rate a human sees; this is explicitly not for anything needing cycle accuracy. Measured: 24358 ms, then 29527 ms five seconds later -- 5169 ms elapsed, so the rate is right rather than merely non-zero. The test checks the rate for that reason: a counter ticking at the wrong speed would satisfy "non-zero" and "increasing" and still break every timeout. AGENTS.md now carries the audit itself: a table of what the firmware actually drives against what is modelled versus stubbed, and the point that answering reads is not the same as being reproduced. The honest summary is that the digital side the firmware depends on is reproduced, and the analogue side is not and cannot be. Full run: 15 passed, 0 failed. --- AGENTS.md | 38 ++++++++++ README.md | 3 + qemu/py32f071.c | 142 +++++++++++++++++++++++++++++++++++- tools/run_tests.sh | 1 + tools/test_millis.py | 168 +++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 351 insertions(+), 1 deletion(-) create mode 100755 tools/test_millis.py diff --git a/AGENTS.md b/AGENTS.md index 215bc90..571d45c 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -510,6 +510,44 @@ plausible way to stall a scan, and the S-meter work made the receiver always bus Page 4 is *not* the meter row, incidentally — it stayed byte-identical across all six samples while the frequency changed. +### What is actually reproduced, and what only answers reads + +Written after a fair criticism: progress reports kept saying what *runs* rather than +what is genuinely reproduced. Those are different, and the gap is easy to hide. + +Counted from the firmware's own call sites: + +| peripheral | call sites | state | +|---|---|---| +| GPIO | 55 | modelled | +| DMA | 59 | modelled, over the CPU's address space | +| SPI | 33 | modelled, with the flash | +| TIM | 23 | **stub** — backlight PWM and `millis()` | +| ADC | 19 | modelled; result settable since `e46cae2` | +| USART | 11 | modelled both directions | +| RTC, IWDG, WWDG, I2C, USB, CRC, EXTI, PWR | 0 | stub, and the firmware never uses them | + +Plus, outside the SoC: the keypad, the BK4819 register interface, and the audio enable +line. + +**A stub accepts writes and returns the last value.** That is enough not to hang and +nothing more. The distinction matters because it is invisible from above: the ADC was +*modelled*, and still returned a hardcoded 2200 forever, so `gBatteryDisplayLevel`, +`gLowBattery` and the low-battery popup were unreachable. Answering reads is not the +same as being reproduced. + +The honest summary is that **the digital side the firmware depends on is reproduced, and +the analogue side is not and cannot be**. Frequency, flash, keypad, serial, register +programming, battery — all real. Audio samples and RF behaviour — no data exists to +model, in the MCU's address space or in any public datasheet. + +Two stubs are worth a look if more coverage is wanted, in order: + +1. **TIM** — 23 call sites. `millis()` reads TIM2 as a free-running counter and + `backlight.c` drives PWM. Timeouts and backlight dimming currently cannot be + exercised. +2. **EXTI** — zero call sites today, but any interrupt-driven rework would need it. + ### Audio: there is nothing to model, and that is the finding "Add a speaker and a microphone, then grant the browser audio permission" is the diff --git a/README.md b/README.md index a5153e0..7fedd8a 100644 --- a/README.md +++ b/README.md @@ -45,6 +45,7 @@ has no public datasheet, so its driver is the only specification available. | S-meter | works via monitor (SIDE1); reads -53 dBm, S9+40 | | PTT and transmit | works; TX annunciator, timer, and mic level bar | | Speaker / microphone audio | **no samples exist to model**, see [Audio](#audio) | +| `millis()` / TIM2 | works; advances at roughly wall-clock rate | | Timing accuracy | deliberately wrong, see [Timing](#timing) | | Analogue RF behaviour | **not modelled and never will be**, see [AGENTS.md](AGENTS.md#the-bk4819-and-where-modelling-it-stops) | @@ -89,6 +90,7 @@ keypresses silently stop working. Run the test after touching that code; test_scan.py a busy band does not stall a scan test_audio_path.py the amplifier turns on when the firmware wants sound test_battery.py battery level and low-battery follow the ADC + test_millis.py millis() advances, so timeouts can expire run_tests.sh runs all of the above, build-checked first test_run_tests.sh that the runner actually notices failures lib_kill_emulator.sh cleanup that only ever kills emulators @@ -148,6 +150,7 @@ that was never compiled. Individual tests still run standalone: python3 tools/test_scan.py python3 tools/test_audio_path.py python3 tools/test_battery.py + python3 tools/test_millis.py This matters more than it looks. The keypad can break silently under -O2 without any compiler warning -- see the `volatile` note in [Status](#status) -- so a clean diff --git a/qemu/py32f071.c b/qemu/py32f071.c index af53462..0e34d71 100644 --- a/qemu/py32f071.c +++ b/qemu/py32f071.c @@ -2147,6 +2147,128 @@ static void py32_adc_class_init(ObjectClass *klass, void *data) "raw 12-bit ADC conversion result, which the firmware reads as battery voltage"); } +/* ------------------------------------------------------------------ TIM2 */ + +/* + * TIM2 as a free-running counter, which is what the firmware's millis() reads. + * + * driver/millis.c programs a prescaler of SystemCoreClock/1000 and an auto-reload of + * 0xFFFFFFFF, then reads CNT directly: + * + * uint32_t millis(void) { return LL_TIM_GetCounter(TIM2); } + * + * A stub returns whatever was last written, so millis() sat at 0 forever and every + * timeout built on it -- 17 call sites -- could never expire. That is a silent wrong + * answer rather than a hang, which is the harder kind to notice. + * + * The count comes from the host clock rather than guest cycles. Guest time here is not + * proportional to wall time anyway (see the SysTick note in README.md), and code that + * measures elapsed milliseconds wants something that advances at roughly the rate a + * human observes. Do not use this to check anything that needs cycle accuracy. + */ +#define TYPE_PY32_TIM2 "py32-tim2" +OBJECT_DECLARE_SIMPLE_TYPE(PY32Tim2State, PY32_TIM2) + +struct PY32Tim2State { + SysBusDevice parent_obj; + MemoryRegion iomem; + uint32_t regs[0x20]; + int64_t started_ms; /* host time at which the counter was enabled */ + uint32_t offset; /* what CNT was set to when that happened */ + bool running; +}; + +#define TIM_CR1 0x00 +#define TIM_CNT 0x24 +#define TIM_PSC 0x28 +#define TIM_ARR 0x2C + +#define TIM_CR1_CEN (1u << 0) + +static uint32_t py32_tim2_count(PY32Tim2State *s) +{ + if (!s->running) { + return s->offset; + } + const int64_t now = qemu_clock_get_ms(QEMU_CLOCK_VIRTUAL); + return s->offset + (uint32_t)(now - s->started_ms); +} + +static uint64_t py32_tim2_read(void *opaque, hwaddr addr, unsigned size) +{ + PY32Tim2State *s = opaque; + const unsigned idx = addr >> 2; + + if (addr == TIM_CNT) { + return py32_tim2_count(s); + } + return idx < ARRAY_SIZE(s->regs) ? s->regs[idx] : 0; +} + +static void py32_tim2_write(void *opaque, hwaddr addr, uint64_t value, unsigned size) +{ + PY32Tim2State *s = opaque; + const unsigned idx = addr >> 2; + + if (idx >= ARRAY_SIZE(s->regs)) { + return; + } + + switch (addr) { + case TIM_CNT: + /* Writing CNT rebases the count, so millis() can be reset. */ + s->offset = value; + s->started_ms = qemu_clock_get_ms(QEMU_CLOCK_VIRTUAL); + break; + case TIM_CR1: + if ((value & TIM_CR1_CEN) && !s->running) { + s->offset = py32_tim2_count(s); + s->started_ms = qemu_clock_get_ms(QEMU_CLOCK_VIRTUAL); + s->running = true; + } else if (!(value & TIM_CR1_CEN) && s->running) { + /* Freeze at the current value rather than snapping back to zero. */ + s->offset = py32_tim2_count(s); + s->running = false; + } + break; + } + s->regs[idx] = value; +} + +static const MemoryRegionOps py32_tim2_ops = { + .read = py32_tim2_read, + .write = py32_tim2_write, + .endianness = DEVICE_LITTLE_ENDIAN, + .valid.min_access_size = 4, + .valid.max_access_size = 4, +}; + +static void py32_tim2_reset(DeviceState *dev) +{ + PY32Tim2State *s = PY32_TIM2(dev); + + memset(s->regs, 0, sizeof(s->regs)); + s->offset = 0; + s->started_ms = 0; + s->running = false; +} + +static void py32_tim2_init(Object *obj) +{ + PY32Tim2State *s = PY32_TIM2(obj); + + memory_region_init_io(&s->iomem, obj, &py32_tim2_ops, s, TYPE_PY32_TIM2, 0x400); + sysbus_init_mmio(SYS_BUS_DEVICE(obj), &s->iomem); +} + +static void py32_tim2_class_init(ObjectClass *klass, void *data) +{ + DeviceClass *dc = DEVICE_CLASS(klass); + + dc->reset = py32_tim2_reset; + dc->desc = "PY32F071 TIM2, the millisecond counter behind millis()"; +} + /* * Peripherals the firmware touches during init but whose behaviour it does not * depend on yet (FLASH latency, PWR, SYSCFG, EXTI, CRC, timers, I2C, ADC). @@ -2383,6 +2505,7 @@ struct PY32F071State { PY32RccState rcc; PY32GpioState gpio[PY32_NUM_GPIO]; PY32AdcState adc; + PY32Tim2State tim2; PY32SpiState spi[2]; PY32DmaState dma; PY32StubState stub[PY32_NUM_STUB]; @@ -2410,7 +2533,6 @@ static const struct { const char *name; hwaddr base; uint32_t size; } py32_stubs { "i2c1", PY32_I2C1_BASE, 0x400 }, { "i2c2", PY32_I2C2_BASE, 0x400 }, { "tim1", PY32_TIM1_BASE, 0x400 }, - { "tim2", PY32_TIM2_BASE, 0x400 }, { "tim3", PY32_TIM3_BASE, 0x400 }, { "tim6", PY32_TIM6_BASE, 0x400 }, { "tim7", PY32_TIM7_BASE, 0x400 }, @@ -2440,6 +2562,7 @@ static void py32f071_soc_init(Object *obj) object_initialize_child(obj, "armv7m", &s->armv7m, TYPE_ARMV7M); object_initialize_child(obj, "rcc", &s->rcc, TYPE_PY32_RCC); object_initialize_child(obj, "adc", &s->adc, TYPE_PY32_ADC); + object_initialize_child(obj, "tim2", &s->tim2, TYPE_PY32_TIM2); object_initialize_child(obj, "spi1", &s->spi[0], TYPE_PY32_SPI); object_initialize_child(obj, "spi2", &s->spi[1], TYPE_PY32_SPI); object_initialize_child(obj, "dma1", &s->dma, TYPE_PY32_DMA); @@ -2512,6 +2635,16 @@ static void py32f071_soc_realize(DeviceState *dev_soc, Error **errp) memory_region_add_subregion(&s->container, PY32_ADC1_BASE, sysbus_mmio_get_region(SYS_BUS_DEVICE(&s->adc), 0)); + /* + * TIM2 gets a real model rather than the catch-all stub: millis() reads its counter + * directly, and a stub left that at 0 forever. + */ + if (!sysbus_realize(SYS_BUS_DEVICE(&s->tim2), errp)) { + return; + } + memory_region_add_subregion(&s->container, PY32_TIM2_BASE, + sysbus_mmio_get_region(SYS_BUS_DEVICE(&s->tim2), 0)); + static const hwaddr spi_bases[2] = { PY32_SPI1_BASE, PY32_SPI2_BASE }; static const char *spi_names[2] = { "1", "2" }; for (int i = 0; i < 2; i++) { @@ -2878,6 +3011,13 @@ static const TypeInfo py32_types[] = { .instance_init = py32_spi_init, .class_init = py32_spi_class_init, }, + { + .name = TYPE_PY32_TIM2, + .parent = TYPE_SYS_BUS_DEVICE, + .instance_size = sizeof(PY32Tim2State), + .instance_init = py32_tim2_init, + .class_init = py32_tim2_class_init, + }, { .name = TYPE_PY32_ADC, .parent = TYPE_SYS_BUS_DEVICE, diff --git a/tools/run_tests.sh b/tools/run_tests.sh index 64e868b..786678a 100755 --- a/tools/run_tests.sh +++ b/tools/run_tests.sh @@ -87,6 +87,7 @@ run "PTT" python3 tools/test_ptt.py run "scan" python3 tools/test_scan.py run "audio path" python3 tools/test_audio_path.py run "battery" python3 tools/test_battery.py +run "millis" python3 tools/test_millis.py run "serial receive" python3 tools/test_serial_rx.py run "flash persistence" python3 tools/test_flash_persist.py run "frequency entry" python3 tools/test_freq_entry.py diff --git a/tools/test_millis.py b/tools/test_millis.py new file mode 100755 index 0000000..5bc5c09 --- /dev/null +++ b/tools/test_millis.py @@ -0,0 +1,168 @@ +#!/usr/bin/env python3 +"""millis() must advance, because 17 call sites build timeouts on it. + +Found by auditing what the emulator genuinely reproduces rather than what merely runs. +TIM2 was covered by the catch-all stub, which returns the last value written -- so + + uint32_t millis(void) { return LL_TIM_GetCounter(TIM2); } + +returned 0 forever and no elapsed-time check could ever fire. A silent wrong answer, +not a hang, which is the harder kind to spot. + +Checked here: + 1. the counter is non-zero once the firmware has been running a while + 2. it increases between two samples + 3. it increases by roughly the elapsed wall time, not some arbitrary amount + +Point 3 is what separates a working counter from one that merely changes: a counter +ticking at the wrong rate would satisfy 1 and 2 and still break every timeout. +""" + +import gzip +import json +import os +import pathlib +import socket +import subprocess +import sys +import tempfile +import time + +SIM = pathlib.Path(__file__).resolve().parent.parent +QEMU = pathlib.Path(os.environ.get( + "QEMU", "/root/qemu-build/qemu-7.2+dfsg/build/qemu-system-arm")) +ELF = pathlib.Path(os.environ.get( + "ELF", "/root/uvk5-port/uvk5-sat/build/CW/nr7y.cw.elf")) +PRISTINE = SIM / "assets/pristine/flash-pristine.img.gz" + +BOOT_SECONDS = 24 +TIM2_CNT = 0x40000024 # TIM2 base + CNT offset +GAP = 5.0 + + +class Qmp: + def __init__(self, path): + self.s = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) + self.s.settimeout(25) + self.s.connect(path) + self.buf = b"" + self._read() + self.cmd("qmp_capabilities") + + def _read(self): + while b"\n" not in self.buf: + chunk = self.s.recv(65536) + if not chunk: + raise RuntimeError("QMP closed") + self.buf += chunk + line, self.buf = self.buf.split(b"\n", 1) + return json.loads(line) + + def cmd(self, name, **args): + msg = {"execute": name} + if args: + msg["arguments"] = args + self.s.sendall(json.dumps(msg).encode() + b"\n") + while True: + reply = self._read() + if "return" in reply or "error" in reply: + return reply + + +def read_counter(port): + """TIM2's CNT, via gdb. + + Read through the CPU so the peripheral's read handler runs -- the count is derived + on access, not stored, so dumping memory another way would miss it. + """ + out = subprocess.run( + ["gdb-multiarch", "-batch", + "-ex", "set confirm off", "-ex", "set pagination off", + "-ex", f"target remote :{port}", + "-ex", f'printf "CNT=%u\\n", *(unsigned int*){TIM2_CNT}', + "-ex", "detach", "-ex", "quit", str(ELF)], + capture_output=True, text=True, timeout=90) + for line in out.stdout.splitlines(): + if line.startswith("CNT="): + return int(line[4:]) + return None + + +def main(): + for tool in (QEMU, ELF, PRISTINE): + if not tool.exists(): + print(f"SKIP missing {tool}") + return 0 + + port = 1263 + with tempfile.TemporaryDirectory() as tmp: + img = pathlib.Path(tmp) / "flash.img" + img.write_bytes(gzip.decompress(PRISTINE.read_bytes())) + sock = pathlib.Path(tmp) / "qmp.sock" + + proc = subprocess.Popen( + [str(QEMU), "-M", f"uv-k5-v3,flash-image={img}", + "-nographic", "-monitor", "none", + "-qmp", f"unix:{sock},server=on,wait=off", + "-kernel", str(ELF), "-gdb", f"tcp::{port}"], + stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL) + try: + for _ in range(BOOT_SECONDS * 4): + if sock.exists(): + break + time.sleep(0.25) + else: + print("FAIL QMP socket never appeared") + return 1 + time.sleep(BOOT_SECONDS) + + failures = 0 + + first = read_counter(port) + print(f"millis() sample 1: {first}") + if first is None: + print("FAIL could not read TIM2") + return 1 + if first == 0: + print("FAIL the counter is still 0; TIM2 is not running") + failures += 1 + else: + print("PASS the counter is running") + + time.sleep(GAP) + second = read_counter(port) + print(f"millis() sample 2: {second} (after {GAP:.0f}s)") + + delta = second - first + if delta > 0: + print(f"PASS it advanced by {delta} ms") + else: + print(f"FAIL it did not advance ({first} -> {second})") + failures += 1 + + # Generous bounds: the guest is paused twice by gdb, and the emulator does + # not track wall time exactly. The point is to catch a counter running at + # completely the wrong rate, not to measure precision. + low, high = GAP * 1000 * 0.3, GAP * 1000 * 3.0 + if low <= delta <= high: + print(f"PASS the rate is plausible " + f"({delta} ms for {GAP:.0f}s of wall time)") + else: + print(f"FAIL the rate is wrong: {delta} ms elapsed over " + f"{GAP:.0f}s, expected roughly {int(GAP * 1000)}") + failures += 1 + + if failures: + return 1 + print("\nmillis() advances at a usable rate") + return 0 + finally: + proc.terminate() + try: + proc.wait(timeout=10) + except subprocess.TimeoutExpired: + proc.kill() + + +if __name__ == "__main__": + sys.exit(main())