From ab415eb3dec1787ed9a55f3d31895a49380b0514 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Sat, 17 May 2025 16:50:36 -0400 Subject: [PATCH 1/3] stats --- esphome/components/api/api_connection.cpp | 170 +++++++++++++++++++++- esphome/components/api/api_connection.h | 71 +++++++++ 2 files changed, 238 insertions(+), 3 deletions(-) diff --git a/esphome/components/api/api_connection.cpp b/esphome/components/api/api_connection.cpp index c377909951..9655034a2e 100644 --- a/esphome/components/api/api_connection.cpp +++ b/esphome/components/api/api_connection.cpp @@ -3,6 +3,9 @@ #include #include #include +#include +#include +#include #include "esphome/components/network/util.h" #include "esphome/core/entity_base.h" #include "esphome/core/hal.h" @@ -106,6 +109,9 @@ APIConnection::~APIConnection() { } void APIConnection::loop() { + // Measure total time for entire loop function + const uint32_t loop_start_time = millis(); + if (this->remove_) return; @@ -123,15 +129,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,26 +167,41 @@ 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(); if (!this->deferred_message_queue_.empty() && this->helper_->can_write_without_blocking()) { 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) { @@ -191,8 +227,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. @@ -231,8 +271,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()) { @@ -248,6 +292,24 @@ 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_; + } + } + + // Record total loop execution time + const uint32_t total_loop_duration = millis() - loop_start_time; + this->section_stats_["total_loop"].record_time(total_loop_duration); } std::string get_default_unique_id(const std::string &component_type, EntityBase *entity) { @@ -1624,8 +1686,14 @@ bool APIConnection::try_to_clear_buffer(bool log_out_of_space) { return false; if (this->helper_->can_write_without_blocking()) return true; + + // Track try_to_clear_buffer time + const uint32_t start_time = millis(); delay(0); APIError err = this->helper_->loop(); + const uint32_t duration = millis() - start_time; + this->section_stats_["try_to_clear_buffer"].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(), @@ -1640,11 +1708,18 @@ bool APIConnection::try_to_clear_buffer(bool log_out_of_space) { return false; } bool APIConnection::send_buffer(ProtoWriteBuffer buffer, uint32_t message_type) { + // Track send_buffer time + const uint32_t start_time = millis(); + if (!this->try_to_clear_buffer(message_type != 29)) { // SubscribeLogsResponse return false; } + uint32_t write_start = millis(); APIError err = this->helper_->write_packet(message_type, buffer.get_buffer()->data(), buffer.get_buffer()->size()); + uint32_t write_duration = millis() - write_start; + this->section_stats_["write_packet"].record_time(write_duration); + if (err == APIError::WOULD_BLOCK) return false; if (err != APIError::OK) { @@ -1657,6 +1732,11 @@ bool APIConnection::send_buffer(ProtoWriteBuffer buffer, uint32_t message_type) } return false; } + + // Measure total send_buffer function time + uint32_t total_duration = millis() - start_time; + this->section_stats_["send_buffer_total"].record_time(total_duration); + // Do not set last_traffic_ on send return true; } @@ -1673,6 +1753,90 @@ void APIConnection::on_fatal_error() { this->remove_ = true; } +void APIConnection::log_section_stats_() { + const char *STATS_TAG = "api.stats"; + ESP_LOGI(STATS_TAG, "Logging API section stats now (current time: %" PRIu32 ", scheduled time: %" PRIu32 ")", + millis(), this->next_stats_log_); + ESP_LOGI(STATS_TAG, "Stats collection status: enabled=%d, sections=%zu", this->stats_enabled_, + this->section_stats_.size()); + + // Check if we have minimal data + bool has_data = false; + for (const auto &it : this->section_stats_) { + if (it.second.get_period_count() > 0) { + has_data = true; + break; + } + } + + if (has_data) { + size_t helper_count = 0; + size_t read_count = 0; + size_t total_count = 0; + if (this->section_stats_.count("helper_loop") > 0) + helper_count = this->section_stats_["helper_loop"].get_period_count(); + if (this->section_stats_.count("read_packet") > 0) + read_count = this->section_stats_["read_packet"].get_period_count(); + if (this->section_stats_.count("total_loop") > 0) + total_count = this->section_stats_["total_loop"].get_period_count(); + + ESP_LOGI(STATS_TAG, "Record count for key sections: helper_loop=%zu, read_packet=%zu, total_loop=%zu", helper_count, + read_count, total_count); + } + + 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> 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 §ion = 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 §ion = 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()); + } + + ESP_LOGD(STATS_TAG, "Resetting API section stats, sections count: %zu", this->section_stats_.size()); +} + +void APIConnection::reset_section_stats_() { + for (auto &it : this->section_stats_) { + it.second.reset_period_stats(); + } +} + } // namespace api } // namespace esphome #endif diff --git a/esphome/components/api/api_connection.h b/esphome/components/api/api_connection.h index dd24802e72..798525a602 100644 --- a/esphome/components/api/api_connection.h +++ b/esphome/components/api/api_connection.h @@ -9,8 +9,12 @@ #include "esphome/core/application.h" #include "esphome/core/component.h" #include "esphome/core/entity_base.h" +#include "esphome/core/helpers.h" +#include "esphome/core/log.h" #include +#include +#include namespace esphome { namespace api { @@ -61,6 +65,65 @@ class APIConnection : public APIServerConnection { APIConnection(std::unique_ptr 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(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(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(); @@ -546,6 +609,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 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 From 663f38d2ecd586077410d7baf20b17826665ca2a Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 22 May 2025 21:31:31 -0500 Subject: [PATCH 2/3] merge --- esphome/components/api/api_connection.cpp | 1 - 1 file changed, 1 deletion(-) diff --git a/esphome/components/api/api_connection.cpp b/esphome/components/api/api_connection.cpp index 92b3fecd71..e41b4bca63 100644 --- a/esphome/components/api/api_connection.cpp +++ b/esphome/components/api/api_connection.cpp @@ -205,7 +205,6 @@ void APIConnection::loop() { start_time = millis(); static uint8_t max_ping_retries = 60; static uint16_t ping_retry_interval = 1000; - const uint32_t now = App.get_loop_component_start_time(); if (this->sent_ping_) { // Disconnect if not responded within 2.5*keepalive if (now - this->last_traffic_ > (KEEPALIVE_TIMEOUT_MS * 5) / 2) { From 0a1f3e813cc40ab94f3d49dc25b6732f8f5db2d5 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 22 May 2025 21:58:16 -0500 Subject: [PATCH 3/3] more stats --- esphome/components/api/api_connection.cpp | 3 + esphome/components/api/api_connection.h | 60 +----------------- esphome/components/api/api_frame_helper.cpp | 67 +++++++++++++++++++++ esphome/components/api/api_frame_helper.h | 66 ++++++++++++++++++++ 4 files changed, 138 insertions(+), 58 deletions(-) diff --git a/esphome/components/api/api_connection.cpp b/esphome/components/api/api_connection.cpp index e41b4bca63..cb466bce81 100644 --- a/esphome/components/api/api_connection.cpp +++ b/esphome/components/api/api_connection.cpp @@ -88,6 +88,9 @@ void APIConnection::start() { // This ensures the first ping happens after the keepalive period this->next_ping_retry_ = this->last_traffic_ + KEEPALIVE_TIMEOUT_MS; + // Pass stats collection to the helper for detailed timing + this->helper_->set_section_stats(&this->section_stats_); + APIError err = this->helper_->init(); if (err != APIError::OK) { on_fatal_error(); diff --git a/esphome/components/api/api_connection.h b/esphome/components/api/api_connection.h index 4c5c6c0a65..218bb22d7a 100644 --- a/esphome/components/api/api_connection.h +++ b/esphome/components/api/api_connection.h @@ -68,64 +68,8 @@ class APIConnection : public APIServerConnection { APIConnection(std::unique_ptr 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(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(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_; - }; + // Use the APISectionStats from api_frame_helper.h to avoid duplication + using APISectionStats = ::esphome::api::APISectionStats; void start(); void loop(); diff --git a/esphome/components/api/api_frame_helper.cpp b/esphome/components/api/api_frame_helper.cpp index 19983e3456..33577837ba 100644 --- a/esphome/components/api/api_frame_helper.cpp +++ b/esphome/components/api/api_frame_helper.cpp @@ -111,7 +111,12 @@ APIError APIFrameHelper::write_raw_(const struct iovec *iov, int iovcnt) { } // Try to send directly if no buffered data + uint32_t write_start = millis(); ssize_t sent = this->socket_->writev(iov, iovcnt); + uint32_t write_duration = millis() - write_start; + if (write_duration > 0 && section_stats_) { + (*section_stats_)["write_packet.socket_writev"].record_time(write_duration); + } if (sent == -1) { if (errno == EWOULDBLOCK || errno == EAGAIN) { @@ -160,7 +165,12 @@ APIError APIFrameHelper::try_send_tx_buf_() { SendBuffer &front_buffer = this->tx_buf_.front(); // Try to send the remaining data in this buffer + uint32_t write_start = millis(); ssize_t sent = this->socket_->write(front_buffer.current_data(), front_buffer.remaining()); + uint32_t write_duration = millis() - write_start; + if (write_duration > 0 && section_stats_) { + (*section_stats_)["send_buffer_total.socket_write"].record_time(write_duration); + } if (sent == -1) { if (errno != EWOULDBLOCK && errno != EAGAIN) { @@ -311,7 +321,12 @@ APIError APINoiseFrameHelper::try_read_frame_(ParsedFrame *frame) { if (rx_header_buf_len_ < 3) { // no header information yet uint8_t to_read = 3 - rx_header_buf_len_; + uint32_t socket_start = millis(); ssize_t received = this->socket_->read(&rx_header_buf_[rx_header_buf_len_], to_read); + uint32_t socket_duration = millis() - socket_start; + if (socket_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.socket_read_header"].record_time(socket_duration); + } if (received == -1) { if (errno == EWOULDBLOCK || errno == EAGAIN) { return APIError::WOULD_BLOCK; @@ -352,13 +367,23 @@ APIError APINoiseFrameHelper::try_read_frame_(ParsedFrame *frame) { // reserve space for body if (rx_buf_.size() != msg_size) { + uint32_t resize_start = millis(); rx_buf_.resize(msg_size); + uint32_t resize_duration = millis() - resize_start; + if (resize_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.buffer_resize"].record_time(resize_duration); + } } if (rx_buf_len_ < msg_size) { // more data to read uint16_t to_read = msg_size - rx_buf_len_; + uint32_t socket_start = millis(); ssize_t received = this->socket_->read(&rx_buf_[rx_buf_len_], to_read); + uint32_t socket_duration = millis() - socket_start; + if (socket_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.socket_read_body"].record_time(socket_duration); + } if (received == -1) { if (errno == EWOULDBLOCK || errno == EAGAIN) { return APIError::WOULD_BLOCK; @@ -554,7 +579,15 @@ void APINoiseFrameHelper::send_explicit_handshake_reject_(const std::string &rea APIError APINoiseFrameHelper::read_packet(ReadPacketBuffer *buffer) { int err; APIError aerr; + uint32_t start_time, duration; + + // Track state_action timing + start_time = millis(); aerr = state_action_(); + duration = millis() - start_time; + if (duration > 0 && section_stats_) { + (*section_stats_)["read_packet.state_action"].record_time(duration); + } if (aerr != APIError::OK) { return aerr; } @@ -563,15 +596,27 @@ APIError APINoiseFrameHelper::read_packet(ReadPacketBuffer *buffer) { return APIError::WOULD_BLOCK; } + // Track frame reading timing + start_time = millis(); ParsedFrame frame; aerr = try_read_frame_(&frame); + duration = millis() - start_time; + if (duration > 0 && section_stats_) { + (*section_stats_)["read_packet.try_read_frame"].record_time(duration); + } if (aerr != APIError::OK) return aerr; + // Track decryption timing + start_time = millis(); NoiseBuffer mbuf; noise_buffer_init(mbuf); noise_buffer_set_inout(mbuf, frame.msg.data(), frame.msg.size(), frame.msg.size()); err = noise_cipherstate_decrypt(recv_cipher_, &mbuf); + duration = millis() - start_time; + if (duration > 0 && section_stats_) { + (*section_stats_)["read_packet.decrypt"].record_time(duration); + } if (err != 0) { state_ = State::FAILED; HELPER_LOG("noise_cipherstate_decrypt failed: %s", noise_err_to_str(err).c_str()); @@ -836,7 +881,12 @@ APIError APIPlaintextFrameHelper::try_read_frame_(ParsedFrame *frame) { // there is no data on the wire (which is the common case). // This results in faster failure detection compared to // attempting to read multiple bytes at once. + uint32_t socket_start = millis(); ssize_t received = this->socket_->read(&data, 1); + uint32_t socket_duration = millis() - socket_start; + if (socket_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.socket_read_header"].record_time(socket_duration); + } if (received == -1) { if (errno == EWOULDBLOCK || errno == EAGAIN) { return APIError::WOULD_BLOCK; @@ -926,13 +976,23 @@ APIError APIPlaintextFrameHelper::try_read_frame_(ParsedFrame *frame) { // reserve space for body if (rx_buf_.size() != rx_header_parsed_len_) { + uint32_t resize_start = millis(); rx_buf_.resize(rx_header_parsed_len_); + uint32_t resize_duration = millis() - resize_start; + if (resize_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.buffer_resize"].record_time(resize_duration); + } } if (rx_buf_len_ < rx_header_parsed_len_) { // more data to read uint16_t to_read = rx_header_parsed_len_ - rx_buf_len_; + uint32_t socket_start = millis(); ssize_t received = this->socket_->read(&rx_buf_[rx_buf_len_], to_read); + uint32_t socket_duration = millis() - socket_start; + if (socket_duration > 0 && section_stats_) { + (*section_stats_)["read_packet.socket_read_body"].record_time(socket_duration); + } if (received == -1) { if (errno == EWOULDBLOCK || errno == EAGAIN) { return APIError::WOULD_BLOCK; @@ -966,13 +1026,20 @@ APIError APIPlaintextFrameHelper::try_read_frame_(ParsedFrame *frame) { } APIError APIPlaintextFrameHelper::read_packet(ReadPacketBuffer *buffer) { APIError aerr; + uint32_t start_time, duration; if (state_ != State::DATA) { return APIError::WOULD_BLOCK; } + // Track frame reading timing + start_time = millis(); ParsedFrame frame; aerr = try_read_frame_(&frame); + duration = millis() - start_time; + if (duration > 0 && section_stats_) { + (*section_stats_)["read_packet.try_read_frame"].record_time(duration); + } if (aerr != APIError::OK) { if (aerr == APIError::BAD_INDICATOR) { // Make sure to tell the remote that we don't diff --git a/esphome/components/api/api_frame_helper.h b/esphome/components/api/api_frame_helper.h index bc25680a53..c16b8ef98b 100644 --- a/esphome/components/api/api_frame_helper.h +++ b/esphome/components/api/api_frame_helper.h @@ -13,10 +13,71 @@ #include "api_noise_context.h" #include "esphome/components/socket/socket.h" +#include +#include namespace esphome { namespace api { +// Forward declaration from api_connection.h +class APIConnection; + +// Stats class definition (copied from api_connection.h to avoid circular dependency) +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; + } + + // Getters for period stats + 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 ? static_cast(this->period_time_ms_) / this->period_count_ : 0.0f; + } + + // Getters for total stats + 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 ? static_cast(this->total_time_ms_) / this->total_count_ : 0.0f; + } + + private: + uint32_t period_count_; + uint32_t total_count_; + uint32_t period_time_ms_; + uint32_t total_time_ms_; + uint32_t period_max_time_ms_; + uint32_t total_max_time_ms_; +}; + class ProtoWriteBuffer; struct ReadPacketBuffer { @@ -85,6 +146,8 @@ class APIFrameHelper { } // Give this helper a name for logging void set_log_info(std::string info) { info_ = std::move(info); } + // Set stats collection for detailed timing + void set_section_stats(std::map *stats) { section_stats_ = stats; } virtual APIError write_protobuf_packet(uint16_t type, ProtoWriteBuffer buffer) = 0; // Get the frame header padding required by this protocol virtual uint8_t frame_header_padding() = 0; @@ -160,6 +223,9 @@ class APIFrameHelper { // Common initialization for both plaintext and noise protocols APIError init_common_(); + + // Stats collection pointer - shared from APIConnection + std::map *section_stats_{nullptr}; }; #ifdef USE_API_NOISE