跳转到内容

运行时统计

runtime_stats 组件允许你收集和分析 ESPHome 设备中所有组件的运行时性能统计信息。这是一个强大的调试和优化工具,有助于识别可能阻塞事件循环或消耗过多处理时间的组件。

WARNING

此组件用于调试和故障排查。虽然可以在生产环境中临时启用它来诊断问题,但不应长期保持启用,因为:

  • 统计信息收集会增加每次组件执行的开销
  • 它会增加用于存储统计信息的内存使用量
  • 周期性日志可能会让你的日志变得杂乱

在需要查找问题时启用它,一旦你的调查完成就禁用它。

# 示例配置条目
runtime_stats:
log_interval: 60s
  • log_interval (可选, Time): 记录统计信息的频率。默认为 60s。

    • 最小值为 1s
    • 设置太低会增加日志刷屏

IMPORTANT

墙钟时间,而非 CPU 时间: 运行时统计衡量的是墙钟时间(实际经过的真实时间),而不是 CPU 时间。 这意味着测量的时间包括组件执行期间发生的任何 FreeRTOS 上下文切换。 在单核芯片(ESP32-C3、C2、H2)上,Wi-Fi、BLE 和其他系统任务共享 同一核心,可能会抢占主循环,从而夸大测量的时间。在双核芯片(ESP32、S3)上, 系统任务大多运行在协议核(核心 0)上,而主循环运行在核心 1 上,因此测量的 时间更接近在组件中实际消耗的 CPU 时间。

例如,同一个 bluetooth_proxy 组件在 ESP32-C3 上可能显示 avg=1.8ms,但在双核 ESP32 上只有 avg=0.4ms。 C3 更慢,但没有数字显示的那么大——差异被单核上的系统任务抢占夸大了。

运行时统计对于识别阻塞组件仍然有价值,但请记住, 绝对时间会显得高于实际消耗的 CPU 时间,尤其是在基于单核 FreeRTOS 的系统上。

该组件记录两种类型的统计信息:

周期统计(Period Statistics) 显示最近一个记录间隔的统计信息。对于识别瞬态性能问题很有用。

总统计(Total Statistics) 显示自启动以来的累计统计信息。对于了解整体系统行为很有用。

对于每个组件,报告以下指标:

  • count(次数):组件执行的次数
  • avg(平均):平均执行时间(毫秒)
  • max(最大):观察到的最大执行时间
  • total(总计):累计执行总时间

组件按总执行时间(降序)排序,以突出影响最大的组件。

除了每个组件的计时外,在 Period 和 Total 部分中都会输出两行主循环信息。它们描述在 Application::loop() 中花费的墙钟时间,不包括每次迭代末尾的 sleep/yield,因此它们反映的是 CPU 为 ESPHome 所做的实际工作——而不是空闲时间。

main_loop: 行

  • iters:此窗口内观察到的主循环迭代次数。
  • active_avg:每次迭代的平均活动时间(从循环开始到 yield/sleep 之前)。
  • active_max:观察到的单次迭代最大活动时间(异常值通常指向阻塞了循环的组件)。
  • active_total:整个窗口内每次迭代活动时间的总和——即主循环中的非睡眠 CPU 总时间。
  • overhead_total:active_total 减去所有组件 total 时间的总和。表示花费在主循环中但不能归因于任何单个组件的时间(调度器分发、组件间簿记、框架胶水代码)。

main_loop_overhead_section: 行

将 overhead_total 分解为三个桶,以便你可以分辨开销花在哪里:

  • before:before_loop_tasks_ 内部的时间——调度器分发和 ISR enable_loop 处理。
  • tail:after_loop_tasks_ 内部的时间加上统计记录前的一小段前缀。通常接近零。
  • inter_component:在组件之间运行的残差逐迭代簿记(set_current_component、逐组件计时保护对象的构造/析构、feed_wdt_with_time 调用、for 循环本身)。

before 中的退化指向调度器或某个频繁从 ISR 请求 enable_loop 的组件;inter_component 中的退化指向逐组件分发路径;tail 应保持平稳。

在下面的示例中,overhead_total 是 active_total 与所有组件 total 时间之和的差值——对于周期部分,479.1ms − (300.0 + 40.0 + 10.4)ms = 128.7ms。三个开销部分桶(before + tail + inter_component)加起来等于 overhead_total。

[09:55:52][I][runtime_stats:042]: Component Runtime Statistics
[09:55:52][I][runtime_stats:043]: Period stats (last 60000ms): 3 active components
[09:55:52][I][runtime_stats:066]: wifi: count=60, avg=5.000ms, max=8.00ms, total=300.0ms
[09:55:52][I][runtime_stats:066]: api: count=120, avg=0.333ms, max=1.00ms, total=40.0ms
[09:55:52][I][runtime_stats:066]: sensor: count=600, avg=0.017ms, max=0.10ms, total=10.4ms
[09:55:52][I][runtime_stats:068]: main_loop: iters=7650, active_avg=0.063ms, active_max=10.67ms, active_total=479.1ms, overhead_total=128.7ms
[09:55:52][I][runtime_stats:070]: main_loop_overhead_section: before=45.0ms, tail=8.0ms, inter_component=75.7ms
[09:55:52][I][runtime_stats:072]: Total stats (since boot): 3 active components
[09:55:52][I][runtime_stats:084]: wifi: count=600, avg=5.000ms, max=8.00ms, total=3000.0ms
[09:55:52][I][runtime_stats:084]: api: count=1200, avg=0.333ms, max=1.00ms, total=400.0ms
[09:55:52][I][runtime_stats:084]: sensor: count=6000, avg=0.017ms, max=0.10ms, total=104.0ms
[09:55:52][I][runtime_stats:094]: main_loop: iters=76500, active_avg=0.063ms, active_max=14.30ms, active_total=4791.0ms, overhead_total=1287.0ms
[09:55:52][I][runtime_stats:096]: main_loop_overhead_section: before=450.0ms, tail=80.0ms, inter_component=757.0ms

识别阻塞组件 查找 max 时间较高的组件。这些组件可能阻塞事件循环,导致其他组件出现问题。

优化目标 total 时间较高的组件是优化的好候选者,尤其是当它们执行频繁时。

性能回归测试 比较更改前后的统计信息,以确保性能没有退化。

排查时序问题 如果组件错过最后期限或行为异常,运行时统计可以帮助识别原因。

  1. 从默认间隔开始:60 秒的默认值在细节和日志量之间提供了很好的平衡。

  2. 关注异常值:执行时间远高于其他组件的组件通常是最好的优化目标。

  3. 考虑执行频率:一个耗时 1ms 但每分钟运行 1000 次的组件,比一个耗时 10ms 但每分钟只运行一次的组件影响更大。

  4. 注意模式:执行时间随时间增加可能表明存在内存泄漏或资源耗尽。

  5. 完成后禁用:完成调试后,始终移除或注释掉 runtime_stats 组件。