From 05679aa74116ebf990c19c5775fdf967b44a147f Mon Sep 17 00:00:00 2001 From: mikecarper Date: Tue, 27 Oct 2026 18:47:05 -0700 Subject: [PATCH] Add a saved override to keep USB packet logging continuous --- docs/cli_command_availability.md | 2 + docs/cli_commands.md | 16 ++- docs/usb_logging_watchdog.md | 2 + examples/companion_radio/CompanionHelp.inc | 3 + examples/companion_radio/DataStore.cpp | 14 ++- examples/companion_radio/MyMesh.cpp | 26 +++++ examples/companion_radio/MyMesh.h | 10 +- examples/companion_radio/NodePrefs.h | 44 +++++-- examples/companion_radio/PrefsStorageLayout.h | 3 +- src/helpers/CommonCLI.cpp | 45 +++++++- src/helpers/CommonCLI.h | 3 + src/helpers/UsbLogging.cpp | 15 ++- src/helpers/UsbLogging.h | 7 ++ test/test_common_usb_debug.py | 108 +++++++++++++++++- test/test_companion_packet_stream.py | 3 +- test/test_companion_prefs_image.py | 24 ++-- test/test_companion_usb_logging.py | 66 ++++++++++- test/test_usb_packet_logging_quiet.py | 30 ++++- 18 files changed, 382 insertions(+), 39 deletions(-) diff --git a/docs/cli_command_availability.md b/docs/cli_command_availability.md index ec7587b5d..1333d4d9f 100644 --- a/docs/cli_command_availability.md +++ b/docs/cli_command_availability.md @@ -56,6 +56,8 @@ current source. Where `usb.logging` is available, `get/set usb.debug on|off` selects debug intent without changing packet capture or adding a build variant. Debug defaults off for fresh and older preference images; effective output requires `usb.logging` and `usb.debug` on plus compiled diagnostic support. +Shared USB consoles also provide saved `get/set usb.logging.always on|off`. +It defaults off; turning it on keeps packet logs running through commands. See [live USB logging](cli_commands.md#control-live-usb-logging) for transport restrictions and Full Companion RAW output. diff --git a/docs/cli_commands.md b/docs/cli_commands.md index a1a154caf..6094581f3 100644 --- a/docs/cli_commands.md +++ b/docs/cli_commands.md @@ -1644,6 +1644,9 @@ set usb.logging on set usb.logging off set usb.logging on reboot set usb.logging off reboot +get usb.logging.always +set usb.logging.always on +set usb.logging.always off get usb.debug set usb.debug on set usb.debug off @@ -1701,18 +1704,29 @@ still reports that saved setting. `set usb.logging on` or `set logging.output usb|both` resumes packet logs immediately after a successful save. No reboot is needed. +To keep packet logs running through commands on a shared USB console, use +`set usb.logging.always on`. This choice is saved, ends any active pause +immediately, and survives reboot. `get usb.logging.always` checks the setting. +`set usb.logging.always off` restores the default five-minute pause for +subsequent commands. The logging master remains separate: this option does +not enable logging while `usb.logging` is off. With continuous logging, +packet lines can appear between command replies. + The routine `stats-core`, `stats-radio`, and `stats-packets` polls do not start or extend this pause. A separate logging USB port and explicit Companion `usb.logging stream` mode also keep logging. The pause leaves command replies, noise-floor sampling, saved history, LoRa telemetry, and direct WiFi MQTT running. A collector reading USB packet logs misses those log copies during the pause, including telemetry packets; this is not buffered capture. +The `usb.logging.always` setting is provided for shared consoles; nRF52 Full +Companion already keeps its dedicated logging port or explicit stream running. `meshcoretomqtt` polls these three stats commands every 300 seconds and publishes `noise_floor` from the `stats-radio` reply in its MQTT status. These polls keep working during the pause. Its startup identity queries do trigger a five-minute packet-capture gap on a shared console, as do ordinary commands -sent through its remote serial feature. +sent through its remote serial feature. Enable `usb.logging.always` to keep +packet capture running through these commands too. For packet-only capture, use these separate text commands: diff --git a/docs/usb_logging_watchdog.md b/docs/usb_logging_watchdog.md index e6449ffad..627c87fd1 100644 --- a/docs/usb_logging_watchdog.md +++ b/docs/usb_logging_watchdog.md @@ -50,6 +50,8 @@ Interactive text commands on a shared USB console pause packet logs for five minutes after the last command. The three routine stats polls above keep their replies and renew the lease without starting or extending this pause. Dedicated logging ports and explicit Companion stream mode keep logging. +On shared consoles, saved `set usb.logging.always on` also keeps packet logs +running through commands; `off` restores pausing for subsequent commands. The pause does not disable measurements, LoRa telemetry, direct WiFi MQTT, or the saved logging master. USB packet collectors miss log copies during the pause. See [live USB logging](cli_commands.md#control-live-usb-logging). diff --git a/examples/companion_radio/CompanionHelp.inc b/examples/companion_radio/CompanionHelp.inc index 2bac7b169..dc80a3230 100644 --- a/examples/companion_radio/CompanionHelp.inc +++ b/examples/companion_radio/CompanionHelp.inc @@ -150,6 +150,9 @@ MESH_COMPANION_HELP_BEGIN #if MESH_USB_LOGGING_AVAILABLE " get/set usb.logging [reboot]\r\n" " get/set usb.debug \r\n" +#if !defined(MESH_DUAL_CDC_LOGGING) + " get/set usb.logging.always \r\n" +#endif #if MESH_USB_CONSOLE_COOPERATIVE " get usb.watchdog.last\r\n" " get/set usb.watchdog (saved; default auto)\r\n" diff --git a/examples/companion_radio/DataStore.cpp b/examples/companion_radio/DataStore.cpp index cdcf3d8cd..4a13b96b1 100644 --- a/examples/companion_radio/DataStore.cpp +++ b/examples/companion_radio/DataStore.cpp @@ -1314,6 +1314,8 @@ bool DataStore::loadPrefsInt(const char *filename, if (success && file.read(static_cast(destination), field.length) != field.length) success = false; } + loaded_prefs.usb_logging_always = success + && pad[0] == CompanionNodePrefs::USB_LOGGING_ALWAYS_WIRE_ON; #else auto readField = [&file, &success](void* dest, size_t size) -> bool { if (!success @@ -1332,6 +1334,8 @@ bool DataStore::loadPrefsInt(const char *filename, readField(&loaded_prefs.airtime_factor, sizeof(float)); // 0 readField(loaded_prefs.node_name, sizeof(loaded_prefs.node_name)); // 4 readField(pad, 4); // 36 + loaded_prefs.usb_logging_always = success + && pad[0] == CompanionNodePrefs::USB_LOGGING_ALWAYS_WIRE_ON; readField(&loaded_lat, sizeof(loaded_lat)); // 40 readField(&loaded_lon, sizeof(loaded_lon)); // 48 readField(&loaded_prefs.freq, sizeof(loaded_prefs.freq)); // 56 @@ -1542,7 +1546,8 @@ bool DataStore::savePrefs(const CompanionNodePrefs& _prefs, double node_lat, dou #endif #if defined(STM32_PLATFORM) && defined(__GNUC__) using namespace mesh::companion_prefs; - const uint8_t pad[4] = {}; + const uint8_t pad[4] = {uint8_t(_prefs.usb_logging_always == 1 + ? CompanionNodePrefs::USB_LOGGING_ALWAYS_WIRE_ON : 0), 0, 0, 0}; size_t used = 0; for (const PrefField& field : PREF_FIELDS) { if (field.length > PREFS_PREFIX_SIZE - used) { @@ -1562,7 +1567,8 @@ bool DataStore::savePrefs(const CompanionNodePrefs& _prefs, double node_lat, dou // nRF52 retains streaming writes and its existing small stack footprint. // The table is the same validated wire order used by the scalar emitter. using namespace mesh::companion_prefs; - const uint8_t pad[4] = {}; + const uint8_t pad[4] = {uint8_t(_prefs.usb_logging_always == 1 + ? CompanionNodePrefs::USB_LOGGING_ALWAYS_WIRE_ON : 0), 0, 0, 0}; bool success = true; for (const PrefField& field : PREF_FIELDS) { if (!success) break; @@ -1595,6 +1601,8 @@ bool DataStore::savePrefs(const CompanionNodePrefs& _prefs, double node_lat, dou #endif uint8_t pad[8]; memset(pad, 0, sizeof(pad)); + pad[0] = _prefs.usb_logging_always == 1 + ? CompanionNodePrefs::USB_LOGGING_ALWAYS_WIRE_ON : 0; bool success = writeField((uint8_t *)&_prefs.airtime_factor, sizeof(float)); // 0 success = success && writeField((uint8_t *)_prefs.node_name, sizeof(_prefs.node_name)); // 4 @@ -1615,7 +1623,7 @@ bool DataStore::savePrefs(const CompanionNodePrefs& _prefs, double node_lat, dou success = success && writeField((uint8_t *)&_prefs.advert_loc_policy, sizeof(_prefs.advert_loc_policy)); // 76 success = success && writeField((uint8_t *)&_prefs.multi_acks, sizeof(_prefs.multi_acks)); // 77 success = success && writeField((uint8_t *)&_prefs.path_hash_mode, sizeof(_prefs.path_hash_mode)); // 78 - success = success && writeField(pad, 1); // 79 + success = success && writeField(pad + 1, 1); // 79 success = success && writeField((uint8_t *)&_prefs.ble_pin, sizeof(_prefs.ble_pin)); // 80 success = success && writeField((uint8_t *)&_prefs.buzzer_quiet, sizeof(_prefs.buzzer_quiet)); // 84 success = success && writeField((uint8_t *)&_prefs.gps_enabled, sizeof(_prefs.gps_enabled)); // 85 diff --git a/examples/companion_radio/MyMesh.cpp b/examples/companion_radio/MyMesh.cpp index 642922644..bbd3fab02 100644 --- a/examples/companion_radio/MyMesh.cpp +++ b/examples/companion_radio/MyMesh.cpp @@ -3360,6 +3360,7 @@ void MyMesh::begin(bool has_display, bool radio_available, _prefs.wifi_enabled = constrain(_prefs.wifi_enabled, 0, 1); _prefs.usb_logging_enabled = constrain(_prefs.usb_logging_enabled, 0, 2); _prefs.usb_debug_enabled = _prefs.usb_debug_enabled == 1 ? 1 : 0; + _prefs.usb_logging_always = _prefs.usb_logging_always == 1 ? 1 : 0; _prefs.cad_enabled = constrain(_prefs.cad_enabled, 0, 1); if (_prefs.cad_scan_timeout_ms != 0 && (_prefs.cad_scan_timeout_ms < mesh::CAD_SCAN_MIN_TIMEOUT_MS @@ -3383,6 +3384,9 @@ void MyMesh::begin(bool has_display, bool radio_available, const bool usb_logging_enabled = _prefs.usb_logging_enabled != 0; mesh::configureUsbLoggingPacketStream(_prefs.usb_logging_enabled == 2); mesh::setUsbDebugEnabled(_prefs.usb_debug_enabled != 0); +#if !defined(MESH_DUAL_CDC_LOGGING) + mesh::setUsbPacketLoggingAlways(_prefs.usb_logging_always != 0); +#endif applyUsbLoggingState(usb_logging_enabled); if (!mesh::saveUsbLoggingBootPreference(usb_logging_enabled)) { MESH_DEBUG_PRINTLN("Unable to save next-boot USB logging interface state"); @@ -4311,6 +4315,28 @@ bool MyMesh::handleLocalControlCommand(const char* command, char* reply, } #endif +#if MESH_USB_LOGGING_AVAILABLE && !defined(MESH_DUAL_CDC_LOGGING) + if (strcmp(command, "get usb.logging.always") == 0) { + snprintf(reply, reply_size, "usb.logging.always %s", + mesh::isUsbPacketLoggingAlways() ? "on" : "off"); + return true; + } + if (strncmp(command, "set usb.logging.always", 22) == 0 + && (command[22] == 0 || command[22] == ' ' || command[22] == '\t')) { + const char* value = command + 22; + while (*value == ' ' || *value == '\t') value++; + if (strcmp(value, "on") != 0 && strcmp(value, "off") != 0) { + mesh::cli::formatError(reply, reply_size, "use set usb.logging.always on|off"); + } else if (!savePreference(_prefs.usb_logging_always, + uint8_t(strcmp(value, "on") == 0))) { + mesh::cli::formatError(reply, reply_size, "USB logging policy could not be saved"); + } else { + snprintf(reply, reply_size, "OK - usb.logging.always %s (saved)", + _prefs.usb_logging_always ? "on" : "off"); + } + return true; + } +#endif #if MESH_USB_LOGGING_AVAILABLE if (strcmp(command, "get usb.debug") == 0) { snprintf(reply, reply_size, "usb.debug %s%s", diff --git a/examples/companion_radio/MyMesh.h b/examples/companion_radio/MyMesh.h index a15321283..c944d5b1b 100644 --- a/examples/companion_radio/MyMesh.h +++ b/examples/companion_radio/MyMesh.h @@ -610,17 +610,23 @@ public: bool getChannel(int channel_idx, ChannelDetails& channel); bool setChannel(int channel_idx, const ChannelDetails& channel); bool savePrefs() { - const uint8_t previous_usb_debug = _prefs.usb_debug_enabled; + const uint8_t previous_tail_flags[] = { + _prefs.usb_debug_enabled, _prefs.usb_logging_always}; _prefs.usb_debug_enabled = _prefs.usb_debug_enabled == 1 ? 1 : 0; + _prefs.usb_logging_always = _prefs.usb_logging_always == 1 ? 1 : 0; const bool saved = _store->savePrefs(_prefs, sensors.node_lat, sensors.node_lon); if (saved) { _prefs.clearDirty(); #if MESH_USB_LOGGING_AVAILABLE mesh::setUsbDebugEnabled(_prefs.usb_debug_enabled != 0); +#if !defined(MESH_DUAL_CDC_LOGGING) + mesh::setUsbPacketLoggingAlways(_prefs.usb_logging_always != 0); +#endif #endif } else { - _prefs.usb_debug_enabled = previous_usb_debug; + _prefs.usb_debug_enabled = previous_tail_flags[0]; + _prefs.usb_logging_always = previous_tail_flags[1]; } return saved; } diff --git a/examples/companion_radio/NodePrefs.h b/examples/companion_radio/NodePrefs.h index 060337f03..c58cbaea8 100644 --- a/examples/companion_radio/NodePrefs.h +++ b/examples/companion_radio/NodePrefs.h @@ -138,6 +138,9 @@ public: #endif uint8_t tx_media = mesh::RADIO_TX_AUTO; uint8_t tx_ssh = mesh::RADIO_TX_AUTO; + // Reserved wire byte 36; older writers stored zero here. + uint8_t usb_logging_always = 0; + static constexpr uint8_t USB_LOGGING_ALWAYS_WIRE_ON = 0xA1; private: class RadioPrefs : public CommonRadioPrefs { @@ -168,6 +171,9 @@ private: def("rxps_level", _parent->rx_ps_level); def("rxps_preamble", _parent->rx_ps_preamble); def("usb_debug", _parent->usb_debug_enabled); +#if !defined(MESH_DUAL_CDC_LOGGING) + def("usb_log_always", _parent->usb_logging_always); +#endif #ifdef TBEAM_1W def("fan", _parent->fan_mode, sizeof(_parent->fan_mode)); def("fan_lo", _parent->fan_lo); @@ -183,25 +189,41 @@ private: } bool getByKey(const char* key, char* value, size_t max_len) override { - if (key != nullptr && strcmp(key, "usb_debug") == 0) { + uint8_t* flag = &_parent->usb_debug_enabled; + bool handled = key != nullptr && strcmp(key, "usb_debug") == 0; +#if !defined(MESH_DUAL_CDC_LOGGING) + if (key != nullptr && strcmp(key, "usb_log_always") == 0) { + flag = &_parent->usb_logging_always; + handled = true; + } +#endif + if (handled) { if (value == nullptr || max_len == 0) return false; if (max_len < 2) { value[0] = 0; return false; } - value[0] = _parent->usb_debug_enabled == 1 ? '1' : '0'; + value[0] = *flag == 1 ? '1' : '0'; value[1] = 0; return true; } return CommonRadioPrefs::getByKey(key, value, max_len); } bool setByKey(const char* key, const char* value) override { - if (key != nullptr && strcmp(key, "usb_debug") == 0) { + uint8_t* flag = &_parent->usb_debug_enabled; + bool handled = key != nullptr && strcmp(key, "usb_debug") == 0; +#if !defined(MESH_DUAL_CDC_LOGGING) + if (key != nullptr && strcmp(key, "usb_log_always") == 0) { + flag = &_parent->usb_logging_always; + handled = true; + } +#endif + if (handled) { if (value == nullptr || (strcmp(value, "0") != 0 && strcmp(value, "1") != 0)) { return false; } - _parent->usb_debug_enabled = value[0] == '1' ? 1 : 0; + *flag = value[0] == '1' ? 1 : 0; markDirty(); return true; } @@ -289,23 +311,23 @@ public: // both live adapters untouched and a scratch snapshot's adapters local. bool copyPersistedValuesFrom(const CompanionNodePrefs& source) { if (&source == this) return true; - const auto& last_value = tx_ssh; - static_assert(sizeof(tx_ssh) == sizeof(uint8_t), - "The last persisted traffic policy is one byte"); + const auto& last_value = usb_logging_always; + static_assert(sizeof(usb_logging_always) == sizeof(uint8_t), + "The last persisted preference is one byte"); const uintptr_t first = reinterpret_cast(&airtime_factor); const uintptr_t last = reinterpret_cast(&last_value); if (last < first - || last - first > sizeof(*this) - sizeof(tx_ssh)) { + || last - first > sizeof(*this) - sizeof(usb_logging_always)) { return false; } const size_t size = static_cast(last - first) - + sizeof(tx_ssh); + + sizeof(usb_logging_always); const auto bounded = [size](const CompanionNodePrefs& values) -> bool { const uintptr_t object = reinterpret_cast(&values); const uintptr_t begin = reinterpret_cast(&values.airtime_factor); const uintptr_t end = reinterpret_cast( - &values.tx_ssh + &values.usb_logging_always ); const uintptr_t radio_begin = reinterpret_cast(&values.radio); const uintptr_t custom_begin = reinterpret_cast(&values.custom); @@ -314,7 +336,7 @@ public: return begin >= object && begin - object <= sizeof(values) && size <= sizeof(values) - static_cast(begin - object) && end >= begin - && end - begin == size - sizeof(values.tx_ssh) + && end - begin == size - sizeof(values.usb_logging_always) && radio_begin >= begin && size <= radio_begin - begin && custom_begin >= begin && size <= custom_begin - begin; }; diff --git a/examples/companion_radio/PrefsStorageLayout.h b/examples/companion_radio/PrefsStorageLayout.h index 16f0da974..b7ebf8a45 100644 --- a/examples/companion_radio/PrefsStorageLayout.h +++ b/examples/companion_radio/PrefsStorageLayout.h @@ -136,7 +136,8 @@ static const void* prefValue(const PrefField& field, const int8_t* timezone = nullptr) { if (field.offset == PrefsLat) return ⪫ if (field.offset == PrefsLon) return &lon; - if (field.offset == PrefsPad) return pad; + // Byte 36 carries the always-log marker; the separate byte 79 stays zero. + if (field.offset == PrefsPad) return pad + (field.length == 1); const void* value = reinterpret_cast(&values) + field.offset; return timezone && value == &values.tz_offset_legacy ? timezone : value; } diff --git a/src/helpers/CommonCLI.cpp b/src/helpers/CommonCLI.cpp index 7f925a1ab..cb84f8e54 100644 --- a/src/helpers/CommonCLI.cpp +++ b/src/helpers/CommonCLI.cpp @@ -1055,6 +1055,7 @@ void CommonCLI::loadPrefs(FILESYSTEM* fs) { _prefs->usb_logging_enabled = 1; #endif _prefs->usb_debug_enabled = 0; + _prefs->usb_logging_always = 0; _prefs->trace_when_repeat_off = 0; _prefs->discovery_responses = mesh::discovery::DEFAULT_RESPONSES; _prefs->ota_channel = 0; @@ -1295,6 +1296,7 @@ void CommonCLI::loadPrefs(FILESYSTEM* fs) { #endif #if MESH_USB_LOGGING_AVAILABLE mesh::setUsbDebugEnabled(_prefs->usb_debug_enabled != 0); + mesh::setUsbPacketLoggingAlways(_prefs->usb_logging_always != 0); mesh::setUsbLoggingEnabled(_prefs->usb_logging_enabled != 0); #endif _radio_profiles.adoptPrimaryPreamble(_prefs->primary_radio_preamble); @@ -1329,6 +1331,7 @@ void CommonCLI::loadPrefsInt(FILESYSTEM* fs, const char* filename) { // Older or truncated preference images must never inherit these opt-ins // from a previous load of a newer image. _prefs->usb_debug_enabled = 0; + _prefs->usb_logging_always = 0; _prefs->trace_when_repeat_off = 0; _prefs->discovery_responses = mesh::discovery::DEFAULT_RESPONSES; _prefs->gps_sync_interval_hours = 0; @@ -1408,7 +1411,9 @@ void CommonCLI::loadPrefsInt(FILESYSTEM* fs, const char* filename) { file.read((uint8_t *)&_prefs->agc_reset_interval, sizeof(_prefs->agc_reset_interval)); // 120 file.read((uint8_t *)&_prefs->path_hash_mode, sizeof(_prefs->path_hash_mode)); // 121 file.read((uint8_t *)&_prefs->loop_detect, sizeof(_prefs->loop_detect)); // 122 - file.read(pad, 1); // 123 + uint8_t usb_logging_policy = 0; + file.read(&usb_logging_policy, 1); // 123: formerly padding + _prefs->usb_logging_always = usb_logging_policy == 0xA1 ? 1 : 0; file.read((uint8_t *)&_prefs->flood_max, sizeof(_prefs->flood_max)); // 124 file.read((uint8_t *)&_prefs->flood_advert_interval, sizeof(_prefs->flood_advert_interval)); // 125 file.read((uint8_t *)&_prefs->interference_threshold, sizeof(_prefs->interference_threshold)); // 126 @@ -1963,6 +1968,7 @@ void CommonCLI::loadPrefsInt(FILESYSTEM* fs, const char* filename) { _prefs->usb_logging_enabled = constrain(_prefs->usb_logging_enabled, 0, 1); // boolean // Only a deliberately saved 1 enables diagnostics; corrupted bytes are OFF. _prefs->usb_debug_enabled = _prefs->usb_debug_enabled == 1 ? 1 : 0; + _prefs->usb_logging_always = _prefs->usb_logging_always == 1 ? 1 : 0; // Corrupt or unknown values must not enable a repeat-off exception. _prefs->trace_when_repeat_off = _prefs->trace_when_repeat_off == 1 ? 1 : 0; _prefs->cad_enabled = constrain(_prefs->cad_enabled, 0, 1); // boolean @@ -2093,7 +2099,8 @@ static bool writeCommonPrefsImage(Writer& writer, NodePrefs* prefs) { WRITE_COMMON_PREFS(&prefs->agc_reset_interval); // 120 WRITE_COMMON_PREFS(&prefs->path_hash_mode); // 121 WRITE_COMMON_PREFS(&prefs->loop_detect); // 122 - WRITE_COMMON_PREFS_BYTES(pad, 1); // 123 + const uint8_t usb_logging_policy = prefs->usb_logging_always == 1 ? 0xA1 : 0; + WRITE_COMMON_PREFS(&usb_logging_policy); // 123: formerly padding WRITE_COMMON_PREFS(&prefs->flood_max); // 124 WRITE_COMMON_PREFS(&prefs->flood_advert_interval); // 125 WRITE_COMMON_PREFS(&prefs->interference_threshold); // 126 @@ -2311,6 +2318,7 @@ void CommonCLI::savePrefs(FILESYSTEM* fs, PrefsSaveRouting::Scope scope) { _common_save_result_known = true; _common_save_succeeded = false; _prefs->usb_debug_enabled = _prefs->usb_debug_enabled == 1 ? 1 : 0; + _prefs->usb_logging_always = _prefs->usb_logging_always == 1 ? 1 : 0; _prefs->trace_when_repeat_off = _prefs->trace_when_repeat_off == 1 ? 1 : 0; if (_prefs->discovery_responses > mesh::discovery::DEFAULT_RESPONSES) _prefs->discovery_responses = mesh::discovery::DEFAULT_RESPONSES; @@ -2373,7 +2381,8 @@ void CommonCLI::savePrefs(FILESYSTEM* fs, PrefsSaveRouting::Scope scope) { file.write((uint8_t *)&_prefs->agc_reset_interval, sizeof(_prefs->agc_reset_interval)); // 120 file.write((uint8_t *)&_prefs->path_hash_mode, sizeof(_prefs->path_hash_mode)); // 121 file.write((uint8_t *)&_prefs->loop_detect, sizeof(_prefs->loop_detect)); // 122 - file.write(pad, 1); // 123 + const uint8_t usb_logging_policy = _prefs->usb_logging_always == 1 ? 0xA1 : 0; + file.write(&usb_logging_policy, 1); // 123: formerly padding file.write((uint8_t *)&_prefs->flood_max, sizeof(_prefs->flood_max)); // 124 file.write((uint8_t *)&_prefs->flood_advert_interval, sizeof(_prefs->flood_advert_interval)); // 125 file.write((uint8_t *)&_prefs->interference_threshold, sizeof(_prefs->interference_threshold)); // 126 @@ -2499,6 +2508,7 @@ void CommonCLI::savePrefs(FILESYSTEM* fs, PrefsSaveRouting::Scope scope) { // Dynamic config imports use this path too. Do not enable diagnostics // until the corresponding common preference image is committed. mesh::setUsbDebugEnabled(_prefs->usb_debug_enabled != 0); + mesh::setUsbPacketLoggingAlways(_prefs->usb_logging_always != 0); mesh::setUsbLoggingEnabled(_prefs->usb_logging_enabled != 0); } #endif @@ -4438,6 +4448,29 @@ void CommonCLI::handleSetCmd(uint32_t sender_timestamp, char* command, char* rep } #endif #if MESH_USB_LOGGING_AVAILABLE +#if !defined(MESH_DUAL_CDC_LOGGING) + if (strncmp(config, "usb.logging.always", 18) == 0 + && (config[18] == 0 || config[18] == ' ' || config[18] == '\t')) { + const char* value = config + 18; + while (*value == ' ' || *value == '\t') value++; + bool enabled = false, reboot_if_needed = false; + if (!mesh::cli::parseLoggingToggle(value, enabled, reboot_if_needed) + || reboot_if_needed) { + mesh::cli::formatError(reply, 160, "usage set usb.logging.always on|off"); + return; + } + const uint8_t previous = _prefs->usb_logging_always; + _prefs->usb_logging_always = enabled ? 1 : 0; + if (!trySavePrefs()) { + _prefs->usb_logging_always = previous; + mesh::cli::formatError(reply, 160, "save unconfirmed; reboot may differ"); + return; + } + mesh::setUsbPacketLoggingAlways(enabled); + snprintf(reply, 160, "OK - USB logging always %s (saved)", enabled ? "on" : "off"); + return; + } +#endif if (strncmp(config, "usb.logging", 11) == 0 && (config[11] == 0 || config[11] == ' ' || config[11] == '\t')) { const char* value = &config[11]; @@ -6035,6 +6068,12 @@ void CommonCLI::handleGetCmd(uint32_t sender_timestamp, char* command, char* rep } #endif #if MESH_USB_LOGGING_AVAILABLE +#if !defined(MESH_DUAL_CDC_LOGGING) + if (strcmp(config, "usb.logging.always") == 0) { + snprintf(reply, 160, "> %s", mesh::isUsbPacketLoggingAlways() ? "on" : "off"); + return; + } +#endif if (strcmp(config, "usb.logging") == 0) { snprintf(reply, 160, "> %s", mesh::isUsbLoggingEnabled() ? "on" : "off"); diff --git a/src/helpers/CommonCLI.h b/src/helpers/CommonCLI.h index 5da5f4f97..e9b73c346 100644 --- a/src/helpers/CommonCLI.h +++ b/src/helpers/CommonCLI.h @@ -201,6 +201,8 @@ public: // USB diagnostics are opt-in independently of the packet output gate. // Appended after GPS sync cadence in /com_prefs, not beside usb_log. uint8_t usb_debug_enabled = 0; + // Reuses reserved /com_prefs byte 123; 0xA1 on disk means enabled. + uint8_t usb_logging_always = 0; // Repeater-only opt-in for routed trace diagnostics while repeat is off. // Appended after usb_debug in /com_prefs; existing images stay disabled. uint8_t trace_when_repeat_off = 0; @@ -386,6 +388,7 @@ private: def("format", _parent->bridge_format); def("usb_log", _parent->usb_logging_enabled); def("usb_dbg", _parent->usb_debug_enabled); + def("usb_always", _parent->usb_logging_always); #ifdef WITH_RS232_BRIDGE def("rs232_heartbeat", _parent->rs232_heartbeat); def("rs232_autosleep", _parent->rs232_autosleep); diff --git a/src/helpers/UsbLogging.cpp b/src/helpers/UsbLogging.cpp index 32ec83907..f03c2486b 100644 --- a/src/helpers/UsbLogging.cpp +++ b/src/helpers/UsbLogging.cpp @@ -96,6 +96,7 @@ static std::atomic usb_logging_preference_known{false}; static std::atomic usb_debug_enabled{false}; #if MESH_USB_LOGGING_AVAILABLE && !defined(MESH_DUAL_CDC_LOGGING) static std::atomic usb_packet_logging_quiet_until{0}; +static std::atomic usb_packet_logging_always{false}; #endif #if MESH_ENABLE_HOST_KISS static std::atomic usb_binary_stream_owned{false}; @@ -1299,7 +1300,8 @@ bool isUsbLoggingEnabled() { #if MESH_USB_LOGGING_AVAILABLE && !defined(MESH_DUAL_CDC_LOGGING) void noteUsbConsoleCommand(const char* command) { - if (command == nullptr || hasDedicatedUsbLoggingPort() || isUsbLoggingPacketStream()) return; + if (command == nullptr || isUsbPacketLoggingAlways() + || hasDedicatedUsbLoggingPort() || isUsbLoggingPacketStream()) return; while (*command == ' ' || *command == '\t' || *command == '\r' || *command == '\n') ++command; if (*command == 0 || isUsbLoggingStatsCommand(command)) return; for (const unsigned char* p = reinterpret_cast(command); *p; ++p) { @@ -1314,6 +1316,15 @@ void resumeUsbPacketLogging() { usb_packet_logging_quiet_until.store(0, std::memory_order_relaxed); } +void setUsbPacketLoggingAlways(bool enabled) { + usb_packet_logging_always.store(enabled, std::memory_order_relaxed); + if (enabled) resumeUsbPacketLogging(); +} + +bool isUsbPacketLoggingAlways() { + return usb_packet_logging_always.load(std::memory_order_relaxed); +} + bool isUsbPacketLoggingAllowed() { uint32_t deadline = usb_packet_logging_quiet_until.load(std::memory_order_relaxed); bool quiet = deadline != 0; @@ -1323,7 +1334,7 @@ bool isUsbPacketLoggingAllowed() { deadline, 0, std::memory_order_relaxed) && deadline != 0; } return isUsbLoggingEnabled() - && (hasDedicatedUsbLoggingPort() || isUsbLoggingPacketStream() || !quiet); + && (isUsbPacketLoggingAlways() || hasDedicatedUsbLoggingPort() || isUsbLoggingPacketStream() || !quiet); } #endif diff --git a/src/helpers/UsbLogging.h b/src/helpers/UsbLogging.h index b317f1c67..693378895 100644 --- a/src/helpers/UsbLogging.h +++ b/src/helpers/UsbLogging.h @@ -98,6 +98,8 @@ void setUsbLoggingEnabled(bool enabled); inline void noteUsbConsoleCommand(const char*) {} inline void resumeUsbPacketLogging() {} inline bool isUsbPacketLoggingAllowed() { return isUsbLoggingEnabled(); } +inline void setUsbPacketLoggingAlways(bool) {} +inline bool isUsbPacketLoggingAlways() { return false; } #elif MESH_USB_LOGGING_AVAILABLE // Human console commands pause packet records for five minutes without // changing the saved logging setting, functional replies, or debug output. @@ -106,10 +108,15 @@ inline bool isUsbPacketLoggingAllowed() { return isUsbLoggingEnabled(); } void noteUsbConsoleCommand(const char* command); void resumeUsbPacketLogging(); bool isUsbPacketLoggingAllowed(); +// The role persists this shared-port policy; it never enables the master gate. +void setUsbPacketLoggingAlways(bool enabled); +bool isUsbPacketLoggingAlways(); #else inline void noteUsbConsoleCommand(const char*) {} inline void resumeUsbPacketLogging() {} inline bool isUsbPacketLoggingAllowed() { return false; } +inline void setUsbPacketLoggingAlways(bool) {} +inline bool isUsbPacketLoggingAlways() { return false; } #endif // Verbose diagnostics are opt-in and persisted by the role preferences. // The requested setting survives switching the master USB output gate off. diff --git a/test/test_common_usb_debug.py b/test/test_common_usb_debug.py index 0bd68c5f0..9f99eb193 100644 --- a/test/test_common_usb_debug.py +++ b/test/test_common_usb_debug.py @@ -59,9 +59,9 @@ class TestFS : public MemoryFS { @CONSTANTS@ namespace mesh { struct RadioProfiles { static constexpr unsigned MaxPreamble = 65535; }; -static bool usb_logging = true, usb_debug = false; +static bool usb_logging = true, usb_debug = false, usb_always = false; static bool prohibit_stale_debug = false; -static unsigned usb_updates = 0, debug_updates = 0; +static unsigned usb_updates = 0, debug_updates = 0, always_updates = 0; void setUsbLoggingEnabled(bool enabled) { if (enabled && prohibit_stale_debug) assert(!usb_debug); usb_logging = enabled; ++usb_updates; @@ -69,6 +69,8 @@ void setUsbLoggingEnabled(bool enabled) { void setUsbDebugEnabled(bool enabled) { usb_debug = enabled; ++debug_updates; } bool isUsbLoggingEnabled() { return usb_logging; } void resumeUsbPacketLogging() {} +void setUsbPacketLoggingAlways(bool enabled) { usb_always = enabled; ++always_updates; } +bool isUsbPacketLoggingAlways() { return usb_always; } bool isUsbDebugEnabled() { return usb_debug; } bool isUsbDebugLoggingEnabled() { return usb_logging && usb_debug; } } @@ -182,6 +184,7 @@ int main() { assert(baseline[gps_offset] == 0 && baseline[gps_offset + 1] == 0); assert(baseline[trace_offset] == 0); assert(baseline[873] == 0); // OTA channel follows the established tail. + assert(baseline[123] == 0); // Reserved legacy byte keeps continuous logging OFF. Capture capture; assert(writeCommonPrefsImage(capture, &cli.prefs)); assert(capture.bytes == baseline); // Checked and ordinary writers agree. @@ -295,6 +298,100 @@ int main() { cli.prefs.usb_debug_enabled = 1; cli.loadPrefsInt(&cli.fs, "/missing"); assert(cli.prefs.usb_debug_enabled == 0); + + // Continuous capture has its own saved policy; changing it must not alter + // the master/debug gates, any established offset, or the optional tail. + CommonCLI policy; + mesh::setUsbDebugEnabled(false); + mesh::setUsbLoggingEnabled(true); + mesh::setUsbPacketLoggingAlways(false); + assert(policy.prefs.usb_logging_always == 0); + policy.savePrefs(&policy.fs, PrefsSaveRouting::Scope::Common); + const auto policy_off = policy.fs.files["/com_prefs"]; + assert(policy_off == baseline); + policy.get("usb.logging.always", reply); + assert(strcmp(reply, "> off") == 0); + policy.set("usb.logging.always on", reply); + assert(strcmp(reply, "OK - USB logging always on (saved)") == 0); + assert(policy.prefs.usb_logging_always == 1 && mesh::isUsbPacketLoggingAlways()); + assert(mesh::isUsbLoggingEnabled() && !mesh::isUsbDebugEnabled()); + auto policy_on = policy.fs.files["/com_prefs"]; + auto expected_on = policy_off; + expected_on[123] = 0xA1; + assert(policy_on == expected_on && policy_on.size() == baseline.size()); + capture.bytes.clear(); + assert(writeCommonPrefsImage(capture, &policy.prefs) && capture.bytes == policy_on); + policy.get("usb.logging.always", reply); + assert(strcmp(reply, "> on") == 0); + for (const char* command : {"usb.logging.always", "usb.logging.always true", + "usb.logging.always 1", "usb.logging.always ON", "usb.logging.always off junk", + "usb.logging.always off ", "usb.logging.always on reboot", "usb.logging.always off reboot"}) { + const unsigned updates = mesh::always_updates; + policy.set(command, reply); + assert(strcmp(reply, "Error: usage set usb.logging.always on|off") == 0); + assert(policy.prefs.usb_logging_always == 1 && mesh::isUsbPacketLoggingAlways()); + assert(mesh::always_updates == updates && policy.fs.files["/com_prefs"] == policy_on); + } + policy.set("usb.logging.alwaysfake off", reply); + assert(strcmp(reply, "unknown") == 0); + policy.get("usb.logging.alwaysfake", reply); + assert(strcmp(reply, "unknown") == 0); + policy.set("usb.logging.always\t \toff", reply); + assert(strcmp(reply, "OK - USB logging always off (saved)") == 0); + assert(!policy.prefs.usb_logging_always && !mesh::isUsbPacketLoggingAlways()); + assert(policy.fs.files["/com_prefs"] == policy_off); + for (int fault : {0, 1, 2, 3}) { + if (fault == 0) policy.fs.fail_write = true; + if (fault == 1) policy.fs.fail_write_after = 123; + if (fault == 2) policy.fs.fail_read_open = true; + if (fault == 3) policy.fs.fail_rename = 1; + const unsigned updates = mesh::always_updates; + policy.set("usb.logging.always on", reply); + assert(strcmp(reply, "Error: save unconfirmed; reboot may differ") == 0); + assert(policy.prefs.usb_logging_always == 0 && !mesh::isUsbPacketLoggingAlways()); + assert(mesh::always_updates == updates && policy.fs.files["/com_prefs"] == policy_off); + policy.fs.fail_write = false; policy.fs.fail_write_after = -1; + policy.fs.fail_read_open = false; policy.fs.fail_rename = 0; + } + BridgePrefs policy_schema(&policy.prefs); + assert(policy_schema.import("usb_always", 1)); + assert(*policy_schema.bytes.at("usb_always") == 1); // Export ordinary 0/1, not the wire marker. + assert(!mesh::isUsbPacketLoggingAlways()); + const unsigned before_import = mesh::always_updates; + policy.savePrefs(&policy.fs, PrefsSaveRouting::Scope::Observer); + assert(!mesh::isUsbPacketLoggingAlways() && mesh::always_updates == before_import); + assert(policy.fs.files["/com_prefs"] == policy_off); + policy.fs.fail_write = true; + policy.savePrefs(&policy.fs, PrefsSaveRouting::Scope::Common); + assert(!policy._common_save_succeeded && !mesh::isUsbPacketLoggingAlways()); + policy.fs.fail_write = false; + policy.savePrefs(&policy.fs, PrefsSaveRouting::Scope::Common); + assert(policy._common_save_succeeded && mesh::isUsbPacketLoggingAlways()); + assert(policy.fs.files["/com_prefs"] == policy_on); + for (uint8_t invalid : {2, 161, 255}) { + assert(policy_schema.import("usb_always", invalid)); + policy.savePrefs(&policy.fs, PrefsSaveRouting::Scope::Common); + assert(policy._common_save_succeeded && !mesh::isUsbPacketLoggingAlways()); + assert(policy.prefs.usb_logging_always == 0 && policy.fs.files["/com_prefs"] == policy_off); + } + // Old padding (including1/FF) cannot opt in, and neither a missing file nor + // a truncated core may retain an ON policy from a previous image. + for (uint8_t stored : {0, 1, 0xA0, 0xA1, 0xA2, 255}) { + auto image = policy_off; image[123] = stored; + policy.fs.files["/com_prefs"] = image; + policy.prefs.usb_logging_always = 1; + policy.loadPrefsInt(&policy.fs, "/com_prefs"); + assert(policy.prefs.usb_logging_always == (stored == 0xA1 ? 1 : 0)); + } + for (size_t size : {size_t(0), size_t(123), size_t(124), size_t(289), size_t(290)}) { + policy.fs.files["/com_prefs"] = {policy_off.begin(), policy_off.begin() + size}; + policy.prefs.usb_logging_always = 1; + policy.loadPrefsInt(&policy.fs, "/com_prefs"); + assert(policy.prefs.usb_logging_always == 0); + } + policy.prefs.usb_logging_always = 1; + policy.loadPrefsInt(&policy.fs, "/missing"); + assert(policy.prefs.usb_logging_always == 0); } ''' @@ -325,7 +422,8 @@ class CommonUsbDebugTest(unittest.TestCase): 'void CommonCLI::savePrefs(FILESYSTEM*', 'void CommonCLI::savePrefs(PrefsSaveRouting::Scope scope)', 'bool CommonCLI::trySavePrefs(', 'void CommonCLI::loadPrefsInt(')) - code = HARNESS + code = HARNESS.replace('@SET_DEBUG@', '@SET_ALWAYS@\n @SET_DEBUG@').replace( + '@GET_DEBUG@', '@GET_ALWAYS@\n @GET_DEBUG@') for key, value in { 'FIELDS': fields, 'CONSTANTS': constants, 'HELPERS': helpers, 'LEGACY': extract_braced(header, 'struct LegacyObserverTail') + ';', @@ -334,6 +432,8 @@ class CommonUsbDebugTest(unittest.TestCase): 'STORE': extract_braced(source, 'class CommonPrefsFileStore'), 'METHODS': ("\n#include \ntemplate\n" + extract_braced(source, "static void writeCommonRetryPrefs(") + "\n" + methods), 'DYNAMIC': extract_braced(header, 'class BridgePrefs :'), + 'SET_ALWAYS': extract_braced(source, 'if (strncmp(config, "usb.logging.always", 18)'), + 'GET_ALWAYS': extract_braced(source, 'if (strcmp(config, "usb.logging.always") == 0)'), 'SET_DEBUG': extract_braced(source, 'if (strncmp(config, "usb.debug", 9)'), 'SET_MASTER': extract_braced(source, 'if (strncmp(config, "usb.logging", 11)'), 'GET_DEBUG': extract_braced(source, 'if (strcmp(config, "usb.debug") == 0)'), @@ -371,8 +471,10 @@ class CommonUsbDebugTest(unittest.TestCase): source = (ROOT / 'src/helpers/CommonCLI.cpp').read_text(encoding='utf-8') load = extract_braced(source, 'void CommonCLI::loadPrefs(FILESYSTEM*') self.assertIn('_prefs->usb_debug_enabled = 0;', load) + self.assertIn('_prefs->usb_logging_always = 0;', load) self.assertIn('mesh::setUsbLoggingEnabled(_prefs->usb_logging_enabled != 0);', load) self.assertIn('mesh::setUsbDebugEnabled(_prefs->usb_debug_enabled != 0);', load) + self.assertIn('mesh::setUsbPacketLoggingAlways(_prefs->usb_logging_always != 0);', load) self.assertLess(load.index('mesh::setUsbDebugEnabled('), load.index('mesh::setUsbLoggingEnabled(')) diff --git a/test/test_companion_packet_stream.py b/test/test_companion_packet_stream.py index b18bc3f77..fb9c3c19c 100644 --- a/test/test_companion_packet_stream.py +++ b/test/test_companion_packet_stream.py @@ -42,6 +42,7 @@ bool isUsbLoggingEnabled(){return logging;} bool isUsbDebugLoggingEnabled(){return false;} void setPlatformDebugOutputEnabled(bool){} void setUsbDebugEnabled(bool){} +void setUsbPacketLoggingAlways(bool){} void setUsbLoggingEnabled(bool enabled){logging=enabled;usb_logging_preference_known=true;} bool saveUsbLoggingBootPreference(bool){return true;} unsigned packet_logging_resumes=0; @@ -190,7 +191,7 @@ class CompanionPacketStreamTests(unittest.TestCase): start = mesh.index(' if (strcmp(command, "get usb.logging") == 0)') end = mesh.index('\n#endif', start) boot_start = mesh.index(' const bool usb_logging_enabled = _prefs.usb_logging_enabled != 0;') - boot_end = mesh.index('\n#endif', boot_start) + boot_end = mesh.index(' if (!mesh::saveUsbLoggingBootPreference(', boot_start) normalize = next(line for line in mesh.splitlines() if '_prefs.usb_logging_enabled = constrain(' in line) code = MODE_HARNESS.replace('@USB_FUNCTIONS@', functions) diff --git a/test/test_companion_prefs_image.py b/test/test_companion_prefs_image.py index b33a14439..2a13b101b 100644 --- a/test/test_companion_prefs_image.py +++ b/test/test_companion_prefs_image.py @@ -14,7 +14,7 @@ ROOT = Path(__file__).resolve().parents[1] # and the class's in-memory member order or padding. None represents reserved # padding; compact Wio Companion claims the single byte at wire offset 79. WIRE_FIELDS = ( - ('airtime_factor', 4), ('node_name', 32), (None, 4), + ('airtime_factor', 4), ('node_name', 32), ('usb_logging_always', 4), ('@lat', 8), ('@lon', 8), ('freq', 4), ('sf', 1), ('cr', 1), ('client_repeat', 1), ('manual_add_contacts', 1), ('bw', 4), ('tx_power_dbm', 1), ('telemetry_mode_base', 1), ('telemetry_mode_loc', 1), @@ -62,6 +62,7 @@ static void seed(CompanionNodePrefs& prefs, uint32_t& random) { } }; @SEED@ + prefs.usb_logging_always = random & 1; prefs.tx_media = random % 5; prefs.tx_ssh = (random >> 8) % 5; #if defined(RAK_4631) @@ -148,22 +149,21 @@ int main() { #endif DataStore reference; assert(reference.savePrefsLegacy(prefs, 47.125, -122.25)); -#if defined(WIO_E5_MINI_HEADLESS_COMPANION_UI) - // The compact target claims exactly the former reserved byte. Its frozen - // predecessor still emits zero there; every other byte stays identical. + // The predecessor emitted zero at the newly claimed reserved bytes. auto historical = store.fs.files.at("/new_prefs"); + assert(historical[36] == (prefs.usb_logging_always == 1 ? 0xa1 : 0)); + historical[36] = 0; +#if defined(WIO_E5_MINI_HEADLESS_COMPANION_UI) assert(historical[79] == prefs.leds_quiet); historical[79] = 0; - assert(reference.fs.files.at("/new_prefs") == historical); -#else - assert(reference.fs.files.at("/new_prefs") == store.fs.files.at("/new_prefs")); #endif + assert(reference.fs.files.at("/new_prefs") == historical); ++comparisons; } CompanionNodePrefs original; assert(original.buzzer_quiet == 1 && original.vibe_quiet == 0); - assert(original.lost_reply == 0); + assert(original.lost_reply == 0 && original.usb_logging_always == 0); assert(original.tx_media == mesh::RADIO_TX_AUTO && original.tx_ssh == mesh::RADIO_TX_AUTO); strcpy(original.node_name, "durable image"); original.freq = 915.25f; original.ble_pin = 123456; @@ -324,6 +324,7 @@ int main() { changed.freq = 910.5f; changed.usb_debug_enabled = 0; changed.gps_sync_interval_hours = 24; changed.lost_reply = 1; + changed.usb_logging_always = 1; #if defined(WIO_E5_MINI_HEADLESS_COMPANION_UI) changed.leds_quiet = 0; #endif @@ -465,6 +466,7 @@ int main() { assert(loaded.gps_sync_interval_hours == 24 && loaded.usb_debug_enabled == 0); assert(loaded.lost_reply == 1); assert(loaded.tx_media == original.tx_media && loaded.tx_ssh == original.tx_ssh); + assert(loaded.usb_logging_always == 1); assert(lat == 42.25 && lon == -121.125); #if defined(STM32_PLATFORM) @@ -531,6 +533,12 @@ def field_code(rows, seed=False): if not seed: result.append('#else\nbytes.push_back(0);') result.append('#endif') + elif name == 'usb_logging_always': + if seed: + result.append('fill(&prefs.usb_logging_always, sizeof(prefs.usb_logging_always));') + else: + result.append('bytes.push_back(prefs.usb_logging_always == 1 ? 0xa1 : 0);') + result.append('bytes.insert(bytes.end(), 3, uint8_t(0));') elif name == 'tz_offset': if seed: result.append('prefs.tz_offset = float(int(random % 27) - 12);') diff --git a/test/test_companion_usb_logging.py b/test/test_companion_usb_logging.py index 2db641863..51545fd8e 100644 --- a/test/test_companion_usb_logging.py +++ b/test/test_companion_usb_logging.py @@ -30,8 +30,10 @@ struct ConfigText : Stream { } }; namespace mesh { -bool logging_enabled=true, debug_enabled=false; -unsigned debug_applies=0; +bool logging_enabled=true, debug_enabled=false, always_enabled=false; +unsigned debug_applies=0, always_applies=0; +bool isUsbPacketLoggingAlways(){return always_enabled;} +void setUsbPacketLoggingAlways(bool enabled){always_enabled=enabled;++always_applies;} bool isUsbLoggingEnabled(){return logging_enabled;} bool isUsbDebugEnabled(){return debug_enabled;} void setUsbDebugEnabled(bool enabled){debug_enabled=enabled;++debug_applies;} @@ -177,6 +179,61 @@ int main(){ // Bounded replies do not write beyond their supplied capacity. char small[9];memset(small,'X',sizeof(small)); assert(node.command("get usb.debug",small,8));assert(small[7]==0&&small[8]=='X'); + // The always-log policy uses only reserved byte 36, preserving all image sizes. + assert(node._prefs.usb_logging_always==0&&!mesh::always_enabled); + mesh::logging_enabled=false; + assert(node.command("set usb.logging.always on",reply,sizeof(reply))); + assert(node._prefs.usb_logging_always==1&&mesh::always_enabled&&!mesh::logging_enabled); + const auto always_disk=node.store.fs.files["/new_prefs"]; + assert(always_disk[36]==0xa1&&always_disk[37]==0&&always_disk[38]==0 + &&always_disk[39]==0&&always_disk[79]==0); + assert(node.command("get usb.logging.always",reply,sizeof(reply))); + assert(!strcmp(reply,"usb.logging.always on")); + for(const char* invalid : {"", "ON", "true", "1", "on extra", "on ", "off reboot"}) { + std::string command=std::string("set usb.logging.always ")+invalid; + const unsigned applied=mesh::always_applies; + assert(node.command(command.c_str(),reply,sizeof(reply))&&strstr(reply,"Error:")); + assert(node._prefs.usb_logging_always==1&&mesh::always_enabled); + assert(mesh::always_applies==applied&&node.store.fs.files["/new_prefs"]==always_disk); + } + for(int fail_after : {17,36,int(always_disk.size()-1)}) { + node.store.fs.fail_write_after=fail_after; + const unsigned applied=mesh::always_applies; + assert(node.command("set usb.logging.always off",reply,sizeof(reply))); + assert(strstr(reply,"could not be saved")&&node._prefs.usb_logging_always==1); + assert(mesh::always_enabled&&mesh::always_applies==applied); + assert(node.store.fs.files["/new_prefs"]==always_disk); + } + node.store.fs.fail_write_after=-1; + assert(node.command("set usb.logging.always off",reply,sizeof(reply))); + assert(!node._prefs.usb_logging_always&&!mesh::always_enabled&&!mesh::logging_enabled); + const auto quiet_disk=node.store.fs.files["/new_prefs"]; + assert(quiet_disk.size()==always_disk.size()); + for(size_t i=0;isetByKey("usb_log_always","1")); + assert(!node._prefs.getRadioPrefs()->setByKey("usb_log_always","2")); + assert(node.savePrefs()&&mesh::always_enabled); + assert(node._prefs.getCustom()->getByKey("usb_log_always",dynamic,sizeof(dynamic))); + assert(!strcmp(dynamic,"1")); + ConfigText policy_import;policy_import.text="{usb_log_always:0}"; + assert(serializer->loadSerial(policy_import)&&node._prefs.usb_logging_always==0); + assert(node.savePrefs()&&!mesh::always_enabled); + ConfigText policy_export;assert(node._prefs.getRadioPrefs()->saveSerial(policy_export)); + assert(policy_export.text.find("usb_log_always:0")!=std::string::npos); + node._prefs.usb_logging_always=255;assert(node.savePrefs()); + assert(node._prefs.usb_logging_always==0&&!mesh::always_enabled); + node._prefs.usb_logging_always=255;node.store.fs.fail_write=true; + assert(!node.savePrefs()&&node._prefs.usb_logging_always==255&&!mesh::always_enabled); } ''' @@ -357,7 +414,10 @@ inline char* utoa(unsigned int value,char* output,int base){ prefix = STORE_HARNESS.split('int main(')[0].replace('@METHODS@', store_methods) start = source.index(' if (strcmp(command, "get usb.debug") == 0)') end = source.index(' if (strcmp(command, "get usb.logging") == 0)', start) - harness = PREFERENCE_HARNESS.replace('@DEBUG_COMMANDS@', source[start:end]) + always = '#if !defined(MESH_DUAL_CDC_LOGGING)\n' + '\n'.join(method(source, signature) + for signature in ('if (strcmp(command, "get usb.logging.always") == 0)', + 'if (strncmp(command, "set usb.logging.always", 22) == 0')) + '\n#endif\n' + harness = PREFERENCE_HARNESS.replace('@DEBUG_COMMANDS@', always + source[start:end]) harness = harness.replace('@SAVE_PREFS@', method(header, ' bool savePrefs()')) harness = harness.replace('@SAVE_PREFERENCE@', method( header, 'template bool savePreference(')) diff --git a/test/test_usb_packet_logging_quiet.py b/test/test_usb_packet_logging_quiet.py index 6727d3d99..9b60fb494 100644 --- a/test/test_usb_packet_logging_quiet.py +++ b/test/test_usb_packet_logging_quiet.py @@ -33,6 +33,7 @@ struct MyMesh { static void timerCases() { mesh::setUsbLoggingEnabled(true);mesh::resumeUsbPacketLogging(); mesh::configureUsbLoggingPacketStream(false);g_mock_millis=0; + assert(!mesh::isUsbPacketLoggingAlways()); for(const char* ignored:std::initializer_list{nullptr,""," \t\r\n","stats-core"," \tstats-radio\t ","stats-packets", "\x01" "get name","get\x7f","\xff" "get name","get name\n","stats-core\r","get\rname"}) { mesh::noteUsbConsoleCommand(ignored);assert(mesh::isUsbPacketLoggingAllowed()); @@ -71,6 +72,20 @@ static void timerCases() { mesh::setUsbLoggingEnabled(true);mesh::configureUsbLoggingPacketStream(true); mesh::noteUsbConsoleCommand("get name");assert(mesh::isUsbPacketLoggingAllowed()); mesh::configureUsbLoggingPacketStream(false);assert(mesh::isUsbPacketLoggingAllowed()); + // Always-on capture clears an existing quiet period without enabling USB. + mesh::noteUsbConsoleCommand("get name");assert(!mesh::isUsbPacketLoggingAllowed()); + mesh::setUsbPacketLoggingAlways(true); + assert(mesh::isUsbPacketLoggingAlways()&&mesh::isUsbPacketLoggingAllowed()); + mesh::noteUsbConsoleCommand("get name");mesh::noteUsbConsoleCommand("get radio"); + assert(mesh::isUsbPacketLoggingAllowed()); + mesh::setUsbLoggingEnabled(false); + assert(mesh::isUsbPacketLoggingAlways()&&!mesh::isUsbPacketLoggingAllowed()); + mesh::setUsbLoggingEnabled(true); + assert(mesh::isUsbPacketLoggingAlways()&&mesh::isUsbPacketLoggingAllowed()); + mesh::setUsbPacketLoggingAlways(false); + assert(!mesh::isUsbPacketLoggingAlways()&&mesh::isUsbPacketLoggingAllowed()); + mesh::noteUsbConsoleCommand("get name");assert(!mesh::isUsbPacketLoggingAllowed()); + mesh::setUsbLoggingEnabled(true);assert(!mesh::isUsbPacketLoggingAllowed()); std::puts("PASS: packet quiet timers, reset, wrap, polls, stream and saved master"); } static void outputCases() { @@ -109,6 +124,15 @@ static void outputCases() { #else assert(host=="stamp RAW: 00ABFF\r\n"); #endif + host.clear();mesh::setUsbPacketLoggingAlways(true);mesh::noteUsbConsoleCommand("get name"); + node.logRxRaw(2.5f,-92,raw,sizeof(raw));drain(); +#if MESH_PACKET_LOGGING_COMPACT + assert(host=="R00ABFF\n"); +#else + assert(host=="stamp RAW: 00ABFF\r\n"); +#endif + host.clear();mesh::setUsbPacketLoggingAlways(false);mesh::noteUsbConsoleCommand("get name"); + node.logRxRaw(2.5f,-92,raw,sizeof(raw));drain();assert(host.empty()); std::puts("PASS: quiet RAW records preserve replies and complete in-progress records"); } int main(int argc,char**) {if(argc==1)timerCases();else outputCases();} @@ -122,6 +146,7 @@ CORE_CASE = r''' namespace mesh { static std::atomic usb_logging_enabled{true}; static std::atomic usb_packet_logging_quiet_until{0}; +static std::atomic usb_packet_logging_always{false}; bool dedicated=false,stream=false; bool hasDedicatedUsbLoggingPort(){return dedicated;} bool isUsbLoggingPacketStream(){return stream;} @@ -175,7 +200,8 @@ class UsbPacketLoggingQuietTests(unittest.TestCase): source = (ROOT / "src/helpers/UsbLogging.cpp").read_text() methods = "\n".join(method(source, signature) for signature in ( "bool isUsbLoggingEnabled(", "void noteUsbConsoleCommand(", - "void resumeUsbPacketLogging(", "bool isUsbPacketLoggingAllowed(")) + "void resumeUsbPacketLogging(", "void setUsbPacketLoggingAlways(", + "bool isUsbPacketLoggingAlways(", "bool isUsbPacketLoggingAllowed(")) with tempfile.TemporaryDirectory(prefix="meshcore-packet-dedicated-") as directory: binary = self.compile(Path(directory), "dedicated", CORE_CASE.replace("@METHODS@", methods), ["-DMESH_DEBUG=1"]) ran = subprocess.run([str(binary)], capture_output=True, text=True, timeout=20) @@ -199,6 +225,7 @@ int main(){ assert(mesh::hasDedicatedUsbLoggingPort()==!stream); mesh::noteUsbConsoleCommand(nullptr);mesh::noteUsbConsoleCommand("get name"); assert(mesh::isUsbPacketLoggingAllowed()==enabled); + mesh::setUsbPacketLoggingAlways(true);assert(!mesh::isUsbPacketLoggingAlways()); mesh::resumeUsbPacketLogging(); assert(mesh::isUsbPacketLoggingAllowed()==enabled); } @@ -219,6 +246,7 @@ int main(){ int main(){ static_assert(!MESH_USB_LOGGING_AVAILABLE,"disabled test profile"); mesh::noteUsbConsoleCommand("get name");mesh::resumeUsbPacketLogging(); + mesh::setUsbPacketLoggingAlways(true);assert(!mesh::isUsbPacketLoggingAlways()); assert(!mesh::isUsbPacketLoggingAllowed()); } ''', flags)