From fc44b9c911ea9e92e197e294fc9c3696c3c6f2a5 Mon Sep 17 00:00:00 2001 From: PurpleSentinel <199351535+PurpleSentinel@users.noreply.github.com> Date: Fri, 16 Oct 2026 22:00:08 +0100 Subject: [PATCH 1/2] Revert "feat(ui): give the G radar a three-second trace, and measure what drawing it costs (#211)" This reverts commit 48222a96f5cc5fedaedfcff06be5e1e27c0510cb. --- CHANGELOG.md | 26 -------- firmware/components/display/panel_esp.cpp | 66 ------------------- .../ui/include/track_timer/ui/imu_meter.hpp | 15 +---- firmware/main/screen_router.cpp | 51 -------------- tests/cpp/test_imu_meter.cpp | 21 +----- 5 files changed, 3 insertions(+), 176 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 127ee86..d88149e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -246,32 +246,6 @@ The project follows Semantic Versioning once the first firmware release is tagge ### Changed -- the G radar's trace now covers **three seconds instead of 1.2**, and its length is - derived from the display cadence rather than stated as a bare count. `kImuTrailCapacity` - was `24`, which reads like a few seconds and was not: the trail is appended once per - display service, so at 20 Hz it held 1.2 s. The span is now what gets chosen - (`kImuTrailSpanMs = 3'000`, picked because a corner in a Seven runs two to four seconds, - so the driver sees the corner they just took) and the capacity follows from it. A - `static_assert` ties the assumed cadence to the real `kDisplayServicePeriodUs`, so - changing the display period fails the build instead of silently rescaling the trace -- **render cost is measured rather than assumed**, which is what let the change above be - made safely. Two periodic log lines: `radar:` times the object work at the call site, - and `draw:` times `lv_timer_handler` in the panel task, which is where drawing actually - happens - repositioning an object only marks an area dirty. Measured on hardware: - - | | 24 points | 60 points | - |---|---|---| - | object work, mean | 1,727 us | 2,395 us | - | share of the 50 ms display period | 3% | 4% | - | worst repaint | 23,597-23,813 us | 24,255-24,287 us | - - Tripling the trace cost **2.3% more repaint time**, because 24 dots already spanned the - whole radar and the invalidated area was already saturated. Per-point object cost works - out at 18.6 us against a fixed 1.28 ms for the rings, labels and markers, so the dots - were never the expensive part. Without the measurement the obvious reading - 150% more - objects, so expect 150% more work - would have argued against a change that is nearly - free - - the receiver now runs at **25 Hz**. Measured on hardware: 24.9 Hz observed, 57 frames, 57 accepted, nothing rejected, no checksum errors, and 40 ms read back from the receiver's flash layer. The part was never in doubt - it was separately measured at diff --git a/firmware/components/display/panel_esp.cpp b/firmware/components/display/panel_esp.cpp index cacac2f..95ce448 100644 --- a/firmware/components/display/panel_esp.cpp +++ b/firmware/components/display/panel_esp.cpp @@ -6,7 +6,6 @@ #include "esp_lcd_panel_vendor.h" #include "esp_lcd_sh8601.h" #include "driver/gpio.h" -#include "esp_log.h" #include "esp_timer.h" #include "freertos/FreeRTOS.h" #include "freertos/semphr.h" @@ -125,64 +124,6 @@ void round_invalidated_area(lv_event_t* event) noexcept void tick(void*) noexcept { lv_tick_inc(kLvglTickPeriodMs); } -// Windowed by time rather than by call count. The handler is called at the minimum delay -// whether or not there is anything to draw, so a count-based window reports every few -// tens of milliseconds and buries the log, while saying nothing about how often a real -// redraw happens. -constexpr std::int64_t kDrawCostReportPeriodUs = 10'000'000; -// Above this, a handler call did real drawing rather than finding nothing dirty. The -// separation is stark in practice - no-op calls are single-digit microseconds and a -// redraw is thousands - so the exact threshold does not matter much. -constexpr std::int64_t kDrawCostRedrawThresholdUs = 5'000; -std::uint32_t draw_cost_count = 0; -std::uint32_t draw_cost_redraws = 0; -std::int64_t draw_cost_total_us = 0; -std::int64_t draw_cost_worst_us = 0; -std::int64_t draw_cost_window_started_us = 0; - -void record_draw_cost(const std::int64_t elapsed_us) noexcept -{ - draw_cost_count += 1; - draw_cost_total_us += elapsed_us; - if (elapsed_us > draw_cost_worst_us) { - draw_cost_worst_us = elapsed_us; - } - if (elapsed_us >= kDrawCostRedrawThresholdUs) { - draw_cost_redraws += 1; - } - const auto now_us = esp_timer_get_time(); - if (draw_cost_window_started_us == 0) { - draw_cost_window_started_us = now_us; - return; - } - const auto window_us = now_us - draw_cost_window_started_us; - if (window_us < kDrawCostReportPeriodUs) { - return; - } - // The worst call is measured against the service period rather than reported alone, - // because this task also dispatches the UI service: drawing that overruns the period - // delays everything else on this task, and starving it is the failure #133 and #141 - // were. - ESP_LOGI("track_timer", - "draw: %u calls in %lld ms, %u redraws (%lld per 10 s), mean %lld us, " - "worst %lld us (%lld us service period, worst %u%%)", - static_cast(draw_cost_count), - static_cast(window_us / 1000), - static_cast(draw_cost_redraws), - static_cast(static_cast(draw_cost_redraws) * - kDrawCostReportPeriodUs / window_us), - static_cast(draw_cost_total_us / - static_cast(draw_cost_count)), - static_cast(draw_cost_worst_us), - static_cast(kServicePeriodUs), - static_cast(draw_cost_worst_us * 100 / kServicePeriodUs)); - draw_cost_count = 0; - draw_cost_redraws = 0; - draw_cost_total_us = 0; - draw_cost_worst_us = 0; - draw_cost_window_started_us = now_us; -} - void lvgl_task(void*) noexcept { auto delay_ms = kLvglMinDelayMs; @@ -198,14 +139,7 @@ void lvgl_task(void*) noexcept service_callback(); } } - // What #136 asked for a measurement of. lv_timer_handler is where the - // drawing actually happens - repositioning an object only marks an area - // dirty - so the cost of a trace redrawn through a 96,000-byte stripe buffer - // shows up here and nowhere else. Reported as a periodic summary, so whatever - // screen the device is sitting on is the screen being measured. - const auto draw_started_us = esp_timer_get_time(); delay_ms = lv_timer_handler(); - record_draw_cost(esp_timer_get_time() - draw_started_us); unlock(); } if (delay_ms > kLvglMaxDelayMs) { diff --git a/firmware/components/ui/include/track_timer/ui/imu_meter.hpp b/firmware/components/ui/include/track_timer/ui/imu_meter.hpp index 6c32526..7f48b98 100644 --- a/firmware/components/ui/include/track_timer/ui/imu_meter.hpp +++ b/firmware/components/ui/include/track_timer/ui/imu_meter.hpp @@ -13,20 +13,7 @@ namespace track_timer::ui { // gyroscope latched tilt as acceleration and had left and right swapped, so they are wrong // rather than merely old and are not migrated. inline constexpr std::uint32_t kImuMeterSchemaVersion = 2; -// The trail is appended once per display service, so a capacity on its own says nothing -// about how much of a drive the trace shows: 24 points is two and a half seconds at 10 Hz -// and a fifth of a second at 120 Hz. The span is therefore the figure that gets chosen and -// the capacity is derived from it, with screen_router static_asserting that the cadence it -// dispatches at is the one assumed here. -inline constexpr std::int64_t kImuTrailSamplePeriodUs = 50'000; -// Three seconds. Chosen against what the trace is for rather than as a round number: a -// corner in a Seven runs roughly two to four seconds from turn-in to unwinding, so three -// seconds shows the driver the corner they have just taken. The previous 24 points were -// 1.2 s at this cadence, which showed them the middle of it. -inline constexpr std::int64_t kImuTrailSpanMs = 3'000; -inline constexpr std::size_t kImuTrailCapacity = - static_cast(kImuTrailSpanMs * 1'000 / kImuTrailSamplePeriodUs); -static_assert(kImuTrailCapacity > 1, "a trace needs more than one point"); +inline constexpr std::size_t kImuTrailCapacity = 24; inline constexpr float kStandardGravityMps2 = 9.80665F; // What the radar can draw. A dot has to stay on the display, so the drawn value is held // inside this - but a recorded peak is a different quantity with a different purpose, and diff --git a/firmware/main/screen_router.cpp b/firmware/main/screen_router.cpp index 3c44414..9bd7137 100644 --- a/firmware/main/screen_router.cpp +++ b/firmware/main/screen_router.cpp @@ -886,42 +886,6 @@ class ScreenRouter { } } - // Render cost, which #136 asked for a measurement of rather than an assumption - // about. The trace is the most demanding drawing this device does: every trail point - // is an LVGL object that is repositioned and restyled on each update, so raising - // kImuTrailCapacity raises the work here one-for-one. - // - // Timed at the call site rather than inside GRadarScreen so the UI component stays - // free of esp_timer and remains buildable on the host, and reported as a periodic - // summary so the figure can be read off an ordinary boot log instead of needing a - // profiler attached. - void record_radar_render(const std::int64_t elapsed_us) noexcept - { - radar_render_count_ += 1; - radar_render_total_us_ += elapsed_us; - radar_render_worst_us_ = std::max(radar_render_worst_us_, elapsed_us); - if (radar_render_count_ < kRadarRenderReportInterval) { - return; - } - // Against the budget, because the absolute figure means little on its own: this - // work has to finish inside the display period it is dispatched from, or the - // cadence that every other screen shares is what gives way. - ESP_LOGI("track_timer", - "radar: %u renders of %u trail points, mean %lld us, worst %lld us " - "(%lld us budget, worst %u%%)", - static_cast(radar_render_count_), - static_cast(ui::kImuTrailCapacity), - static_cast(radar_render_total_us_ / - static_cast(radar_render_count_)), - static_cast(radar_render_worst_us_), - static_cast(kDisplayServicePeriodUs), - static_cast(radar_render_worst_us_ * 100 / - kDisplayServicePeriodUs)); - radar_render_count_ = 0; - radar_render_total_us_ = 0; - radar_render_worst_us_ = 0; - } - void service_imu() noexcept { board::ImuSample sample{}; @@ -979,9 +943,7 @@ class ScreenRouter { // and it invalidates areas nobody is looking at. if (radar_ != nullptr && radar_root_ != nullptr && lv_screen_active() == radar_root_) { - const auto started_us = esp_timer_get_time(); radar_->update(snapshot); - record_radar_render(esp_timer_get_time() - started_us); } // Same gate, same reason. The snapshot stays at its default until there is a // transport to fill it (#17, #18), which is why the screen has to render an absent @@ -2456,19 +2418,6 @@ class ScreenRouter { ui::ClockState logged_clock_state_{ui::ClockState::no_receiver}; // Everything that is not the GNSS poll runs at this period rather than the tick's. static constexpr std::int64_t kDisplayServicePeriodUs = 50'000; - // The trail's span in seconds is this period times its capacity, so the two cannot be - // reasoned about separately. Asserted rather than commented: changing the cadence - // silently rescales the trace, which is how it came to hold roughly a second while - // claiming to hold a few. - static_assert(kDisplayServicePeriodUs == ui::kImuTrailSamplePeriodUs, - "the trail is appended once per display service, and its span is " - "derived from that period"); - // Ten seconds at the display cadence. Long enough to average over a real trace rather - // than a single frame, short enough that a boot capture contains several reports. - static constexpr std::uint32_t kRadarRenderReportInterval = 200; - std::uint32_t radar_render_count_{0}; - std::int64_t radar_render_total_us_{0}; - std::int64_t radar_render_worst_us_{0}; std::int64_t last_display_service_us_{0}; gnss::GnssTransport* gnss_transport_{nullptr}; gnss::GnssPipeline gnss_pipeline_{}; diff --git a/tests/cpp/test_imu_meter.cpp b/tests/cpp/test_imu_meter.cpp index 560eba2..756cb0d 100644 --- a/tests/cpp/test_imu_meter.cpp +++ b/tests/cpp/test_imu_meter.cpp @@ -40,16 +40,6 @@ track_timer::ui::ImuMeterInput vertical_sample(const float vertical_g, } // namespace -// #136 asked for "a trace of the last few seconds". That is a property of the span, so the -// span is what gets asserted: a capacity on its own could mean any duration, which is how -// 24 points came to be read as a few seconds when it was one and a fifth of one. -static_assert(track_timer::ui::kImuTrailSpanMs >= 2'000, - "the trace has to cover a corner rather than a fraction of one"); -static_assert(track_timer::ui::kImuTrailCapacity * - track_timer::ui::kImuTrailSamplePeriodUs / 1'000 == - track_timer::ui::kImuTrailSpanMs, - "the capacity has to hold exactly the span it claims to"); - int main() { using namespace track_timer; @@ -69,20 +59,13 @@ int main() assert(near(snapshot.peaks.braking_g, 1.1F)); assert(near(snapshot.peaks.left_g, 0.9F)); - // Overfilled relative to whatever the capacity currently is, not to a literal: the - // capacity is derived from the trace span and the display cadence now, so a test - // written against the number it happens to produce breaks every time either changes - // and tells you nothing about the ring buffer either way. Sixteen past full is enough - // to prove the oldest points are dropped rather than the newest refused. - constexpr std::uint64_t kOverfill = ui::kImuTrailCapacity + 16; - for (std::uint64_t index = 0; index < kOverfill; ++index) { + for (std::uint64_t index = 0; index < 40; ++index) { input = sample(static_cast(index) / 100.0F, 0.1F, 30 + index); meter.update(input, false); } assert(meter.snapshot().trail_count == ui::kImuTrailCapacity); assert(meter.trail_point(ui::kImuTrailCapacity).lateral_g == 0.0F); - assert(near(meter.trail_point(ui::kImuTrailCapacity - 1).lateral_g, - static_cast(kOverfill - 1) / 100.0F)); + assert(near(meter.trail_point(ui::kImuTrailCapacity - 1).lateral_g, 0.39F)); input = sample(0.1F, 0.2F, 80); snapshot = meter.update(input, true); From 1db819042170860be3bceb472acb054c72d7757c Mon Sep 17 00:00:00 2001 From: PurpleSentinel <199351535+PurpleSentinel@users.noreply.github.com> Date: Fri, 16 Oct 2026 22:00:47 +0100 Subject: [PATCH 2/2] docs: record why the three-second trace was reverted The measurement it was merged on was taken while the device was being moved by hand. Motion keeps the gravity calibration from completing, so resolve() stays invalid, the meter state is not ready, and update() takes the branch that hides every trail dot without positioning or restyling it. The apparently clean scaling from 1,727 to 2,395 us was the cost of drawing nothing. Measured again with the device untouched, which is when the trace is actually drawn: 24 points 60 points object work, mean 4,889-6,252 us 13,658-18,303 us share of the 50 ms display period 12-16% 36-41% worst repaint 38,532-41,095 us 53,101-55,442 us repaints per 10 s 147-152 166-170 Three times the object work and 14 ms more repaint, so the increase was a regression rather than nearly free. Also records the pre-existing finding: at 24 points a repaint already costs 40 ms against a 25 ms service period, on the task that also dispatches the receiver poll, and a fix is due every 40 ms at 25 Hz. The trace cannot grow until that is addressed. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 24 ++++++++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index d88149e..2e15d87 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -246,6 +246,30 @@ The project follows Semantic Versioning once the first firmware release is tagge ### Changed +- the G radar's trace is back to **1.2 seconds**, reverting an increase to three that was + merged on a bad measurement and then measured properly. Both figures below are with the + device untouched, which is when the meter reaches `ready` and the trace is actually + drawn: + + | | 24 points | 60 points | + |---|---|---| + | object work, mean | 4,889-6,252 us | 13,658-18,303 us | + | share of the 50 ms display period | 12-16% | 36-41% | + | worst repaint | 38,532-41,095 us | 53,101-55,442 us | + | repaints per 10 s | 147-152 | 166-170 | + + The first measurement was taken while the device was being moved by hand, on the + reasoning that a moving dot dirties more screen area than a parked one. Motion keeps the + gravity calibration from completing, so `resolve()` stays invalid, the meter state is not + `ready`, and `update()` takes the branch that hides every dot without positioning or + restyling it. The clean 1,727 to 2,395 us scaling that appeared to make three seconds + nearly free was the cost of drawing nothing + +- the repaint figures above are a pre-existing problem this work measured rather than + caused: **40 ms against a 25 ms service period at the current 24 points**, on the task + that also dispatches the receiver poll. At 25 Hz a fix is due every 40 ms. Tracked + separately; the trace cannot grow until it is addressed + - the receiver now runs at **25 Hz**. Measured on hardware: 24.9 Hz observed, 57 frames, 57 accepted, nothing rejected, no checksum errors, and 40 ms read back from the receiver's flash layer. The part was never in doubt - it was separately measured at