Compare commits
6 Commits
socket_lat
...
add_api_st
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
c6858163a7 | ||
|
|
0a1f3e813c | ||
|
|
663f38d2ec | ||
|
|
f0b311f839 | ||
|
|
1c06137ae0 | ||
|
|
ab415eb3de |
@@ -3,6 +3,9 @@
|
||||
#include <cerrno>
|
||||
#include <cinttypes>
|
||||
#include <utility>
|
||||
#include <algorithm>
|
||||
#include <map>
|
||||
#include <string>
|
||||
#include "esphome/components/network/util.h"
|
||||
#include "esphome/core/application.h"
|
||||
#include "esphome/core/entity_base.h"
|
||||
@@ -85,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();
|
||||
@@ -111,6 +117,9 @@ APIConnection::~APIConnection() {
|
||||
}
|
||||
|
||||
void APIConnection::loop() {
|
||||
// Measure total time for entire loop function
|
||||
const uint32_t loop_start_time = millis();
|
||||
|
||||
if (this->remove_)
|
||||
return;
|
||||
|
||||
@@ -128,7 +137,16 @@ 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(),
|
||||
@@ -136,48 +154,64 @@ void APIConnection::loop() {
|
||||
return;
|
||||
}
|
||||
|
||||
// Check if socket has data ready before attempting to read
|
||||
if (this->helper_->is_socket_ready()) {
|
||||
ReadPacketBuffer buffer;
|
||||
err = this->helper_->read_packet(&buffer);
|
||||
if (err == APIError::WOULD_BLOCK) {
|
||||
// pass
|
||||
} else if (err != APIError::OK) {
|
||||
on_fatal_error();
|
||||
if (err == APIError::SOCKET_READ_FAILED && errno == ECONNRESET) {
|
||||
ESP_LOGW(TAG, "%s: Connection reset", this->client_combined_info_.c_str());
|
||||
} else if (err == APIError::CONNECTION_CLOSED) {
|
||||
ESP_LOGW(TAG, "%s: Connection closed", this->client_combined_info_.c_str());
|
||||
} else {
|
||||
ESP_LOGW(TAG, "%s: Reading 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) {
|
||||
on_fatal_error();
|
||||
if (err == APIError::SOCKET_READ_FAILED && errno == ECONNRESET) {
|
||||
ESP_LOGW(TAG, "%s: Connection reset", this->client_combined_info_.c_str());
|
||||
} else if (err == APIError::CONNECTION_CLOSED) {
|
||||
ESP_LOGW(TAG, "%s: Connection closed", this->client_combined_info_.c_str());
|
||||
} else {
|
||||
this->last_traffic_ = App.get_loop_component_start_time();
|
||||
// read a packet
|
||||
if (buffer.data_len > 0) {
|
||||
this->read_message(buffer.data_len, buffer.type, &buffer.container[buffer.data_offset]);
|
||||
} else {
|
||||
this->read_message(0, buffer.type, nullptr);
|
||||
}
|
||||
if (this->remove_)
|
||||
return;
|
||||
ESP_LOGW(TAG, "%s: Reading failed: %s errno=%d", this->client_combined_info_.c_str(), api_error_to_str(err),
|
||||
errno);
|
||||
}
|
||||
return;
|
||||
} else {
|
||||
this->last_traffic_ = App.get_loop_component_start_time();
|
||||
|
||||
// Section: Process Message
|
||||
start_time = millis();
|
||||
if (buffer.data_len > 0) {
|
||||
this->read_message(buffer.data_len, buffer.type, &buffer.container[buffer.data_offset]);
|
||||
} else {
|
||||
this->read_message(0, buffer.type, nullptr);
|
||||
}
|
||||
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 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) {
|
||||
@@ -203,8 +237,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.
|
||||
@@ -243,8 +281,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()) {
|
||||
@@ -260,6 +302,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) {
|
||||
@@ -1636,8 +1696,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(),
|
||||
@@ -1652,11 +1718,17 @@ 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_protobuf_packet(message_type, buffer);
|
||||
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) {
|
||||
@@ -1669,6 +1741,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;
|
||||
}
|
||||
@@ -1685,6 +1762,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<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 §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
|
||||
|
||||
@@ -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 <vector>
|
||||
#include <map>
|
||||
#include <string>
|
||||
|
||||
namespace esphome {
|
||||
namespace api {
|
||||
@@ -64,6 +68,9 @@ class APIConnection : public APIServerConnection {
|
||||
APIConnection(std::unique_ptr<socket::Socket> socket, APIServer *parent);
|
||||
virtual ~APIConnection();
|
||||
|
||||
// Use the APISectionStats from api_frame_helper.h to avoid duplication
|
||||
using APISectionStats = ::esphome::api::APISectionStats;
|
||||
|
||||
void start();
|
||||
void loop();
|
||||
|
||||
@@ -556,6 +563,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
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -13,11 +13,71 @@
|
||||
|
||||
#include "api_noise_context.h"
|
||||
#include "esphome/components/socket/socket.h"
|
||||
#include "esphome/core/application.h"
|
||||
#include <map>
|
||||
#include <string>
|
||||
|
||||
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<float>(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<float>(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 {
|
||||
@@ -86,13 +146,13 @@ 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<std::string, APISectionStats> *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;
|
||||
// Get the frame footer size required by this protocol
|
||||
virtual uint8_t frame_footer_size() = 0;
|
||||
// Check if socket has data ready to read
|
||||
bool is_socket_ready() const { return socket_ != nullptr && socket_->ready(); }
|
||||
|
||||
protected:
|
||||
// Struct for holding parsed frame data
|
||||
@@ -163,6 +223,9 @@ class APIFrameHelper {
|
||||
|
||||
// Common initialization for both plaintext and noise protocols
|
||||
APIError init_common_();
|
||||
|
||||
// Stats collection pointer - shared from APIConnection
|
||||
std::map<std::string, APISectionStats> *section_stats_{nullptr};
|
||||
};
|
||||
|
||||
#ifdef USE_API_NOISE
|
||||
|
||||
@@ -43,7 +43,7 @@ void APIServer::setup() {
|
||||
}
|
||||
#endif
|
||||
|
||||
this->socket_ = socket::socket_ip_loop_monitored(SOCK_STREAM, 0); // monitored for incoming connections
|
||||
this->socket_ = socket::socket_ip(SOCK_STREAM, 0);
|
||||
if (this->socket_ == nullptr) {
|
||||
ESP_LOGW(TAG, "Could not create socket");
|
||||
this->mark_failed();
|
||||
@@ -112,20 +112,18 @@ void APIServer::setup() {
|
||||
}
|
||||
|
||||
void APIServer::loop() {
|
||||
// Accept new clients only if the socket has incoming connections
|
||||
if (this->socket_->ready()) {
|
||||
while (true) {
|
||||
struct sockaddr_storage source_addr;
|
||||
socklen_t addr_len = sizeof(source_addr);
|
||||
auto sock = this->socket_->accept_loop_monitored((struct sockaddr *) &source_addr, &addr_len);
|
||||
if (!sock)
|
||||
break;
|
||||
ESP_LOGD(TAG, "Accepted %s", sock->getpeername().c_str());
|
||||
// Accept new clients
|
||||
while (true) {
|
||||
struct sockaddr_storage source_addr;
|
||||
socklen_t addr_len = sizeof(source_addr);
|
||||
auto sock = this->socket_->accept((struct sockaddr *) &source_addr, &addr_len);
|
||||
if (!sock)
|
||||
break;
|
||||
ESP_LOGD(TAG, "Accepted %s", sock->getpeername().c_str());
|
||||
|
||||
auto *conn = new APIConnection(std::move(sock), this);
|
||||
this->clients_.emplace_back(conn);
|
||||
conn->start();
|
||||
}
|
||||
auto *conn = new APIConnection(std::move(sock), this);
|
||||
this->clients_.emplace_back(conn);
|
||||
conn->start();
|
||||
}
|
||||
|
||||
// Process clients and remove disconnected ones in a single pass
|
||||
|
||||
@@ -26,7 +26,7 @@ void ESPHomeOTAComponent::setup() {
|
||||
ota::register_ota_platform(this);
|
||||
#endif
|
||||
|
||||
server_ = socket::socket_ip_loop_monitored(SOCK_STREAM, 0); // monitored for incoming connections
|
||||
server_ = socket::socket_ip(SOCK_STREAM, 0);
|
||||
if (server_ == nullptr) {
|
||||
ESP_LOGW(TAG, "Could not create socket");
|
||||
this->mark_failed();
|
||||
@@ -100,12 +100,9 @@ void ESPHomeOTAComponent::handle_() {
|
||||
#endif
|
||||
|
||||
if (client_ == nullptr) {
|
||||
// Check if the server socket is ready before accepting
|
||||
if (this->server_->ready()) {
|
||||
struct sockaddr_storage source_addr;
|
||||
socklen_t addr_len = sizeof(source_addr);
|
||||
client_ = server_->accept((struct sockaddr *) &source_addr, &addr_len);
|
||||
}
|
||||
struct sockaddr_storage source_addr;
|
||||
socklen_t addr_len = sizeof(source_addr);
|
||||
client_ = server_->accept((struct sockaddr *) &source_addr, &addr_len);
|
||||
}
|
||||
if (client_ == nullptr)
|
||||
return;
|
||||
|
||||
@@ -1,26 +0,0 @@
|
||||
"""
|
||||
Runtime statistics component for ESPHome.
|
||||
"""
|
||||
|
||||
import esphome.codegen as cg
|
||||
import esphome.config_validation as cv
|
||||
|
||||
DEPENDENCIES = []
|
||||
|
||||
CONF_ENABLED = "enabled"
|
||||
CONF_LOG_INTERVAL = "log_interval"
|
||||
|
||||
CONFIG_SCHEMA = cv.Schema(
|
||||
{
|
||||
cv.Optional(CONF_ENABLED, default=True): cv.boolean,
|
||||
cv.Optional(
|
||||
CONF_LOG_INTERVAL, default=60000
|
||||
): cv.positive_time_period_milliseconds,
|
||||
}
|
||||
)
|
||||
|
||||
|
||||
async def to_code(config):
|
||||
"""Generate code for the runtime statistics component."""
|
||||
cg.add(cg.App.set_runtime_stats_enabled(config[CONF_ENABLED]))
|
||||
cg.add(cg.App.set_runtime_stats_log_interval(config[CONF_LOG_INTERVAL]))
|
||||
@@ -35,7 +35,5 @@ async def to_code(config):
|
||||
cg.add_define("USE_SOCKET_IMPL_LWIP_TCP")
|
||||
elif impl == IMPLEMENTATION_LWIP_SOCKETS:
|
||||
cg.add_define("USE_SOCKET_IMPL_LWIP_SOCKETS")
|
||||
cg.add_define("USE_SOCKET_SELECT_SUPPORT")
|
||||
elif impl == IMPLEMENTATION_BSD_SOCKETS:
|
||||
cg.add_define("USE_SOCKET_IMPL_BSD_SOCKETS")
|
||||
cg.add_define("USE_SOCKET_SELECT_SUPPORT")
|
||||
|
||||
@@ -5,7 +5,6 @@
|
||||
#ifdef USE_SOCKET_IMPL_BSD_SOCKETS
|
||||
|
||||
#include <cstring>
|
||||
#include "esphome/core/application.h"
|
||||
|
||||
#ifdef USE_ESP32
|
||||
#include <esp_idf_version.h>
|
||||
@@ -41,20 +40,7 @@ std::string format_sockaddr(const struct sockaddr_storage &storage) {
|
||||
|
||||
class BSDSocketImpl : public Socket {
|
||||
public:
|
||||
BSDSocketImpl(int fd, bool monitor_loop = false) : fd_(fd) {
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
// Register new socket with the application for select() if monitoring requested
|
||||
if (monitor_loop && fd_ >= 0) {
|
||||
// Only set loop_monitored_ to true if registration succeeds
|
||||
loop_monitored_ = App.register_socket_fd(fd_);
|
||||
} else {
|
||||
loop_monitored_ = false;
|
||||
}
|
||||
#else
|
||||
// Without select support, ignore monitor_loop parameter
|
||||
(void) monitor_loop;
|
||||
#endif
|
||||
}
|
||||
BSDSocketImpl(int fd) : fd_(fd) {}
|
||||
~BSDSocketImpl() override {
|
||||
if (!closed_) {
|
||||
close(); // NOLINT(clang-analyzer-optin.cplusplus.VirtualCall)
|
||||
@@ -62,35 +48,16 @@ class BSDSocketImpl : public Socket {
|
||||
}
|
||||
int connect(const struct sockaddr *addr, socklen_t addrlen) override { return ::connect(fd_, addr, addrlen); }
|
||||
std::unique_ptr<Socket> accept(struct sockaddr *addr, socklen_t *addrlen) override {
|
||||
return accept_impl_(addr, addrlen, false);
|
||||
}
|
||||
std::unique_ptr<Socket> accept_loop_monitored(struct sockaddr *addr, socklen_t *addrlen) override {
|
||||
return accept_impl_(addr, addrlen, true);
|
||||
}
|
||||
|
||||
private:
|
||||
std::unique_ptr<Socket> accept_impl_(struct sockaddr *addr, socklen_t *addrlen, bool loop_monitored) {
|
||||
int fd = ::accept(fd_, addr, addrlen);
|
||||
if (fd == -1)
|
||||
return {};
|
||||
return make_unique<BSDSocketImpl>(fd, loop_monitored);
|
||||
return make_unique<BSDSocketImpl>(fd);
|
||||
}
|
||||
|
||||
public:
|
||||
int bind(const struct sockaddr *addr, socklen_t addrlen) override { return ::bind(fd_, addr, addrlen); }
|
||||
int close() override {
|
||||
if (!closed_) {
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
// Unregister from select() before closing if monitored
|
||||
if (loop_monitored_) {
|
||||
App.unregister_socket_fd(fd_);
|
||||
}
|
||||
#endif
|
||||
int ret = ::close(fd_);
|
||||
closed_ = true;
|
||||
return ret;
|
||||
}
|
||||
return 0;
|
||||
int ret = ::close(fd_);
|
||||
closed_ = true;
|
||||
return ret;
|
||||
}
|
||||
int shutdown(int how) override { return ::shutdown(fd_, how); }
|
||||
|
||||
@@ -159,27 +126,16 @@ class BSDSocketImpl : public Socket {
|
||||
return 0;
|
||||
}
|
||||
|
||||
int get_fd() const override { return fd_; }
|
||||
|
||||
protected:
|
||||
int fd_;
|
||||
bool closed_ = false;
|
||||
};
|
||||
|
||||
// Helper to create a socket with optional monitoring
|
||||
static std::unique_ptr<Socket> create_socket(int domain, int type, int protocol, bool loop_monitored = false) {
|
||||
std::unique_ptr<Socket> socket(int domain, int type, int protocol) {
|
||||
int ret = ::socket(domain, type, protocol);
|
||||
if (ret == -1)
|
||||
return nullptr;
|
||||
return std::unique_ptr<Socket>{new BSDSocketImpl(ret, loop_monitored)};
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket(int domain, int type, int protocol) {
|
||||
return create_socket(domain, type, protocol, false);
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket_loop_monitored(int domain, int type, int protocol) {
|
||||
return create_socket(domain, type, protocol, true);
|
||||
return std::unique_ptr<Socket>{new BSDSocketImpl(ret)};
|
||||
}
|
||||
|
||||
} // namespace socket
|
||||
|
||||
@@ -606,11 +606,6 @@ std::unique_ptr<Socket> socket(int domain, int type, int protocol) {
|
||||
return std::unique_ptr<Socket>{sock};
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket_loop_monitored(int domain, int type, int protocol) {
|
||||
// LWIPRawImpl doesn't use file descriptors, so monitoring is not applicable
|
||||
return socket(domain, type, protocol);
|
||||
}
|
||||
|
||||
} // namespace socket
|
||||
} // namespace esphome
|
||||
|
||||
|
||||
@@ -5,7 +5,6 @@
|
||||
#ifdef USE_SOCKET_IMPL_LWIP_SOCKETS
|
||||
|
||||
#include <cstring>
|
||||
#include "esphome/core/application.h"
|
||||
|
||||
namespace esphome {
|
||||
namespace socket {
|
||||
@@ -34,20 +33,7 @@ std::string format_sockaddr(const struct sockaddr_storage &storage) {
|
||||
|
||||
class LwIPSocketImpl : public Socket {
|
||||
public:
|
||||
LwIPSocketImpl(int fd, bool monitor_loop = false) : fd_(fd) {
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
// Register new socket with the application for select() if monitoring requested
|
||||
if (monitor_loop && fd_ >= 0) {
|
||||
// Only set loop_monitored_ to true if registration succeeds
|
||||
loop_monitored_ = App.register_socket_fd(fd_);
|
||||
} else {
|
||||
loop_monitored_ = false;
|
||||
}
|
||||
#else
|
||||
// Without select support, ignore monitor_loop parameter
|
||||
(void) monitor_loop;
|
||||
#endif
|
||||
}
|
||||
LwIPSocketImpl(int fd) : fd_(fd) {}
|
||||
~LwIPSocketImpl() override {
|
||||
if (!closed_) {
|
||||
close(); // NOLINT(clang-analyzer-optin.cplusplus.VirtualCall)
|
||||
@@ -55,35 +41,16 @@ class LwIPSocketImpl : public Socket {
|
||||
}
|
||||
int connect(const struct sockaddr *addr, socklen_t addrlen) override { return lwip_connect(fd_, addr, addrlen); }
|
||||
std::unique_ptr<Socket> accept(struct sockaddr *addr, socklen_t *addrlen) override {
|
||||
return accept_impl_(addr, addrlen, false);
|
||||
}
|
||||
std::unique_ptr<Socket> accept_loop_monitored(struct sockaddr *addr, socklen_t *addrlen) override {
|
||||
return accept_impl_(addr, addrlen, true);
|
||||
}
|
||||
|
||||
private:
|
||||
std::unique_ptr<Socket> accept_impl_(struct sockaddr *addr, socklen_t *addrlen, bool loop_monitored) {
|
||||
int fd = lwip_accept(fd_, addr, addrlen);
|
||||
if (fd == -1)
|
||||
return {};
|
||||
return make_unique<LwIPSocketImpl>(fd, loop_monitored);
|
||||
return make_unique<LwIPSocketImpl>(fd);
|
||||
}
|
||||
|
||||
public:
|
||||
int bind(const struct sockaddr *addr, socklen_t addrlen) override { return lwip_bind(fd_, addr, addrlen); }
|
||||
int close() override {
|
||||
if (!closed_) {
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
// Unregister from select() before closing if monitored
|
||||
if (loop_monitored_) {
|
||||
App.unregister_socket_fd(fd_);
|
||||
}
|
||||
#endif
|
||||
int ret = lwip_close(fd_);
|
||||
closed_ = true;
|
||||
return ret;
|
||||
}
|
||||
return 0;
|
||||
int ret = lwip_close(fd_);
|
||||
closed_ = true;
|
||||
return ret;
|
||||
}
|
||||
int shutdown(int how) override { return lwip_shutdown(fd_, how); }
|
||||
|
||||
@@ -131,27 +98,16 @@ class LwIPSocketImpl : public Socket {
|
||||
return 0;
|
||||
}
|
||||
|
||||
int get_fd() const override { return fd_; }
|
||||
|
||||
protected:
|
||||
int fd_;
|
||||
bool closed_ = false;
|
||||
};
|
||||
|
||||
// Helper to create a socket with optional monitoring
|
||||
static std::unique_ptr<Socket> create_socket(int domain, int type, int protocol, bool loop_monitored = false) {
|
||||
std::unique_ptr<Socket> socket(int domain, int type, int protocol) {
|
||||
int ret = lwip_socket(domain, type, protocol);
|
||||
if (ret == -1)
|
||||
return nullptr;
|
||||
return std::unique_ptr<Socket>{new LwIPSocketImpl(ret, loop_monitored)};
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket(int domain, int type, int protocol) {
|
||||
return create_socket(domain, type, protocol, false);
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket_loop_monitored(int domain, int type, int protocol) {
|
||||
return create_socket(domain, type, protocol, true);
|
||||
return std::unique_ptr<Socket>{new LwIPSocketImpl(ret)};
|
||||
}
|
||||
|
||||
} // namespace socket
|
||||
|
||||
@@ -4,35 +4,12 @@
|
||||
#include <cstring>
|
||||
#include <string>
|
||||
#include "esphome/core/log.h"
|
||||
#include "esphome/core/application.h"
|
||||
|
||||
namespace esphome {
|
||||
namespace socket {
|
||||
|
||||
Socket::~Socket() {}
|
||||
|
||||
bool Socket::ready() const {
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
if (!loop_monitored_) {
|
||||
// Non-monitored sockets always return true (assume data may be available)
|
||||
return true;
|
||||
}
|
||||
|
||||
// For loop-monitored sockets, check with the Application's select() results
|
||||
int fd = this->get_fd();
|
||||
if (fd < 0) {
|
||||
// No valid file descriptor, assume ready (fallback behavior)
|
||||
return true;
|
||||
}
|
||||
|
||||
return App.is_socket_ready(fd);
|
||||
#else
|
||||
// Without select() support, we can't monitor sockets in the loop
|
||||
// Always return true (assume data may be available)
|
||||
return true;
|
||||
#endif
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket_ip(int type, int protocol) {
|
||||
#if USE_NETWORK_IPV6
|
||||
return socket(AF_INET6, type, protocol);
|
||||
@@ -41,14 +18,6 @@ std::unique_ptr<Socket> socket_ip(int type, int protocol) {
|
||||
#endif /* USE_NETWORK_IPV6 */
|
||||
}
|
||||
|
||||
std::unique_ptr<Socket> socket_ip_loop_monitored(int type, int protocol) {
|
||||
#if USE_NETWORK_IPV6
|
||||
return socket_loop_monitored(AF_INET6, type, protocol);
|
||||
#else
|
||||
return socket_loop_monitored(AF_INET, type, protocol);
|
||||
#endif /* USE_NETWORK_IPV6 */
|
||||
}
|
||||
|
||||
socklen_t set_sockaddr(struct sockaddr *addr, socklen_t addrlen, const std::string &ip_address, uint16_t port) {
|
||||
#if USE_NETWORK_IPV6
|
||||
if (ip_address.find(':') != std::string::npos) {
|
||||
|
||||
@@ -17,11 +17,6 @@ class Socket {
|
||||
Socket &operator=(const Socket &) = delete;
|
||||
|
||||
virtual std::unique_ptr<Socket> accept(struct sockaddr *addr, socklen_t *addrlen) = 0;
|
||||
/// Accept a connection and monitor it in the main loop
|
||||
/// NOTE: This function is NOT thread-safe and must only be called from the main loop
|
||||
virtual std::unique_ptr<Socket> accept_loop_monitored(struct sockaddr *addr, socklen_t *addrlen) {
|
||||
return accept(addr, addrlen); // Default implementation for backward compatibility
|
||||
}
|
||||
virtual int bind(const struct sockaddr *addr, socklen_t addrlen) = 0;
|
||||
virtual int close() = 0;
|
||||
// not supported yet:
|
||||
@@ -49,35 +44,14 @@ class Socket {
|
||||
|
||||
virtual int setblocking(bool blocking) = 0;
|
||||
virtual int loop() { return 0; };
|
||||
|
||||
/// Get the underlying file descriptor (returns -1 if not supported)
|
||||
virtual int get_fd() const { return -1; }
|
||||
|
||||
/// Check if socket has data ready to read
|
||||
/// For loop-monitored sockets, checks with the Application's select() results
|
||||
/// For non-monitored sockets, always returns true (assumes data may be available)
|
||||
bool ready() const;
|
||||
|
||||
protected:
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
bool loop_monitored_{false}; ///< Whether this socket is monitored by the event loop
|
||||
#endif
|
||||
};
|
||||
|
||||
/// Create a socket of the given domain, type and protocol.
|
||||
std::unique_ptr<Socket> socket(int domain, int type, int protocol);
|
||||
|
||||
/// Create a socket in the newest available IP domain (IPv6 or IPv4) of the given type and protocol.
|
||||
std::unique_ptr<Socket> socket_ip(int type, int protocol);
|
||||
|
||||
/// Create a socket and monitor it for data in the main loop.
|
||||
/// Like socket() but also registers the socket with the Application's select() loop.
|
||||
/// WARNING: These functions are NOT thread-safe. They must only be called from the main loop
|
||||
/// as they register the socket file descriptor with the global Application instance.
|
||||
/// NOTE: On ESP platforms, FD_SETSIZE is typically 10, limiting the number of monitored sockets.
|
||||
/// File descriptors >= FD_SETSIZE will not be monitored and will log an error.
|
||||
std::unique_ptr<Socket> socket_loop_monitored(int domain, int type, int protocol);
|
||||
std::unique_ptr<Socket> socket_ip_loop_monitored(int type, int protocol);
|
||||
|
||||
/// Set a sockaddr to the specified address and port for the IP version used by socket_ip().
|
||||
socklen_t set_sockaddr(struct sockaddr *addr, socklen_t addrlen, const std::string &ip_address, uint16_t port);
|
||||
|
||||
|
||||
@@ -2,30 +2,11 @@
|
||||
#include "esphome/core/log.h"
|
||||
#include "esphome/core/version.h"
|
||||
#include "esphome/core/hal.h"
|
||||
#include <algorithm>
|
||||
|
||||
#ifdef USE_STATUS_LED
|
||||
#include "esphome/components/status_led/status_led.h"
|
||||
#endif
|
||||
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
#include <cerrno>
|
||||
|
||||
#ifdef USE_SOCKET_IMPL_LWIP_SOCKETS
|
||||
// LWIP sockets implementation
|
||||
#include <lwip/sockets.h>
|
||||
#elif defined(USE_SOCKET_IMPL_BSD_SOCKETS)
|
||||
// BSD sockets implementation
|
||||
#ifdef USE_ESP32
|
||||
// ESP32 "BSD sockets" are actually LWIP under the hood
|
||||
#include <lwip/sockets.h>
|
||||
#else
|
||||
// True BSD sockets (e.g., host platform)
|
||||
#include <sys/select.h>
|
||||
#endif
|
||||
#endif
|
||||
#endif
|
||||
|
||||
namespace esphome {
|
||||
|
||||
static const char *const TAG = "app";
|
||||
@@ -125,65 +106,7 @@ void Application::loop() {
|
||||
// otherwise interval=0 schedules result in constant looping with almost no sleep
|
||||
next_schedule = std::max(next_schedule, delay_time / 2);
|
||||
delay_time = std::min(next_schedule, delay_time);
|
||||
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
if (!this->socket_fds_.empty()) {
|
||||
// Use select() with timeout when we have sockets to monitor
|
||||
|
||||
// Update fd_set if socket list has changed
|
||||
if (this->socket_fds_changed_) {
|
||||
FD_ZERO(&this->base_read_fds_);
|
||||
for (int fd : this->socket_fds_) {
|
||||
if (fd >= 0 && fd < FD_SETSIZE) {
|
||||
FD_SET(fd, &this->base_read_fds_);
|
||||
}
|
||||
}
|
||||
this->socket_fds_changed_ = false;
|
||||
}
|
||||
|
||||
// Copy base fd_set before each select
|
||||
this->read_fds_ = this->base_read_fds_;
|
||||
|
||||
// Convert delay_time (milliseconds) to timeval
|
||||
struct timeval tv;
|
||||
tv.tv_sec = delay_time / 1000;
|
||||
tv.tv_usec = (delay_time - tv.tv_sec * 1000) * 1000;
|
||||
|
||||
// Call select with timeout
|
||||
#if defined(USE_SOCKET_IMPL_LWIP_SOCKETS) || (defined(USE_ESP32) && defined(USE_SOCKET_IMPL_BSD_SOCKETS))
|
||||
// Use lwip_select() on platforms with lwIP - it's faster
|
||||
// Note: On ESP32 with BSD sockets, select() is already mapped to lwip_select() via macros,
|
||||
// but we explicitly call lwip_select() for clarity and to ensure we get the optimized version
|
||||
int ret = lwip_select(this->max_fd_ + 1, &this->read_fds_, nullptr, nullptr, &tv);
|
||||
#else
|
||||
// Use standard select() on other platforms (e.g., host/native builds)
|
||||
int ret = ::select(this->max_fd_ + 1, &this->read_fds_, nullptr, nullptr, &tv);
|
||||
#endif
|
||||
|
||||
if (ret < 0) {
|
||||
if (errno == EINTR) {
|
||||
// Interrupted by signal - this is normal, just continue
|
||||
// No need to delay as some time has already passed
|
||||
ESP_LOGVV(TAG, "select() interrupted by signal");
|
||||
} else {
|
||||
// Actual error - log and fall back to delay
|
||||
ESP_LOGW(TAG, "select() failed with errno %d", errno);
|
||||
delay(delay_time);
|
||||
}
|
||||
} else if (ret > 0) {
|
||||
ESP_LOGVV(TAG, "select() woke early: %d socket(s) ready (saved up to %ums)", ret, delay_time);
|
||||
} else {
|
||||
// ret == 0: timeout occurred (normal)
|
||||
ESP_LOGVV(TAG, "select() timeout after %ums (no sockets ready)", delay_time);
|
||||
}
|
||||
} else {
|
||||
// No sockets registered, use regular delay
|
||||
delay(delay_time);
|
||||
}
|
||||
#else
|
||||
// No select support, use regular delay
|
||||
delay(delay_time);
|
||||
#endif
|
||||
}
|
||||
this->last_loop_ = last_op_end_time;
|
||||
|
||||
@@ -244,67 +167,6 @@ void Application::calculate_looping_components_() {
|
||||
}
|
||||
}
|
||||
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
bool Application::register_socket_fd(int fd) {
|
||||
// WARNING: This function is NOT thread-safe and must only be called from the main loop
|
||||
// It modifies socket_fds_ and related variables without locking
|
||||
if (fd < 0)
|
||||
return false;
|
||||
|
||||
if (fd >= FD_SETSIZE) {
|
||||
ESP_LOGE(TAG, "Cannot monitor socket fd %d: exceeds FD_SETSIZE (%d)", fd, FD_SETSIZE);
|
||||
ESP_LOGE(TAG, "Socket will not be monitored for data - may cause performance issues!");
|
||||
return false;
|
||||
}
|
||||
|
||||
this->socket_fds_.push_back(fd);
|
||||
this->socket_fds_changed_ = true;
|
||||
|
||||
if (fd > this->max_fd_) {
|
||||
this->max_fd_ = fd;
|
||||
}
|
||||
|
||||
return true;
|
||||
}
|
||||
|
||||
void Application::unregister_socket_fd(int fd) {
|
||||
// WARNING: This function is NOT thread-safe and must only be called from the main loop
|
||||
// It modifies socket_fds_ and related variables without locking
|
||||
if (fd < 0)
|
||||
return;
|
||||
|
||||
auto it = std::find(this->socket_fds_.begin(), this->socket_fds_.end(), fd);
|
||||
if (it != this->socket_fds_.end()) {
|
||||
// Swap with last element and pop - O(1) removal since order doesn't matter
|
||||
if (it != this->socket_fds_.end() - 1) {
|
||||
std::swap(*it, this->socket_fds_.back());
|
||||
}
|
||||
this->socket_fds_.pop_back();
|
||||
this->socket_fds_changed_ = true;
|
||||
|
||||
// Only recalculate max_fd if we removed the current max
|
||||
if (fd == this->max_fd_) {
|
||||
if (this->socket_fds_.empty()) {
|
||||
this->max_fd_ = -1;
|
||||
} else {
|
||||
// Find new max using std::max_element
|
||||
this->max_fd_ = *std::max_element(this->socket_fds_.begin(), this->socket_fds_.end());
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
bool Application::is_socket_ready(int fd) const {
|
||||
// This function is thread-safe for reading the result of select()
|
||||
// However, it should only be called after select() has been executed in the main loop
|
||||
// The read_fds_ is only modified by select() in the main loop
|
||||
if (fd < 0 || fd >= FD_SETSIZE)
|
||||
return false;
|
||||
|
||||
return FD_ISSET(fd, &this->read_fds_);
|
||||
}
|
||||
#endif
|
||||
|
||||
Application App; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables)
|
||||
|
||||
} // namespace esphome
|
||||
|
||||
@@ -7,13 +7,8 @@
|
||||
#include "esphome/core/hal.h"
|
||||
#include "esphome/core/helpers.h"
|
||||
#include "esphome/core/preferences.h"
|
||||
#include "esphome/core/runtime_stats.h"
|
||||
#include "esphome/core/scheduler.h"
|
||||
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
#include <sys/select.h>
|
||||
#endif
|
||||
|
||||
#ifdef USE_BINARY_SENSOR
|
||||
#include "esphome/components/binary_sensor/binary_sensor.h"
|
||||
#endif
|
||||
@@ -242,18 +237,6 @@ class Application {
|
||||
|
||||
uint32_t get_loop_interval() const { return this->loop_interval_; }
|
||||
|
||||
/** Enable or disable runtime statistics collection.
|
||||
*
|
||||
* @param enable Whether to enable runtime statistics collection.
|
||||
*/
|
||||
void set_runtime_stats_enabled(bool enable) { runtime_stats.set_enabled(enable); }
|
||||
|
||||
/** Set the interval at which runtime statistics are logged.
|
||||
*
|
||||
* @param interval The interval in milliseconds between logging of runtime statistics.
|
||||
*/
|
||||
void set_runtime_stats_log_interval(uint32_t interval) { runtime_stats.set_log_interval(interval); }
|
||||
|
||||
void schedule_dump_config() { this->dump_config_at_ = 0; }
|
||||
|
||||
void feed_wdt(uint32_t time = 0);
|
||||
@@ -484,19 +467,6 @@ class Application {
|
||||
|
||||
Scheduler scheduler;
|
||||
|
||||
/// Register/unregister a socket file descriptor to be monitored for read events.
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
/// These functions update the fd_set used by select() in the main loop.
|
||||
/// WARNING: These functions are NOT thread-safe. They must only be called from the main loop.
|
||||
/// NOTE: File descriptors >= FD_SETSIZE (typically 10 on ESP) will be rejected with an error.
|
||||
/// @return true if registration was successful, false if fd exceeds limits
|
||||
bool register_socket_fd(int fd);
|
||||
void unregister_socket_fd(int fd);
|
||||
/// Check if there's data available on a socket without blocking
|
||||
/// This function is thread-safe for reading, but should be called after select() has run
|
||||
bool is_socket_ready(int fd) const;
|
||||
#endif
|
||||
|
||||
protected:
|
||||
friend Component;
|
||||
|
||||
@@ -580,20 +550,11 @@ class Application {
|
||||
const char *compilation_time_{nullptr};
|
||||
bool name_add_mac_suffix_;
|
||||
uint32_t last_loop_{0};
|
||||
uint32_t loop_interval_{16}; // Standard interval for platforms without select()
|
||||
uint32_t loop_interval_{16};
|
||||
size_t dump_config_at_{SIZE_MAX};
|
||||
uint32_t app_state_{0};
|
||||
Component *current_component_{nullptr};
|
||||
uint32_t loop_component_start_time_{0};
|
||||
|
||||
#ifdef USE_SOCKET_SELECT_SUPPORT
|
||||
// Socket select management
|
||||
std::vector<int> socket_fds_; // Vector of all monitored socket file descriptors
|
||||
bool socket_fds_changed_{false}; // Flag to rebuild base_read_fds_ when socket_fds_ changes
|
||||
int max_fd_{-1}; // Highest file descriptor number for select()
|
||||
fd_set base_read_fds_{}; // Cached fd_set rebuilt only when socket_fds_ changes
|
||||
fd_set read_fds_{}; // Working fd_set for select(), copied from base_read_fds_
|
||||
#endif
|
||||
};
|
||||
|
||||
/// Global storage of Application pointer - only one Application can exist.
|
||||
|
||||
@@ -246,9 +246,6 @@ uint32_t WarnIfComponentBlockingGuard::finish() {
|
||||
uint32_t curr_time = millis();
|
||||
|
||||
uint32_t blocking_time = curr_time - this->started_;
|
||||
|
||||
// Record component runtime stats
|
||||
runtime_stats.record_component_time(this->component_, blocking_time, curr_time);
|
||||
bool should_warn;
|
||||
if (this->component_ != nullptr) {
|
||||
should_warn = this->component_->should_warn_of_blocking(blocking_time);
|
||||
|
||||
@@ -6,7 +6,6 @@
|
||||
#include <string>
|
||||
|
||||
#include "esphome/core/optional.h"
|
||||
#include "esphome/core/runtime_stats.h"
|
||||
|
||||
namespace esphome {
|
||||
|
||||
|
||||
@@ -1,28 +0,0 @@
|
||||
#include "esphome/core/runtime_stats.h"
|
||||
#include "esphome/core/component.h"
|
||||
|
||||
namespace esphome {
|
||||
|
||||
RuntimeStatsCollector runtime_stats;
|
||||
|
||||
void RuntimeStatsCollector::record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time) {
|
||||
if (!this->enabled_ || component == nullptr)
|
||||
return;
|
||||
|
||||
const char *component_source = component->get_component_source();
|
||||
this->component_stats_[component_source].record_time(duration_ms);
|
||||
|
||||
// If next_log_time_ is 0, initialize it
|
||||
if (this->next_log_time_ == 0) {
|
||||
this->next_log_time_ = current_time + this->log_interval_;
|
||||
return;
|
||||
}
|
||||
|
||||
if (current_time >= this->next_log_time_) {
|
||||
this->log_stats_();
|
||||
this->reset_stats_();
|
||||
this->next_log_time_ = current_time + this->log_interval_;
|
||||
}
|
||||
}
|
||||
|
||||
} // namespace esphome
|
||||
@@ -1,161 +0,0 @@
|
||||
#pragma once
|
||||
|
||||
#include <map>
|
||||
#include <string>
|
||||
#include <vector>
|
||||
#include <cstdint>
|
||||
#include <algorithm>
|
||||
#include "esphome/core/helpers.h"
|
||||
#include "esphome/core/log.h"
|
||||
|
||||
namespace esphome {
|
||||
|
||||
static const char *const RUNTIME_TAG = "runtime";
|
||||
|
||||
class Component; // Forward declaration
|
||||
|
||||
class ComponentRuntimeStats {
|
||||
public:
|
||||
ComponentRuntimeStats()
|
||||
: 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_;
|
||||
};
|
||||
|
||||
// For sorting components by run time
|
||||
struct ComponentStatPair {
|
||||
std::string name;
|
||||
const ComponentRuntimeStats *stats;
|
||||
|
||||
bool operator>(const ComponentStatPair &other) const {
|
||||
// Sort by period time as that's what we're displaying in the logs
|
||||
return stats->get_period_time_ms() > other.stats->get_period_time_ms();
|
||||
}
|
||||
};
|
||||
|
||||
class RuntimeStatsCollector {
|
||||
public:
|
||||
RuntimeStatsCollector() : log_interval_(60000), next_log_time_(0), enabled_(true) {}
|
||||
|
||||
void set_log_interval(uint32_t log_interval) { this->log_interval_ = log_interval; }
|
||||
uint32_t get_log_interval() const { return this->log_interval_; }
|
||||
|
||||
void set_enabled(bool enabled) { this->enabled_ = enabled; }
|
||||
bool is_enabled() const { return this->enabled_; }
|
||||
|
||||
void record_component_time(Component *component, uint32_t duration_ms, uint32_t current_time);
|
||||
|
||||
protected:
|
||||
void log_stats_() {
|
||||
ESP_LOGI(RUNTIME_TAG, "Component Runtime Statistics");
|
||||
ESP_LOGI(RUNTIME_TAG, "Period stats (last %" PRIu32 "ms):", this->log_interval_);
|
||||
|
||||
// First collect stats we want to display
|
||||
std::vector<ComponentStatPair> stats_to_display;
|
||||
|
||||
for (const auto &it : this->component_stats_) {
|
||||
const ComponentRuntimeStats &stats = it.second;
|
||||
if (stats.get_period_count() > 0) {
|
||||
ComponentStatPair pair = {it.first, &stats};
|
||||
stats_to_display.push_back(pair);
|
||||
}
|
||||
}
|
||||
|
||||
// Sort by period runtime (descending)
|
||||
std::sort(stats_to_display.begin(), stats_to_display.end(), std::greater<ComponentStatPair>());
|
||||
|
||||
// Log top components by period runtime
|
||||
for (const auto &it : stats_to_display) {
|
||||
const std::string &source = it.name;
|
||||
const ComponentRuntimeStats *stats = it.stats;
|
||||
|
||||
ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms",
|
||||
source.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(RUNTIME_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 ComponentStatPair &a, const ComponentStatPair &b) {
|
||||
return a.stats->get_total_time_ms() > b.stats->get_total_time_ms();
|
||||
});
|
||||
|
||||
for (const auto &it : stats_to_display) {
|
||||
const std::string &source = it.name;
|
||||
const ComponentRuntimeStats *stats = it.stats;
|
||||
|
||||
ESP_LOGI(RUNTIME_TAG, " %s: count=%" PRIu32 ", avg=%.2fms, max=%" PRIu32 "ms, total=%" PRIu32 "ms",
|
||||
source.c_str(), stats->get_total_count(), stats->get_total_avg_time_ms(), stats->get_total_max_time_ms(),
|
||||
stats->get_total_time_ms());
|
||||
}
|
||||
}
|
||||
|
||||
void reset_stats_() {
|
||||
for (auto &it : this->component_stats_) {
|
||||
it.second.reset_period_stats();
|
||||
}
|
||||
}
|
||||
|
||||
std::map<std::string, ComponentRuntimeStats> component_stats_;
|
||||
uint32_t log_interval_;
|
||||
uint32_t next_log_time_;
|
||||
bool enabled_;
|
||||
};
|
||||
|
||||
// Global instance for runtime stats collection
|
||||
extern RuntimeStatsCollector runtime_stats;
|
||||
|
||||
} // namespace esphome
|
||||
Reference in New Issue
Block a user