Advance successful Bluetooth cache recovery without retry delays

docs/test-results/esp32_ble_radio2_sleep_2026-10-21.md

@@ -16,14 +16,19 @@ the main loop. Bluetooth on rebuilds the service without releasing controller
 memory permanently or clearing successful bonds. Address, name, PIN and saved
 stealth policy remain intact. Pending or failed teardown prevents CPU sleep.
 The Bluedroid characteristics have deterministic TX/RX registration order;
-heap fragmentation must not change a paired client's cached handles.
+heap fragmentation must not change a paired client's cached handles. On SDKs
+using automatic Service Changed handling, a small asynchronous service change
+requests client rediscovery after authentication. A local SDK completion is
+not treated as proof that the client refreshed its cache. Only actual use of
+the current notification and receive handles permits skipping this request on
+a later connection from the same peer within that host session.
 
 Companion, Repeater, Room Server and Sensor can idle during an eligible
 radio2 visit. The decision requires a settled, validated receive profile,
 working radio GPIO wake, no pending reception and physically stopped wireless
 drivers. An absolute scanner deadline is checked again at sleep entry. The
-sleep slice is at most 10 ms, ends at least 4 ms before the visit deadline and
-requires at least 2 ms of useful time. Calibration, repair, ownership, queue,
+timer budget is at most 10 ms, reserves a 4 ms early-wake scheduling guard and
+requires at least 2 ms remaining. Calibration, repair, ownership, queue,
 network, USB and role deadlines retain their existing guards. The receiver
 stays on. This does not enable sleep through an active Bluetooth/WiFi link.
 
@@ -36,14 +41,22 @@ exercise actual production code with ASan/UBSan, ownership differences,
 partial initialization/teardown failures and repeated off/on cycles. Existing
 nRF52 event/profile tests also pass; nRF52 hardware was not touched.
 
-Full V4.3 FEM-off Companion, V3 Companion, V4 Repeater, Room and Sensor builds
+The initial sleep/teardown implementation, before the cache fix, has Full
+V4.3 FEM-off Companion, V3 Companion, V4 Repeater, Room and Sensor builds that
 pass their capability and memory gates. ESP32-C6 BLE (Arduino 3.1.3), the
 NimBLE-Arduino V4 trial and RC32 Full (Arduino 3.3.11) also compile. RC32
 exposed SDK service ownership and array-deletion defects; a version/hash-bound
 build-local repair fixes those sources without editing a shared SDK install.
 
+The cache fix is published in
+[`1087643ae`](https://github.com/mikecarper/MeshCore/commit/1087643ae867b9a8746f00b3ff43d574b59e2457).
+Its V4.3 FEM-off Full and RC32 Full builds pass all 24 capability markers and
+their application size gates: 2,551,592 and 2,152,840 bytes respectively, each
+within a 6,553,600-byte application slot. The other earlier builds do not
+constitute a full build matrix of this later source revision.
+
 Classic Heltec V2 BLE remains below its required 8,192-byte internal RAM
-reserve. The baseline has 2,552 bytes free and the candidate has 2,432 bytes
+reserve. The baseline has 2,552 bytes free and the initial candidate has 2,432 bytes
 free, a 120-byte regression against an existing failure. Removing an
 unnecessary WiFi-driver reference recovered 1,208 bytes. The gate was retained;
 this target is not reported as passing.
@@ -75,9 +88,14 @@ as proof that firmware handles remain stable or an existing cache migrates.
 Encrypted nonce tests on both frequencies have not yet passed. Earlier
 six-packet attempts completed physical transmissions but did not deliver all
 expected nonces. An awake control then stopped before transmitting when the
-peer rejected a TX-power setting. These failures remain separate from the
-successful SDK wait window; that window does not qualify end-to-end radio2
-delivery. The peer is an ESP32 XIAO S3 WIO, independently identified over USB.
+peer rejected a TX-power setting. A separate control with bounded configuration
+admission completed both physical transmissions at verified 2 dBm, but received
+zero matching nonces and zero direct packets. V4 profile RX counters advanced
+by 22 on the primary and zero on the secondary. USB remained active with zero
+SDK sleep calls: CPU sleep alone does not explain the RF failure. These
+failures remain separate from the successful SDK wait window; that window
+does not qualify end-to-end radio2 delivery. The peer is an ESP32 XIAO S3 WIO,
+independently identified over USB. No failed packet was resent automatically.
 
 Private artifacts, receipts and traces are retained under
 `/home/mesh/hwtest/esp32-ble-radio2-sleep-cd4ea053-20261021/`.

src/helpers/esp32/SerialBLEInterface.cpp

@@ -180,6 +180,7 @@ void SerialBLEInterface::serviceGattCacheRefresh(uint32_t now) {
       }
     } else {
       ++_cacheFailures;
+      _cacheLastAttempt = now; // Back off known failures, not successful progress.
       if (event == CacheOperation::Create && _cacheEventHandle == UINT16_MAX)
         _cacheStalled = true;
     }
@@ -208,9 +209,10 @@ void SerialBLEInterface::serviceGattCacheRefresh(uint32_t now) {
     _cacheLastAttempt = now;
     // A stale cached handle can fail before its security permissions are
     // consulted. Request the same existing MITM security independently of NUS.
-    if (esp_ble_set_encryption(remote, ESP_BLE_SEC_ENCRYPT_MITM) == ESP_OK)
+    if (esp_ble_set_encryption(remote, ESP_BLE_SEC_ENCRYPT_MITM) == ESP_OK) {
       _cacheEncryptedConnection = connection;
-    else ++_cacheFailures;
+      _cacheLastAttempt = now - BLE_POWER_RETRY_MS;
+    } else ++_cacheFailures;
     return;
   }
   if (!_cacheAuthenticated.load(std::memory_order_acquire)) return;
@@ -241,6 +243,9 @@ void SerialBLEInterface::serviceGattCacheRefresh(uint32_t now) {
   if (result != ESP_OK) {
     _cacheOperation.store(CacheOperation::None, std::memory_order_release);
     ++_cacheFailures;
+  } else {
+    // Completion events serialize the successful phases; no timer is needed.
+    _cacheLastAttempt = now - BLE_POWER_RETRY_MS;
   }
 }
 #endif

test/fixtures/esp32_ble_power/test_bluedroid_power.cpp

@@ -171,7 +171,9 @@ static void cache_async_migration_and_real_nus_proof() {
   rx->callbacks->onWrite(rx,&stale_write); tick(a); // Old CCCD2D is now RX, actual TX remains off.
   disconnect_cache(); connect_cache(a); auth_cache(); tick(a);
   assert(cache_deletes==1); // Local START was not proof that this peer repaired its cache.
-  changed_cache(false,1); tick(a); assert(cache_deletes==2); // Known failure retry.
+  changed_cache(false,1); a.servicePowerState(); assert(cache_deletes==1);
+  test_millis+=999; a.servicePowerState(); assert(cache_deletes==1);
+  ++test_millis; a.servicePowerState(); assert(cache_deletes==2); // Known failure retry.
   changed_cache(false); tick(a);
   verify_nus(a);
   disconnect_cache(); connect_cache(a); auth_cache(); tick(a);
@@ -209,6 +211,40 @@ static void cache_disconnect_pending_timeout_and_teardown() {
   }
   ++suites;
 }
+static void cache_success_progresses_without_timer_delay() {
+  reset_cache_stats();
+  SerialBLEInterface a; assert(a.begin("MeshCore-","legacy",246810,custom)); a.enable();
+  connect_cache(a); const uint32_t connected_at=test_millis;
+  assert(encryptions==1 && cache_creates==0);
+  auth_cache(); a.servicePowerState(); assert(cache_creates==1);
+  created_cache(); a.servicePowerState(); assert(cache_starts==1);
+  changed_cache(true); a.servicePowerState();
+  assert(test_millis==connected_at); // No artificial wait between successful phases.
+  disconnect_cache(); stopped(a); retire_global();
+  BLEDevice::setCustomGattsHandler(nullptr);
+
+  for(const char* fault : {"encrypt","cache-create","cache-start"}) {
+    reset_cache_stats();
+    SerialBLEInterface b; assert(b.begin("MeshCore-","legacy",246810,custom)); b.enable();
+    if(std::string(fault)=="encrypt") failure=fault;
+    connect_cache(b);
+    if(std::string(fault)!="encrypt") {
+      auth_cache();
+      if(std::string(fault)=="cache-create") failure=fault;
+      b.servicePowerState();
+      if(std::string(fault)=="cache-start") {
+        created_cache(); failure=fault; b.servicePowerState();
+      }
+    }
+    const unsigned attempts=encryptions+cache_creates+cache_starts;
+    b.servicePowerState(); assert(encryptions+cache_creates+cache_starts==attempts);
+    test_millis+=999; b.servicePowerState(); assert(encryptions+cache_creates+cache_starts==attempts);
+    ++test_millis; b.servicePowerState(); assert(encryptions+cache_creates+cache_starts==attempts+1);
+    failure.clear(); disconnect_cache(); stopped(b); retire_global();
+    BLEDevice::setCustomGattsHandler(nullptr);
+  }
+  ++suites;
+}
 static void cache_api_and_async_failures_are_bounded() {
   for(const char* fault : {"encrypt","cache-create","async-create","malformed-create","cache-start"}) {
     reset_cache_stats();
@@ -217,7 +253,9 @@ static void cache_api_and_async_failures_are_bounded() {
     connect_cache(a); auth_cache();
     if(std::string(fault)=="cache-create") failure=fault;
     tick(a);
-    if(std::string(fault)=="async-create") { created_cache(1); tick(a); created_cache(1); tick(a); created_cache(1); }
+    if(std::string(fault)=="async-create") {
+      for(unsigned i=0;i<3;++i) { created_cache(1); a.servicePowerState(); tick(a); }
+    }
     if(std::string(fault)=="malformed-create") {
       esp_ble_gatts_cb_param_t param;
       memcpy(param.add_attr_tab.svc_uuid.uuid.uuid128,marker_attributes->att_desc.value,16);
@@ -240,6 +278,7 @@ int main() {
   cache_async_migration_and_real_nus_proof();
   cache_disconnect_pending_timeout_and_teardown();
   cache_api_and_async_failures_are_bounded();
+  cache_success_progresses_without_timer_delay();
 #endif
   pointer_map_reproduces_cached_cccd_failure();
   repeated_cycles(); partial_stop_failures_and_late_callbacks(); startup_failures();