This commit is contained in:
J. Nick Koston
2026-04-23 06:01:08 -05:00
parent 2a0f2abd6b
commit 89fca4f446
3 changed files with 35 additions and 1 deletions
@@ -81,6 +81,19 @@ void RuntimeStatsCollector::log_stats_() {
ESP_LOGI(TAG, " main_loop_overhead_section: before=%.1fms, tail=%.1fms, inter_component=%.1fms",
static_cast<double>(before) / 1000.0, static_cast<double>(tail) / 1000.0,
static_cast<double>(inter) / 1000.0);
uint64_t sched = this->period_before_sched_time_us_;
uint64_t wdt = this->period_before_wdt_time_us_;
uint64_t before_residual = before > sched + wdt ? before - sched - wdt : 0;
ESP_LOGI(TAG, " main_loop_before_breakdown: sched=%.1fms, wdt=%.1fms, residual=%.1fms",
static_cast<double>(sched) / 1000.0, static_cast<double>(wdt) / 1000.0,
static_cast<double>(before_residual) / 1000.0);
uint32_t wdt_slow_hits = App.wdt_slow_count_;
App.wdt_slow_count_ = 0;
ESP_LOGI(TAG, " wdt_slow_path: hits=%" PRIu32 " (%.1f%% of iters, avg=%.2fus/hit)", wdt_slow_hits,
this->period_active_count_ > 0
? 100.0 * static_cast<double>(wdt_slow_hits) / static_cast<double>(this->period_active_count_)
: 0.0,
wdt_slow_hits > 0 ? static_cast<double>(wdt) / static_cast<double>(wdt_slow_hits) : 0.0);
}
// Log total stats since boot (only for active components - idle ones haven't changed)
@@ -116,6 +129,12 @@ void RuntimeStatsCollector::log_stats_() {
ESP_LOGI(TAG, " main_loop_overhead_section: before=%.1fms, tail=%.1fms, inter_component=%.1fms",
static_cast<double>(before) / 1000.0, static_cast<double>(tail) / 1000.0,
static_cast<double>(inter) / 1000.0);
uint64_t sched = this->total_before_sched_time_us_;
uint64_t wdt = this->total_before_wdt_time_us_;
uint64_t before_residual = before > sched + wdt ? before - sched - wdt : 0;
ESP_LOGI(TAG, " main_loop_before_breakdown: sched=%.1fms, wdt=%.1fms, residual=%.1fms",
static_cast<double>(sched) / 1000.0, static_cast<double>(wdt) / 1000.0,
static_cast<double>(before_residual) / 1000.0);
}
// Reset period stats
@@ -126,6 +145,8 @@ void RuntimeStatsCollector::log_stats_() {
this->period_active_time_us_ = 0;
this->period_active_max_us_ = 0;
this->period_before_time_us_ = 0;
this->period_before_sched_time_us_ = 0;
this->period_before_wdt_time_us_ = 0;
this->period_tail_time_us_ = 0;
}
@@ -49,7 +49,8 @@ class RuntimeStatsCollector {
// which captures per-iteration inter-component bookkeeping (set_current_component,
// WarnIfComponentBlockingGuard construction/destruction, feed_wdt_with_time calls,
// the for-loop itself).
void record_loop_active(uint32_t active_us, uint32_t before_us, uint32_t tail_us) {
void record_loop_active(uint32_t active_us, uint32_t before_us, uint32_t sched_us, uint32_t wdt_us,
uint32_t tail_us) {
this->period_active_count_++;
this->period_active_time_us_ += active_us;
if (active_us > this->period_active_max_us_)
@@ -61,6 +62,10 @@ class RuntimeStatsCollector {
this->period_before_time_us_ += before_us;
this->total_before_time_us_ += before_us;
this->period_before_sched_time_us_ += sched_us;
this->total_before_sched_time_us_ += sched_us;
this->period_before_wdt_time_us_ += wdt_us;
this->total_before_wdt_time_us_ += wdt_us;
this->period_tail_time_us_ += tail_us;
this->total_tail_time_us_ += tail_us;
}
@@ -88,6 +93,11 @@ class RuntimeStatsCollector {
// Split of overhead sections — accumulated per iteration.
uint64_t period_before_time_us_{0};
uint64_t total_before_time_us_{0};
// Sub-split of `before` into scheduler_tick_ vs. post-scheduler feed_wdt_with_time.
uint64_t period_before_sched_time_us_{0};
uint64_t total_before_sched_time_us_{0};
uint64_t period_before_wdt_time_us_{0};
uint64_t total_before_wdt_time_us_{0};
uint64_t period_tail_time_us_{0};
uint64_t total_tail_time_us_{0};
};
+3
View File
@@ -210,6 +210,9 @@ void HOT Application::feed_wdt_slow_(uint32_t time) {
// confirmed the WDT_FEED_INTERVAL_MS rate limit was exceeded.
arch_feed_wdt();
this->last_wdt_feed_ = time;
#ifdef USE_RUNTIME_STATS
this->wdt_slow_count_++;
#endif
}
#ifdef USE_STATUS_LED