diff --git a/CHANGELOG.md b/CHANGELOG.md index 127ee86..2e15d87 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -246,31 +246,29 @@ 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: +- 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 | 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 + | 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 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);