Fix USB logging ownership, persistence, and reconnect safety

src/helpers/CommonCLI.cpp

@@ -3389,9 +3389,15 @@ void CommonCLI::handleSetCmd(uint32_t sender_timestamp, char* command, char* rep
     while (*value == ' ' || *value == '\t') value++;
     bool enabled = false, reboot_if_needed = false;
     if (mesh::cli::parseLoggingToggle(value, enabled, reboot_if_needed)) {
+      const uint8_t previous = _prefs->usb_logging_enabled;
       _prefs->usb_logging_enabled = enabled ? 1 : 0;
+      if (!trySavePrefs()) {
+        _prefs->usb_logging_enabled = previous;
+        strcpy(reply, "Error: USB logging not saved; unchanged");
+        return;
+      }
+      // Commit before changing the stream's live protocol ownership.
       mesh::setUsbLoggingEnabled(enabled);
-      savePrefs();
       snprintf(reply, 160, "OK - USB logging %s (saved)", enabled ? "on" : "off");
     } else {
       strcpy(reply, "Error: usage set usb.logging on|off");
@@ -3410,11 +3416,21 @@ void CommonCLI::handleSetCmd(uint32_t sender_timestamp, char* command, char* rep
       strcpy(reply, "Error: usage set logging.output off|usb|wifi|both");
       return;
     }
+    const uint8_t previous_usb = _prefs->usb_logging_enabled;
+    const uint8_t previous_bridge = _prefs->bridge_enabled;
     _prefs->usb_logging_enabled = usb_enabled ? 1 : 0;
     _prefs->bridge_enabled = wifi_enabled ? 1 : 0;
+    if (!trySavePrefs()) {
+      _prefs->usb_logging_enabled = previous_usb;
+      _prefs->bridge_enabled = previous_bridge;
+      strcpy(reply, "Error: logging output not saved; unchanged");
+      return;
+    }
     mesh::setUsbLoggingEnabled(usb_enabled);
-    _callbacks->setMqttBridgeState(wifi_enabled);
-    savePrefs();
+    if (!_callbacks->setMqttBridgeState(wifi_enabled)) {
+      strcpy(reply, "Error: logging output saved, but MQTT runtime change failed");
+      return;
+    }
     snprintf(reply, 160, "OK - logging.output %s (saved)", value);
     return;
   }

src/helpers/NetworkLink.cpp

@@ -3,6 +3,7 @@
 #if defined(ESP_PLATFORM)
 
 #include "MQTTConnectionPolicy.h"
+#include "UsbLogging.h"
 #include "WifiPowerSavePolicy.h"
 
 #include <atomic>
@@ -25,8 +26,8 @@ extern void tcpipInit();
 #endif
 
 // Same "MQTT: " prefix as MQTT_DEBUG_PRINTLN so existing log greps keep matching.
-#if defined(MQTT_DEBUG)
-  #define NETWORK_DEBUG_PRINTLN(F, ...) do { if (Serial.availableForWrite() > 0) { Serial.printf("MQTT: " F "\n", ##__VA_ARGS__); } } while (0)
+#if defined(MQTT_DEBUG) && MQTT_DEBUG
+  #define NETWORK_DEBUG_PRINTLN(F, ...) do { if (mesh::isUsbLoggingEnabled() && mesh::usbLoggingPort().availableForWrite() > 0) { mesh::usbLoggingPort().printf("MQTT: " F "\n", ##__VA_ARGS__); } } while (0)
 #else
   #define NETWORK_DEBUG_PRINTLN(...) do {} while (0)
 #endif

src/helpers/UsbAsciiBinarySwitch.h

@@ -333,6 +333,7 @@ public:
 // must not be displaced just because USB logging is enabled.
 enum class UsbLoggingTerminalAction : uint8_t {
   NO_ACTION,
+  PARK_USB_FOR_NETWORK,
   CLAIM_USB,
   RETURN_TO_BINARY,
   KEEP_ASCII,
@@ -342,9 +343,15 @@ inline UsbLoggingTerminalAction selectUsbLoggingTerminalAction(
     bool has_dedicated_logging_port, bool logging_enabled,
     bool usb_terminal_active, bool usb_logging_terminal_active,
     bool full_companion, bool network_terminal_active) {
-  if (has_dedicated_logging_port || network_terminal_active) {
+  if (has_dedicated_logging_port) {
     return UsbLoggingTerminalAction::NO_ACTION;
   }
+  if (network_terminal_active) {
+    // Keep the network CLI owner, but never leave framed USB traffic enabled
+    // on the same CDC stream receiving ASCII diagnostics.
+    return logging_enabled ? UsbLoggingTerminalAction::PARK_USB_FOR_NETWORK
+                           : UsbLoggingTerminalAction::NO_ACTION;
+  }
   if (logging_enabled) {
     return UsbLoggingTerminalAction::CLAIM_USB;
   }

src/helpers/UsbLogging.cpp

@@ -25,6 +25,9 @@
     (defined(ENABLE_USB_INTERFACE) || defined(OTA_FOLDER_SERIAL))
   #define MESH_NRF52_PRIMARY_USB_NONBLOCKING 1
   #include <Adafruit_TinyUSB.h>
+  // Build-local CDC query installed by scripts/nrf52_usb_power_fix.py. It does
+  // not clear/cancel an endpoint or change its USB bulk data-toggle state.
+  extern "C" bool mesh_tud_cdc_n_tx_pending(uint8_t instance);
   #if !defined(CFG_TUD_CDC) || CFG_TUD_CDC < 1
     #error "nRF52 USB Companion/mOTA requires CFG_TUD_CDC >= 1"
   #endif
@@ -437,6 +440,43 @@ static std::atomic<bool> primary_usb_line_state_dtr{false};
 static std::atomic<uint32_t> primary_usb_rx_generation{UINT32_MAX};
 static constexpr uint32_t primary_usb_session_settle_millis = 8;
 static std::atomic<uint32_t> primary_usb_reset_settle_until{0};
+static std::atomic<bool> nrf52_usb_reenumeration_pending{false};
+static std::atomic<uint32_t> nrf52_usb_reattach_after{0};
+static constexpr uint32_t nrf52_usb_detach_millis = 20;
+
+static void requestNrf52UsbSessionReenumeration() {
+  // Only an armed old-session packet needs this recovery. TinyUSB has no safe
+  // nRF52 per-endpoint abort API; FIFO clears cannot retract endpoint RAM. A
+  // physical detach guarantees that packet cannot enter a reopened handle,
+  // and the host's fresh enumeration resets endpoint/data-toggle state. Both
+  // CDC ports briefly re-enumerate whenever a close finds a pending transfer,
+  // including an unread packet or the stack's trailing zero-length packet.
+  if (nrf52_usb_reenumeration_pending.exchange(true,
+                                               std::memory_order_acq_rel)) return;
+  primary_usb_line_state_dtr.store(false, std::memory_order_release);
+  primary_usb_reset_generation.fetch_add(1, std::memory_order_acq_rel);
+  nrf52_usb_reattach_after.store(millis() + nrf52_usb_detach_millis,
+                                std::memory_order_release);
+  TinyUSBDevice.detach();
+}
+
+static void clearNrf52UsbTxForSession(uint8_t instance) {
+  (void)tud_cdc_n_write_clear(instance);
+  if (mesh_tud_cdc_n_tx_pending(instance)) {
+    requestNrf52UsbSessionReenumeration();
+  }
+}
+
+static void serviceNrf52UsbSessionReenumeration() {
+  if (!nrf52_usb_reenumeration_pending.load(std::memory_order_acquire)
+      || (int32_t)(millis() - nrf52_usb_reattach_after.load(
+                       std::memory_order_acquire)) < 0
+      || tud_mounted()) return;
+  // Waiting for unmount as well as the quiet interval ensures TinyUSB's owner
+  // has consumed the unplug event. Never reattach with its old class state.
+  TinyUSBDevice.attach();
+  nrf52_usb_reenumeration_pending.store(false, std::memory_order_release);
+}
 
 static uint32_t primaryUsbSessionGeneration() {
   return primary_usb_reset_generation.load(std::memory_order_acquire);
@@ -444,7 +484,8 @@ static uint32_t primaryUsbSessionGeneration() {
 
 static bool canAccessPrimaryUsbSession(void*) {
   const uint32_t generation = primaryUsbSessionGeneration();
-  if (!tud_mounted()
+  if (nrf52_usb_reenumeration_pending.load(std::memory_order_acquire)
+      || !tud_mounted()
       || primary_usb_allowed_generation.load(std::memory_order_acquire)
           != generation) return false;
 
@@ -469,9 +510,9 @@ static void endPrimaryUsbHostSession(bool clear_cdc_fifos) {
       && !(clear_cdc_fifos && tud_cdc_n_available(0) != 0)) return;
 
   // Publish a short quiescence deadline before closing the generation gate.
-  // TinyUSB's TX clear does not cancel an endpoint transfer already in its
-  // class buffer, so the later final TX purge catches a racing old-session
-  // write. RX is purged synchronously below; bytes sent by a reopened host
+  // FIFO-only cleanup suffices when no old IN packet is armed; otherwise
+  // quarantine and physically re-enumerate rather than leaking that packet.
+  // RX is purged synchronously below; bytes sent by a reopened host
   // during the settle interval remain queued until the gate reopens.
   primary_usb_reset_settle_until.store(
       millis() + primary_usb_session_settle_millis,
@@ -481,7 +522,7 @@ static void endPrimaryUsbHostSession(bool clear_cdc_fifos) {
     // The line-state callback runs before TinyUSB resets the device. A device
     // unmount/remount boundary has already reset these class FIFOs.
     tud_cdc_n_read_flush(0);
-    (void)tud_cdc_n_write_clear(0);
+    clearNrf52UsbTxForSession(0);
   }
 }
 #endif
@@ -498,6 +539,7 @@ static size_t writeTinyUsbCdcOnce(void* context, const uint8_t* data,
     return 0;
   }
 #if defined(ENABLE_USB_INTERFACE)
+  if (nrf52_usb_reenumeration_pending.load(std::memory_order_acquire)) return 0;
   if (instance == 0) {
     if (!canAccessPrimaryUsbSession(nullptr)) return 0;
   } else
@@ -641,7 +683,7 @@ static void restartDedicatedUsbLoggingHostSession() {
   // identity marker after a rapid reopen.
   dedicated_usb_logging_port_connected.store(false,
                                                std::memory_order_release);
-  (void)tud_cdc_n_write_clear(1);
+  clearNrf52UsbTxForSession(1);
   resetDedicatedUsbLoggingUsbTaskState();
   dedicated_usb_logging_quiet_sofs =
       dedicated_usb_logging_host_settle_sofs;
@@ -682,6 +724,12 @@ static void handleDedicatedUsbLoggingLineCoding() {
 // 1 kHz also catches a close/reopen that occurs entirely between main-loop
 // service calls.
 void serviceDedicatedUsbLoggingFromUsbTask() {
+  if (nrf52_usb_reenumeration_pending.load(std::memory_order_acquire)) {
+    dedicated_usb_logging_port_connected.store(false,
+                                               std::memory_order_release);
+    resetDedicatedUsbLoggingUsbTaskState();
+    return;
+  }
   const uint32_t reset_generation =
       dedicated_usb_logging_reset_generation.load(std::memory_order_acquire);
   if (reset_generation != dedicated_usb_logging_seen_reset_generation) {
@@ -708,9 +756,9 @@ void serviceDedicatedUsbLoggingFromUsbTask() {
   if (dedicated_usb_logging_quiet_sofs > 0) {
     dedicated_usb_logging_port_connected.store(
         false, std::memory_order_release);
-    // Drop anything already in flight from the prior session and anything a
-    // producer raced into the owner queue before the callback gated it.
-    (void)tud_cdc_n_write_clear(1);
+    // Drop racing producer bytes. An armed old IN packet requires a physical
+    // detach, not another FIFO clear or an arbitrary number of quiet SOFs.
+    clearNrf52UsbTxForSession(1);
     resetDedicatedUsbLoggingUsbTaskState();
     --dedicated_usb_logging_quiet_sofs;
     return;
@@ -851,23 +899,24 @@ void beginUsbLoggingPort() {
     return;
   }
 
+  // The core already started USB before setup. A host can have fetched the
+  // old descriptor even while mounted() is false. Detach BEFORE mutating the
+  // live configuration buffer, allow the owner to consume the unplug event,
+  // then always enumerate the complete descriptor (not just mounted hosts).
+  TinyUSBDevice.detach();
+  delay(10);
   dedicated_usb_logging_port.begin(115200);
   dedicated_usb_logging_port_configured = true;
   dedicated_usb_logging_port_started = true;
 
-  // The nRF52 core starts TinyUSB before setup(). If the host completed
-  // enumeration in that small window, reconnect once so it reads the expanded
-  // two-CDC descriptor. Usually enumeration has not completed and no reconnect
-  // is needed.
-  if (TinyUSBDevice.mounted()) {
-    TinyUSBDevice.detach();
-    delay(10);
-    TinyUSBDevice.attach();
-  }
+  TinyUSBDevice.attach();
 #endif
 }
 
 void serviceUsbLoggingPort() {
+#if defined(NRF52_PLATFORM) && defined(ENABLE_USB_INTERFACE)
+  serviceNrf52UsbSessionReenumeration();
+#endif
 #if MESH_ESP32_TINYUSB_NONBLOCKING
   serviceEsp32TinyUsbPorts();
 #elif MESH_ESP32_HWCDC_SESSION_GUARD
@@ -1214,7 +1263,7 @@ static void completePrimaryUsbSessionReset(void*) {
   // the close/line-coding boundary was captured. Do not purge it again here:
   // hosts such as meshcli send APP_START immediately after opening the port,
   // while this generation gate is deliberately settling.
-  (void)tud_cdc_n_write_clear(0);
+  clearNrf52UsbTxForSession(0);
   const uint32_t cleaned_generation =
       primary_usb_terminal_taken_reset_generation;
   primary_usb_allowed_generation.store(cleaned_generation,
@@ -1228,11 +1277,15 @@ bool tryCompleteUsbTerminalSessionReset() {
   return esp32_tinyusb_clean_generation.load(std::memory_order_acquire)
       == esp32_tinyusb_reset_generation.load(std::memory_order_acquire);
 #elif defined(NRF52_PLATFORM) && defined(ENABLE_USB_INTERFACE)
+  serviceNrf52UsbSessionReenumeration();
+  if (nrf52_usb_reenumeration_pending.load(std::memory_order_acquire)) return false;
   const uint32_t settle_until =
       primary_usb_reset_settle_until.load(std::memory_order_acquire);
   if ((int32_t)(millis() - settle_until) < 0) return false;
-  return nonblocking_primary_usb_companion_port.tryRunExclusive(
+  const bool completed = nonblocking_primary_usb_companion_port.tryRunExclusive(
       completePrimaryUsbSessionReset);
+  return completed
+      && !nrf52_usb_reenumeration_pending.load(std::memory_order_acquire);
 #elif MESH_ESP32_HWCDC_SESSION_GUARD
   if (!esp32_hwcdc_cleanup_pending
       && esp32_hwcdc_allowed_generation.load(std::memory_order_acquire)

src/helpers/nrf52/EthernetCLI.h

@@ -6,6 +6,16 @@
 #include <SPI.h>
 #include <RAK13800_W5100S.h>
 #include <helpers/nrf52/EthernetMac.h>
+#include <helpers/UsbLogging.h>
+
+// Ethernet startup runs on a FreeRTOS task, and client acceptance runs in the
+// mesh loop. Never let either path wait on a CDC host which stopped reading.
+// Keep diagnostics separate from functional replies on the Ethernet client.
+#define ETHERNET_CLI_LOG(F, ...) do { \
+  if (mesh::isUsbLoggingEnabled() && mesh::usbLoggingPort().availableForWrite() > 0) { \
+    mesh::usbLoggingPort().printf("ETH: " F "\n", ##__VA_ARGS__); \
+  } \
+} while (0)
 
 #define PIN_SPI1_MISO (29)
 #define PIN_SPI1_MOSI (30)
@@ -41,7 +51,7 @@ static bool ethernet_take_session_reset() {
 static void ethernet_task(void* param) {
   (void)param;
 
-  Serial.println("ETH: Initializing hardware");
+  ETHERNET_CLI_LOG("Initializing hardware");
   // WB_IO2 (power enable) is already driven HIGH by early constructor
   // in RAK4631Board.cpp to support POE boot.
   // Skip hardware reset - the W5100S comes out of power-on reset cleanly,
@@ -54,30 +64,30 @@ static void ethernet_task(void* param) {
 
   uint8_t mac[6];
   generateEthernetMac(mac);
-  Serial.printf("ETH: MAC: %02X:%02X:%02X:%02X:%02X:%02X\n",
+  ETHERNET_CLI_LOG("MAC: %02X:%02X:%02X:%02X:%02X:%02X",
       mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]);
 
   // Retry loop: keep trying until we get an IP
   while (!ethernet_running) {
-    Serial.println("ETH: Attempting DHCP...");
+    ETHERNET_CLI_LOG("Attempting DHCP...");
     if (Ethernet.begin(mac, 10000, 2000) == 0) {
       if (Ethernet.hardwareStatus() == EthernetNoHardware) {
-        Serial.println("ETH: Hardware not found, giving up");
+        ETHERNET_CLI_LOG("Hardware not found, giving up");
         vTaskDelete(NULL);
         return;
       }
       if (Ethernet.linkStatus() == LinkOFF) {
-        Serial.println("ETH: Cable not connected, will retry");
+        ETHERNET_CLI_LOG("Cable not connected, will retry");
       } else {
-        Serial.println("ETH: DHCP failed, will retry");
+        ETHERNET_CLI_LOG("DHCP failed, will retry");
       }
       vTaskDelay(pdMS_TO_TICKS(ETHERNET_RETRY_INTERVAL_MS));
       continue;
     }
 
     IPAddress ip = Ethernet.localIP();
-    Serial.printf("ETH: IP: %u.%u.%u.%u\n", ip[0], ip[1], ip[2], ip[3]);
-    Serial.printf("ETH: Listening on TCP port %d\n", ETHERNET_TCP_PORT);
+    ETHERNET_CLI_LOG("IP: %u.%u.%u.%u", ip[0], ip[1], ip[2], ip[3]);
+    ETHERNET_CLI_LOG("Listening on TCP port %d", ETHERNET_TCP_PORT);
     ethernet_server.begin();
     ethernet_running = true;
   }
@@ -115,7 +125,7 @@ static void ethernet_check_client() {
     ethernet_client = newClient;
     ethernet_session_reset = true;
     IPAddress ip = ethernet_client.remoteIP();
-    Serial.printf("ETH: Client connected from %u.%u.%u.%u\n", ip[0], ip[1], ip[2], ip[3]);
+    ETHERNET_CLI_LOG("Client connected from %u.%u.%u.%u", ip[0], ip[1], ip[2], ip[3]);
     ethernet_client.println(ETHERNET_CLI_BANNER);
   }
 }
@@ -161,4 +171,6 @@ static void ethernet_send_reply(const char* reply) {
   }
 }
 
+#undef ETHERNET_CLI_LOG
+
 #endif // ETHERNET_ENABLED