Fix SENSOR power saving deep sleep truncating TX and skipping sleep on failed reads (#10939)

* Fix SENSOR power saving deep sleep behavior

Deep sleep could be entered while a telemetry packet was still queued
or on air, truncating the transmission. canSleep() gained a deepSleep
parameter and now vetoes in that case; light sleep is unchanged.
Telemetry modules defer a pending deep sleep (bounded to 30s) until the
radio is idle and no longer let the sensor polling interval override
the 5s pre-sleep grace period. A failed sensor read still arms deep
sleep instead of leaving the node awake for a full telemetry interval.

Fixes #10890
Fixes #10932

* Deduplicate telemetry deep sleep deferral logic

Move the radio-busy deferral and its counter into BaseTelemetryModule
and add an isPowerSavingSensor() helper. Removes the telemetry-specific
counter from OSThread. The sleep arming block stays per module because
it needs protected OSThread members not visible to the base class.

src/mesh/RadioInterface.h

@@ -141,8 +141,12 @@ class RadioInterface
      * Return true if we think the board can go to sleep (i.e. our tx queue is empty, we are not sending or receiving)
      *
      * This method must be used before putting the CPU into deep or light sleep.
+     *
+     * @param deepSleep true when the radio itself is about to be powered down (deep sleep or
+     * shutdown) - an in-flight transmission then vetoes sleep, since it would be truncated on
+     * air. false for a light sleep where the radio stays powered and finishes the TX on its own.
      */
-    virtual bool canSleep() { return true; }
+    virtual bool canSleep(bool deepSleep = false) { return true; }
 
     virtual bool wideLora() { return false; }
 
@@ -314,8 +318,9 @@ class RadioInterface
      */
     void applyModemConfig();
 
-    /// Return 0 if sleep is okay
+    /// Return 0 if sleep is okay. A non-NULL argument means the radio is about to be powered
-    int preflightSleepCb(void *unused = NULL) { return canSleep() ? 0 : 1; }
+    /// down (deep sleep / shutdown), see doPreflightSleep()
+    int preflightSleepCb(void *deepSleep = NULL) { return canSleep(deepSleep != NULL) ? 0 : 1; }
 
     int notifyDeepSleepCb(void *unused = NULL);
 

src/mesh/RadioLibInterface.cpp

@@ -222,11 +222,15 @@ meshtastic_QueueStatus RadioLibInterface::getQueueStatus()
     return qs;
 }
 
-bool RadioLibInterface::canSleep()
+bool RadioLibInterface::canSleep(bool deepSleep)
 {
-    bool res = txQueue.empty();
+    // A packet being actively transmitted has already left the TX queue (sendingPacket), so
+    // check it separately. It only vetoes deep sleep: light sleep keeps the radio powered and
+    // the TX finishes on its own, but deep sleep powers the radio down and would truncate the
+    // packet on air.
+    bool res = txQueue.empty() && !(deepSleep && isSending());
     if (!res) { // only print debug messages if we are vetoing sleep
-        LOG_DEBUG("Radio wait to sleep, txEmpty=%d", res);
+        LOG_DEBUG("Radio wait to sleep, txEmpty=%d, txInFlight=%d", txQueue.empty(), isSending());
     }
     return res;
 }

src/mesh/RadioLibInterface.h

@@ -180,8 +180,9 @@ class RadioLibInterface : public RadioInterface, protected concurrency::Notified
      * Return true if we think the board can go to sleep (i.e. our tx queue is empty, we are not sending or receiving)
      *
      * This method must be used before putting the CPU into deep or light sleep.
+     * With deepSleep set, an in-flight transmission also vetoes sleep (see RadioInterface).
      */
-    virtual bool canSleep() override;
+    virtual bool canSleep(bool deepSleep) override;
 
     /**
      * Start waiting to receive a message

src/modules/Telemetry/AirQualityTelemetry.cpp

@@ -119,6 +119,8 @@ void AirQualityTelemetryModule::i2cScanFinished(ScanI2C *i2cScanner)
 int32_t AirQualityTelemetryModule::runOnce()
 {
     if (sleepOnNextExecution == true) {
+        if (shouldDeferDeepSleep())
+            return PREFLIGHT_SLEEP_RETRY_MS;
         sleepOnNextExecution = false;
         uint32_t nightyNightMs = Default::getConfiguredOrDefaultMs(moduleConfig.telemetry.air_quality_interval,
                                                                    default_telemetry_broadcast_interval_secs);
@@ -223,6 +225,12 @@ int32_t AirQualityTelemetryModule::runOnce()
             }
         }
     }
+    if (sleepOnNextExecution) {
+        // Honor the pre-sleep grace period armed in sendTelemetry(): OSThread reschedules with
+        // this return value, which would otherwise override setIntervalFromNow() and delay or
+        // mistime the pending deep sleep
+        return FIVE_SECONDS_MS;
+    }
     return min(sendToPhoneIntervalMs, result);
 }
 
@@ -422,7 +430,8 @@ bool AirQualityTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
     m.which_variant = meshtastic_Telemetry_air_quality_metrics_tag;
     m.time = getTime();
 
-    if (getAirQualityTelemetry(&m)) {
+    bool validTelemetry = getAirQualityTelemetry(&m);
+    if (validTelemetry) {
 
         bool hasAnyPM =
             m.variant.air_quality_metrics.has_pm10_standard || m.variant.air_quality_metrics.has_pm25_standard ||
@@ -474,7 +483,7 @@ bool AirQualityTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
             LOG_INFO("Sending packet to mesh");
             service->sendToMesh(p, RX_SRC_LOCAL, true);
 
-            if (config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving) {
+            if (isPowerSavingSensor()) {
                 meshtastic_ClientNotification *notification = clientNotificationPool.allocZeroed();
                 notification->level = meshtastic_LogRecord_Level_INFO;
                 notification->time = getValidTime(RTCQualityFromNet);
@@ -483,14 +492,22 @@ bool AirQualityTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
                                                           default_telemetry_broadcast_interval_secs) /
                             1000U);
                 service->sendClientNotification(notification);
-                sleepOnNextExecution = true;
-                LOG_DEBUG("Start next execution in 5s, then sleep");
-                setIntervalFromNow(FIVE_SECONDS_MS);
             }
         }
-        return true;
     }
-    return false;
+
+    // Arm the pre-sleep sequence even when no valid reading was available this cycle: a
+    // power-saving SENSOR node must still return to deep sleep, otherwise it stays awake
+    // until the next telemetry interval and drains its battery
+    if (!phoneOnly && isPowerSavingSensor()) {
+        if (!validTelemetry)
+            LOG_WARN("Air quality telemetry unavailable this cycle, sleep without sending");
+        sleepOnNextExecution = true;
+        preflightSleepDeferrals = 0;
+        LOG_DEBUG("Start next execution in 5s, then sleep");
+        setIntervalFromNow(FIVE_SECONDS_MS);
+    }
+    return validTelemetry;
 }
 
 AdminMessageHandleResult AirQualityTelemetryModule::handleAdminMessageForModule(const meshtastic_MeshPacket &mp,

src/modules/Telemetry/BaseTelemetryModule.h

@@ -1,7 +1,9 @@
 #pragma once
 
+#include "DebugConfiguration.h"
 #include "NodeDB.h"
 #include "configuration.h"
+#include "sleep.h"
 
 class BaseTelemetryModule
 {
@@ -12,4 +14,32 @@ class BaseTelemetryModule
                config.device.role == meshtastic_Config_DeviceConfig_Role_ROUTER ||
                config.device.role == meshtastic_Config_DeviceConfig_Role_ROUTER_LATE;
     }
+
+    /// True for a SENSOR role node with power saving enabled, the only combination that deep
+    /// sleeps between telemetry broadcasts
+    bool isPowerSavingSensor() const
+    {
+        return config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving;
+    }
+
+    /**
+     * Call while a deep sleep is pending (sleepOnNextExecution): the telemetry packet queued by
+     * sendTelemetry() goes out asynchronously, and sleeping while it is still queued or on air
+     * truncates the transmission. Returns true if the caller should reschedule in
+     * PREFLIGHT_SLEEP_RETRY_MS and check again. Bounded by MAX_PREFLIGHT_SLEEP_DEFERRALS so a
+     * busy mesh can't keep the node awake forever. Reset preflightSleepDeferrals to 0 whenever
+     * sleepOnNextExecution is armed.
+     */
+    bool shouldDeferDeepSleep()
+    {
+        if (doPreflightSleep(true) || preflightSleepDeferrals >= MAX_PREFLIGHT_SLEEP_DEFERRALS)
+            return false;
+        preflightSleepDeferrals++;
+        LOG_DEBUG("Radio busy, defer deep sleep");
+        return true;
+    }
+
+    // While sleepOnNextExecution is pending, counts how often the deep sleep was postponed
+    // because doPreflightSleep() vetoed it (e.g. radio still transmitting)
+    uint32_t preflightSleepDeferrals = 0;
 };

src/modules/Telemetry/EnvironmentTelemetry.cpp

@@ -253,6 +253,8 @@ void EnvironmentTelemetryModule::i2cScanFinished(ScanI2C *i2cScanner)
 int32_t EnvironmentTelemetryModule::runOnce()
 {
     if (sleepOnNextExecution == true) {
+        if (shouldDeferDeepSleep())
+            return PREFLIGHT_SLEEP_RETRY_MS;
         sleepOnNextExecution = false;
         uint32_t nightyNightMs = Default::getConfiguredOrDefaultMs(moduleConfig.telemetry.environment_update_interval,
                                                                    default_telemetry_broadcast_interval_secs);
@@ -334,6 +336,12 @@ int32_t EnvironmentTelemetryModule::runOnce()
             lastSentToPhone = millis();
         }
     }
+    if (sleepOnNextExecution) {
+        // Honor the pre-sleep grace period armed in sendTelemetry(): OSThread reschedules with
+        // this return value, which would otherwise override setIntervalFromNow() with the sensor
+        // polling interval (35 ms for BSEC2) and trigger deep sleep while the TX is still on air
+        return FIVE_SECONDS_MS;
+    }
     return min(sendToPhoneIntervalMs, result);
 }
 
@@ -635,7 +643,8 @@ bool EnvironmentTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
     m.which_variant = meshtastic_Telemetry_environment_metrics_tag;
     m.time = getTime();
 
-    if (getEnvironmentTelemetry(&m)) {
+    bool validTelemetry = getEnvironmentTelemetry(&m);
+    if (validTelemetry) {
         LOG_INFO("Send: barometric_pressure=%f, current=%f, gas_resistance=%f, relative_humidity=%f, temperature=%f",
                  m.variant.environment_metrics.barometric_pressure, m.variant.environment_metrics.current,
                  m.variant.environment_metrics.gas_resistance, m.variant.environment_metrics.relative_humidity,
@@ -670,7 +679,7 @@ bool EnvironmentTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
             LOG_INFO("Send packet to mesh");
             service->sendToMesh(p, RX_SRC_LOCAL, true);
 
-            if (config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving) {
+            if (isPowerSavingSensor()) {
                 meshtastic_ClientNotification *notification = clientNotificationPool.allocZeroed();
                 notification->level = meshtastic_LogRecord_Level_INFO;
                 notification->time = getValidTime(RTCQualityFromNet);
@@ -679,14 +688,22 @@ bool EnvironmentTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
                                                           default_telemetry_broadcast_interval_secs) /
                             1000U);
                 service->sendClientNotification(notification);
-                sleepOnNextExecution = true;
-                LOG_DEBUG("Start next execution in 5s, then sleep");
-                setIntervalFromNow(FIVE_SECONDS_MS);
             }
         }
-        return true;
     }
-    return false;
+
+    // Arm the pre-sleep sequence even when no valid reading was available this cycle (e.g. a
+    // BSEC2 call timing violation): a power-saving SENSOR node must still return to deep sleep,
+    // otherwise it stays awake until the next telemetry interval and drains its battery
+    if (!phoneOnly && isPowerSavingSensor()) {
+        if (!validTelemetry)
+            LOG_WARN("Environment telemetry unavailable this cycle, sleep without sending");
+        sleepOnNextExecution = true;
+        preflightSleepDeferrals = 0;
+        LOG_DEBUG("Start next execution in 5s, then sleep");
+        setIntervalFromNow(FIVE_SECONDS_MS);
+    }
+    return validTelemetry;
 }
 
 AdminMessageHandleResult EnvironmentTelemetryModule::handleAdminMessageForModule(const meshtastic_MeshPacket &mp,

src/modules/Telemetry/HealthTelemetry.cpp

@@ -39,6 +39,8 @@ static constexpr uint16_t TX_HISTORY_KEY_HEALTH_TELEMETRY = 0x8003;
 int32_t HealthTelemetryModule::runOnce()
 {
     if (sleepOnNextExecution == true) {
+        if (shouldDeferDeepSleep())
+            return PREFLIGHT_SLEEP_RETRY_MS;
         sleepOnNextExecution = false;
         uint32_t nightyNightMs = Default::getConfiguredOrDefaultMs(moduleConfig.telemetry.health_update_interval,
                                                                    default_telemetry_broadcast_interval_secs);
@@ -91,6 +93,12 @@ int32_t HealthTelemetryModule::runOnce()
             lastSentToPhone = millis();
         }
     }
+    if (sleepOnNextExecution) {
+        // Honor the pre-sleep grace period armed in sendTelemetry(): OSThread reschedules with
+        // this return value, which would otherwise override setIntervalFromNow() with the
+        // sensor polling interval and trigger deep sleep while the TX is still on air
+        return FIVE_SECONDS_MS;
+    }
     return min(sendToPhoneIntervalMs, result);
 }
 
@@ -232,7 +240,8 @@ bool HealthTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
     meshtastic_Telemetry m = meshtastic_Telemetry_init_zero;
     m.which_variant = meshtastic_Telemetry_health_metrics_tag;
     m.time = getTime();
-    if (getHealthTelemetry(&m)) {
+    bool validTelemetry = getHealthTelemetry(&m);
+    if (validTelemetry) {
         LOG_INFO("Send: temperature=%f, heart_bpm=%d, spO2=%d", m.variant.health_metrics.temperature,
                  m.variant.health_metrics.heart_bpm, m.variant.health_metrics.spO2);
 
@@ -256,16 +265,21 @@ bool HealthTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
         } else {
             LOG_INFO("Send packet to mesh");
             service->sendToMesh(p, RX_SRC_LOCAL, true);
-
-            if (config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving) {
-                LOG_DEBUG("Start next execution in 5s, then sleep");
-                sleepOnNextExecution = true;
-                setIntervalFromNow(5000);
-            }
         }
-        return true;
     }
-    return false;
+
+    // Arm the pre-sleep sequence even when no valid reading was available this cycle: a
+    // power-saving SENSOR node must still return to deep sleep, otherwise it stays awake
+    // until the next telemetry interval and drains its battery
+    if (!phoneOnly && isPowerSavingSensor()) {
+        if (!validTelemetry)
+            LOG_WARN("Health telemetry unavailable this cycle, sleep without sending");
+        sleepOnNextExecution = true;
+        preflightSleepDeferrals = 0;
+        LOG_DEBUG("Start next execution in 5s, then sleep");
+        setIntervalFromNow(FIVE_SECONDS_MS);
+    }
+    return validTelemetry;
 }
 
 #endif

src/modules/Telemetry/PowerTelemetry.cpp

@@ -34,6 +34,8 @@ extern void drawCommonHeader(OLEDDisplay *display, int16_t x, int16_t y, const c
 int32_t PowerTelemetryModule::runOnce()
 {
     if (sleepOnNextExecution == true) {
+        if (shouldDeferDeepSleep())
+            return PREFLIGHT_SLEEP_RETRY_MS;
         sleepOnNextExecution = false;
         uint32_t nightyNightMs = Default::getConfiguredOrDefaultMs(moduleConfig.telemetry.power_update_interval,
                                                                    default_telemetry_broadcast_interval_secs);
@@ -106,6 +108,11 @@ int32_t PowerTelemetryModule::runOnce()
             lastSentToPhone = millis();
         }
     }
+    if (sleepOnNextExecution) {
+        // Honor the pre-sleep grace period armed in sendTelemetry(): OSThread reschedules with
+        // this return value, which would otherwise override setIntervalFromNow()
+        return FIVE_SECONDS_MS;
+    }
     return min(sendToPhoneIntervalMs, sendToMeshIntervalMs);
 }
 
@@ -258,7 +265,8 @@ bool PowerTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
     meshtastic_Telemetry m = meshtastic_Telemetry_init_zero;
     m.which_variant = meshtastic_Telemetry_power_metrics_tag;
     m.time = getTime();
-    if (getPowerTelemetry(&m)) {
+    bool validTelemetry = getPowerTelemetry(&m);
+    if (validTelemetry) {
         LOG_INFO("Send: ch1_voltage=%f, ch1_current=%f, ch2_voltage=%f, ch2_current=%f, "
                  "ch3_voltage=%f, ch3_current=%f",
                  m.variant.power_metrics.ch1_voltage, m.variant.power_metrics.ch1_current, m.variant.power_metrics.ch2_voltage,
@@ -284,16 +292,21 @@ bool PowerTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly)
         } else {
             LOG_INFO("Send packet to mesh");
             service->sendToMesh(p, RX_SRC_LOCAL, true);
-
-            if (config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving) {
-                LOG_DEBUG("Start next execution in 5s then sleep");
-                sleepOnNextExecution = true;
-                setIntervalFromNow(5000);
-            }
         }
-        return true;
     }
-    return false;
+
+    // Arm the pre-sleep sequence even when no valid reading was available this cycle: a
+    // power-saving SENSOR node must still return to deep sleep, otherwise it stays awake
+    // until the next telemetry interval and drains its battery
+    if (!phoneOnly && isPowerSavingSensor()) {
+        if (!validTelemetry)
+            LOG_WARN("Power telemetry unavailable this cycle, sleep without sending");
+        sleepOnNextExecution = true;
+        preflightSleepDeferrals = 0;
+        LOG_DEBUG("Start next execution in 5s then sleep");
+        setIntervalFromNow(FIVE_SECONDS_MS);
+    }
+    return validTelemetry;
 }
 
 #endif

src/sleep.cpp

@@ -190,20 +190,23 @@ void initDeepSleep()
 #endif
 }
 
-bool doPreflightSleep()
+bool doPreflightSleep(bool deepSleep)
 {
-    if (preflightSleep.notifyObservers(NULL) != 0)
+    // Observers only get a void*: non-NULL means the hardware (radio) is about to be powered
+    // down (deep sleep / shutdown), NULL means a light sleep where the radio keeps running
+    static const bool deepSleepFlag = true;
+    if (preflightSleep.notifyObservers(deepSleep ? (void *)&deepSleepFlag : NULL) != 0)
         return false; // vetoed
     else
         return true;
 }
 
 /// Tell devices we are going to sleep and wait for them to handle things
-static void waitEnterSleep(bool skipPreflight = false)
+static void waitEnterSleep(bool skipPreflight, bool deepSleep)
 {
     if (!skipPreflight) {
         uint32_t now = millis();
-        while (!doPreflightSleep()) {
+        while (!doPreflightSleep(deepSleep)) {
             delay(100); // Kinda yucky - wait until radio says say we can shutdown (finished in process sends/receives)
 
             if (!Throttle::isWithinTimespanMs(now,
@@ -230,7 +233,7 @@ void doDeepSleep(uint32_t msecToWake, bool skipPreflight = false, bool skipSaveN
 
     // not using wifi yet, but once we are this is needed to shutoff the radio hw
     // esp_wifi_stop();
-    waitEnterSleep(skipPreflight);
+    waitEnterSleep(skipPreflight, true);
 
 #if defined(ARCH_ESP32) && !MESHTASTIC_EXCLUDE_BLUETOOTH
     // Full shutdown of bluetooth hardware
@@ -410,7 +413,7 @@ esp_sleep_wakeup_cause_t doLightSleep(uint64_t sleepMsec) // FIXME, use a more r
     return ESP_SLEEP_WAKEUP_TIMER;
 #endif
 
-    waitEnterSleep(false);
+    waitEnterSleep(false, false);
     notifyLightSleep.notifyObservers(NULL); // Button interrupts are detached here
 
     uint64_t sleepUsec = sleepMsec * 1000LL;

src/sleep.h

@@ -23,8 +23,18 @@ void initDeepSleep();
 
 void setCPUFast(bool on);
 
-/** return true if sleep is allowed right now */
+/** return true if sleep is allowed right now
-bool doPreflightSleep();
+ * @param deepSleep true when the hardware (radio) is about to be powered down (deep sleep or
+ * shutdown), false for a light sleep where the radio keeps running. Observers may veto more
+ * aggressively for deep sleep, e.g. while a LoRa transmission is still in flight.
+ */
+bool doPreflightSleep(bool deepSleep = false);
+
+/// When a power-saving module wants to deep sleep but doPreflightSleep() vetoes it (e.g. the
+/// radio is still transmitting), re-check this often, and give up waiting after this many
+/// attempts so a busy mesh can't keep the node awake forever
+static constexpr uint32_t PREFLIGHT_SLEEP_RETRY_MS = 1000;
+static constexpr uint32_t MAX_PREFLIGHT_SLEEP_DEFERRALS = 30;
 
 extern int bootCount;