Florian/esphome
1
0
Fork 0
Code Issues Pull Requests Actions 4 Packages Projects Releases Wiki Activity

cleanup

Browse Source
This commit is contained in:
J. Nick Koston
2025-05-14 12:38:07 -05:00
parent 45e08ed584
commit c4aee545c3
2 changed files with 179 additions and 3 deletions
Download Patch File Download Diff File Expand all files Collapse all files

111
esphome/components/api/api_connection.cpp
View File

@@ -26,6 +26,7 @@ namespace esphome {
namespace api {
static const char *const TAG = "api.connection";
static const char *const STATS_TAG = "api.stats";
static const int ESP32_CAMERA_STOP_STREAM = 5000;
// helper for allowing only unique entries in the queue
@@ -92,6 +93,58 @@ void APIConnection::start() {
this->helper_->set_log_info(this->client_info_);
}
void APIConnection::log_section_stats_() {
ESP_LOGI(STATS_TAG, "API Connection Section Runtime Statistics");
ESP_LOGI(STATS_TAG, "Period stats (last %" PRIu32 "ms):", this->stats_log_interval_);
// First collect stats we want to display
std::vector<std::pair<std::string, const APISectionStats *>> stats_to_display;
for (const auto &it : this->section_stats_) {
const APISectionStats &stats = it.second;
if (stats.get_period_count() > 0) {
stats_to_display.push_back({it.first, &stats});
}
}
// Sort by period runtime (descending)
std::sort(stats_to_display.begin(), stats_to_display.end(), [](const auto &a, const auto &b) {
return a.second->get_period_time_ms() > b.second->get_period_time_ms();
});
// Log top components by period runtime
for (const auto &it : stats_to_display) {
const std::string &section = it.first;
const APISectionStats *stats = it.second;
ESP_LOGI(STATS_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", section.c_str(),
stats->get_period_count(), stats->get_period_avg_time_ms(), stats->get_period_max_time_ms(),
stats->get_period_time_ms());
}
// Log total stats since boot
ESP_LOGI(STATS_TAG, "Total stats (since boot):");
// Re-sort by total runtime for all-time stats
std::sort(stats_to_display.begin(), stats_to_display.end(),
[](const auto &a, const auto &b) { return a.second->get_total_time_ms() > b.second->get_total_time_ms(); });
for (const auto &it : stats_to_display) {
const std::string &section = it.first;
const APISectionStats *stats = it.second;
ESP_LOGI(STATS_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms", section.c_str(),
stats->get_total_count(), stats->get_total_avg_time_ms(), stats->get_total_max_time_ms(),
stats->get_total_time_ms());
}
}
void APIConnection::reset_section_stats_() {
for (auto &it : this->section_stats_) {
it.second.reset_period_stats();
}
}
APIConnection::~APIConnection() {
#ifdef USE_BLUETOOTH_PROXY
if (bluetooth_proxy::global_bluetooth_proxy->get_api_connection() == this) {
@@ -123,15 +176,30 @@ void APIConnection::loop() {
return;
}
const uint32_t now = millis();
uint32_t start_time;
uint32_t duration;
// Section: Helper Loop
start_time = millis();
APIError err = this->helper_->loop();
duration = millis() - start_time;
this->section_stats_["helper_loop"].record_time(duration);
if (err != APIError::OK) {
on_fatal_error();
ESP_LOGW(TAG, "%s: Socket operation failed: %s errno=%d", this->client_combined_info_.c_str(),
api_error_to_str(err), errno);
return;
}
// Section: Read Packet
start_time = millis();
ReadPacketBuffer buffer;
err = this->helper_->read_packet(&buffer);
duration = millis() - start_time;
this->section_stats_["read_packet"].record_time(duration);
if (err == APIError::WOULD_BLOCK) {
// pass
} else if (err != APIError::OK) {
@@ -146,24 +214,39 @@ void APIConnection::loop() {
}
return;
} else {
this->last_traffic_ = millis();
// read a packet
this->last_traffic_ = now;
// Section: Process Message
start_time = millis();
this->read_message(buffer.data_len, buffer.type, &buffer.container[buffer.data_offset]);
duration = millis() - start_time;
this->section_stats_["process_message"].record_time(duration);
if (this->remove_)
return;
}
// Section: Process Queue
start_time = millis();
this->deferred_message_queue_.process_queue();
duration = millis() - start_time;
this->section_stats_["process_queue"].record_time(duration);
// Section: Iterator Advance
start_time = millis();
if (!this->list_entities_iterator_.completed())
this->list_entities_iterator_.advance();
if (!this->initial_state_iterator_.completed() && this->list_entities_iterator_.completed())
this->initial_state_iterator_.advance();
duration = millis() - start_time;
this->section_stats_["iterator_advance"].record_time(duration);
// Section: Keepalive
start_time = millis();
static uint32_t keepalive = 60000;
static uint8_t max_ping_retries = 60;
static uint16_t ping_retry_interval = 1000;
const uint32_t now = millis();
if (this->sent_ping_) {
// Disconnect if not responded within 2.5*keepalive
if (now - this->last_traffic_ > (keepalive * 5) / 2) {
@@ -189,8 +272,12 @@ void APIConnection::loop() {
}
}
}
duration = millis() - start_time;
this->section_stats_["keepalive"].record_time(duration);
#ifdef USE_ESP32_CAMERA
// Section: Camera
start_time = millis();
if (this->image_reader_.available() && this->helper_->can_write_without_blocking()) {
// Message will use 8 more bytes than the minimum size, and typical
// MTU is 1500. Sometimes users will see as low as 1460 MTU.
@@ -229,8 +316,12 @@ void APIConnection::loop() {
this->image_reader_.return_image();
}
}
duration = millis() - start_time;
this->section_stats_["camera"].record_time(duration);
#endif
// Section: State Subscriptions
start_time = millis();
if (state_subs_at_ != -1) {
const auto &subs = this->parent_->get_state_subs();
if (state_subs_at_ >= (int) subs.size()) {
@@ -246,6 +337,20 @@ void APIConnection::loop() {
}
}
}
duration = millis() - start_time;
this->section_stats_["state_subs"].record_time(duration);
// Log stats periodically
if (this->stats_enabled_) {
// If next_stats_log_ is 0, initialize it
if (this->next_stats_log_ == 0) {
this->next_stats_log_ = now + this->stats_log_interval_;
} else if (now >= this->next_stats_log_) {
this->log_section_stats_();
this->reset_section_stats_();
this->next_stats_log_ = now + this->stats_log_interval_;
}
}
}
std::string get_default_unique_id(const std::string &component_type, EntityBase *entity) {

71
esphome/components/api/api_connection.h
View File

@@ -10,6 +10,10 @@
#include "esphome/core/component.h"
#include <vector>
#include <map>
#include <string>
#include "esphome/core/helpers.h"
#include "esphome/core/log.h"
namespace esphome {
namespace api {
@@ -59,6 +63,65 @@ class APIConnection : public APIServerConnection {
APIConnection(std::unique_ptr<socket::Socket> socket, APIServer *parent);
virtual ~APIConnection();
// Performance statistics class for API loop sections
class APISectionStats {
public:
APISectionStats()
: period_count_(0),
total_count_(0),
period_time_ms_(0),
total_time_ms_(0),
period_max_time_ms_(0),
total_max_time_ms_(0) {}
void record_time(uint32_t duration_ms) {
// Update period counters
this->period_count_++;
this->period_time_ms_ += duration_ms;
if (duration_ms > this->period_max_time_ms_)
this->period_max_time_ms_ = duration_ms;
// Update total counters
this->total_count_++;
this->total_time_ms_ += duration_ms;
if (duration_ms > this->total_max_time_ms_)
this->total_max_time_ms_ = duration_ms;
}
void reset_period_stats() {
this->period_count_ = 0;
this->period_time_ms_ = 0;
this->period_max_time_ms_ = 0;
}
// Period stats (reset each logging interval)
uint32_t get_period_count() const { return this->period_count_; }
uint32_t get_period_time_ms() const { return this->period_time_ms_; }
uint32_t get_period_max_time_ms() const { return this->period_max_time_ms_; }
float get_period_avg_time_ms() const {
return this->period_count_ > 0 ? this->period_time_ms_ / static_cast<float>(this->period_count_) : 0.0f;
}
// Total stats (persistent until reboot)
uint32_t get_total_count() const { return this->total_count_; }
uint32_t get_total_time_ms() const { return this->total_time_ms_; }
uint32_t get_total_max_time_ms() const { return this->total_max_time_ms_; }
float get_total_avg_time_ms() const {
return this->total_count_ > 0 ? this->total_time_ms_ / static_cast<float>(this->total_count_) : 0.0f;
}
protected:
// Period stats (reset each logging interval)
uint32_t period_count_;
uint32_t period_time_ms_;
uint32_t period_max_time_ms_;
// Total stats (persistent until reboot)
uint32_t total_count_;
uint32_t total_time_ms_;
uint32_t total_max_time_ms_;
};
void start();
void loop();
@@ -362,6 +425,14 @@ class APIConnection : public APIServerConnection {
InitialStateIterator initial_state_iterator_;
ListEntitiesIterator list_entities_iterator_;
int state_subs_at_ = -1;
// API loop section performance statistics
std::map<std::string, APISectionStats> section_stats_;
uint32_t stats_log_interval_{60000}; // 60 seconds default
uint32_t next_stats_log_{0};
bool stats_enabled_{true};
void log_section_stats_();
void reset_section_stats_();
};
} // namespace api