From 9c709869090dc8aefeab300850dfeaf8ea30f43d Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Fri, 10 Apr 2026 16:13:56 -1000 Subject: [PATCH] [esphome.ota] TEMP: log server_->ready() after setup + add global rcvplus counter --- .../components/esphome/ota/ota_esphome.cpp | 27 +++++++++++++++---- esphome/core/lwip_fast_select.c | 6 +++++ esphome/core/lwip_fast_select.h | 3 +++ 3 files changed, 31 insertions(+), 5 deletions(-) diff --git a/esphome/components/esphome/ota/ota_esphome.cpp b/esphome/components/esphome/ota/ota_esphome.cpp index dac8b6e1c7..fb583e6d7a 100644 --- a/esphome/components/esphome/ota/ota_esphome.cpp +++ b/esphome/components/esphome/ota/ota_esphome.cpp @@ -15,6 +15,9 @@ #include "esphome/core/helpers.h" #include "esphome/core/log.h" #include "esphome/core/util.h" +#ifdef USE_LWIP_FAST_SELECT +#include "esphome/core/lwip_fast_select.h" +#endif #include #include @@ -34,6 +37,13 @@ void ESPHomeOTAComponent::setup() { this->server_failed_(LOG_STR("creation")); return; } + // DEBUG: immediately after socket creation, ready() on an idle monitored socket + // MUST return false. If it returns true, loop_monitored_ is false — meaning + // App.register_socket() failed (likely because esphome_lwip_get_sock returned null + // because the socket fd is outside the lwip socket table range), and our wake hook + // was never installed on this socket. In that case the whole disable_loop+wake + // approach silently degrades — ready() stays true forever and we poll every tick. + ESP_LOGD(TAG, "setup: server_->ready() immediately after socket creation = %d (expect 0)", this->server_->ready()); int enable = 1; int err = this->server_->setsockopt(SOL_SOCKET, SO_REUSEADDR, &enable, sizeof(int)); if (err != 0) { @@ -104,16 +114,23 @@ void ESPHomeOTAComponent::loop() { // // Note: No need to check server_ for null — setup() marks the component failed // if server_ creation fails. - // DEBUG: self-disable removed. Log every tick with wake counter + ready state so - // we can tell (a) whether the lwip listener wake hook ever fires and (b) whether - // server_->ready() ever flips to true when a client tries to connect. + // DEBUG: self-disable removed; always poll so we can see ready/wake state. const uint32_t wake_count = App.ota_wake_count_debug(); +#ifdef USE_LWIP_FAST_SELECT + const uint32_t total_rcvplus = esphome_fast_select_rcvplus_total_debug; +#else + const uint32_t total_rcvplus = 0; +#endif const bool ready = this->server_->ready(); static uint32_t last_wake_count = 0; + static uint32_t last_total_rcvplus = 0; static bool last_ready = false; - if (wake_count != last_wake_count || ready != last_ready || this->client_ != nullptr) { - ESP_LOGD(TAG, "loop tick: client=%p ready=%d wakes=%u", (void *) this->client_.get(), ready, wake_count); + if (wake_count != last_wake_count || total_rcvplus != last_total_rcvplus || ready != last_ready || + this->client_ != nullptr) { + ESP_LOGD(TAG, "loop tick: client=%p ready=%d wakes=%u total_rcvplus=%u", (void *) this->client_.get(), ready, + wake_count, total_rcvplus); last_wake_count = wake_count; + last_total_rcvplus = total_rcvplus; last_ready = ready; } if (this->client_ == nullptr && !ready) { diff --git a/esphome/core/lwip_fast_select.c b/esphome/core/lwip_fast_select.c index 96eddf00ff..a3d9898757 100644 --- a/esphome/core/lwip_fast_select.c +++ b/esphome/core/lwip_fast_select.c @@ -157,6 +157,11 @@ _Static_assert(offsetof(struct lwip_sock, rcvevent) == ESPHOME_LWIP_SOCK_RCVEVEN // Saved original event_callback pointer — written once in first hook_socket(), read from TCP/IP task. static netconn_callback s_original_callback = NULL; +// DEBUG: counts every RCVPLUS the wrapper callback observes, for any monitored socket. +// Read by OTA's debug logging to distinguish "callback not firing at all" from +// "callback fires for other sockets but not OTA's listener". +volatile uint32_t esphome_fast_select_rcvplus_total_debug = 0; + #ifdef USE_OTA // Extern wake hook for the OTA component (implemented in application.cpp). Called from the // TCP/IP task on every NETCONN_EVT_RCVPLUS — not just OTA's listener, so this can be a false @@ -180,6 +185,7 @@ static void esphome_socket_event_callback(struct netconn *conn, enum netconn_evt // (rcvevent++ with a NULL pbuf or error in recvmbox), so error conditions // already wake the main loop through the RCVPLUS path. if (evt == NETCONN_EVT_RCVPLUS) { + esphome_fast_select_rcvplus_total_debug++; // DEBUG #ifdef USE_OTA // Mark the OTA component loop to be re-enabled if it disabled itself while idle. // This MUST happen before xTaskNotifyGive below — otherwise the main task could diff --git a/esphome/core/lwip_fast_select.h b/esphome/core/lwip_fast_select.h index 20ac191673..6ed2704ef0 100644 --- a/esphome/core/lwip_fast_select.h +++ b/esphome/core/lwip_fast_select.h @@ -53,6 +53,9 @@ static inline bool esphome_lwip_socket_has_data(struct lwip_sock *sock) { /// The sock pointer must have been obtained from esphome_lwip_get_sock(). void esphome_lwip_hook_socket(struct lwip_sock *sock); +// DEBUG counter: total RCVPLUS events the wrapper callback observed across all monitored sockets. +extern volatile uint32_t esphome_fast_select_rcvplus_total_debug; + /// Set or clear TCP_NODELAY on a socket's tcp_pcb directly. /// Must be called with the TCPIP core lock held (LwIPLock in C++). /// This bypasses lwip_setsockopt() overhead (socket lookups, switch cascade,