From 7c65314266e1158599d8214a43a019f82d0dbe76 Mon Sep 17 00:00:00 2001 From: mikecarper Date: Sun, 13 Sep 2026 15:34:00 -0700 Subject: [PATCH] Preserve Full USB packet logging and verify packaged firmware --- .github/workflows/run-unit-tests.yml | 8 +++ build.sh | 68 ++++++++++++++++++++ docs/full_usb_logging_validation.md | 78 +++++++++++++++++++++++ scripts/check_firmware_capabilities.py | 33 ++++++++-- scripts/deduplicate_full_build_flags.py | 35 ++++++++++- test/test_build_profiles.sh | 58 +++++++++++++++++ test/test_firmware_capabilities.py | 54 ++++++++++++++++ test/test_full_build_flag_dedup.py | 30 ++++++++- test/test_full_logging_compile.py | 84 +++++++++++++++++++++++++ test/test_full_logging_resume.py | 66 +++++++++++++++++++ 10 files changed, 508 insertions(+), 6 deletions(-) create mode 100644 docs/full_usb_logging_validation.md create mode 100644 test/test_full_logging_compile.py create mode 100644 test/test_full_logging_resume.py diff --git a/.github/workflows/run-unit-tests.yml b/.github/workflows/run-unit-tests.yml index 943bbbafa..81c99b73e 100644 --- a/.github/workflows/run-unit-tests.yml +++ b/.github/workflows/run-unit-tests.yml @@ -106,6 +106,14 @@ jobs: python3 -B test/test_picker_controls_generator.py node test/test_firmware_picker.js + - name: Verify Full logging compiler flags and packaged capabilities + run: | + python3 -B test/test_full_build_flag_dedup.py + python3 -B test/test_full_logging_compile.py + python3 -B test/test_full_logging_resume.py + python3 -B test/test_firmware_capabilities.py + bash test/test_build_profiles.sh + - name: Verify nRF52 UF2-reset CLI coverage run: python3 -B test/test_nrf52_uf2reset_cli.py diff --git a/build.sh b/build.sh index eb5e78bb1..de1171505 100755 --- a/build.sh +++ b/build.sh @@ -2607,6 +2607,23 @@ disable_usb_logging_for_mqtt() { fi } +requires_full_usb_packet_logging() { + local env_name=$1 + + # Full Companion and the combined USB+WiFi infrastructure artifact always + # carry the logger behind runtime controls. Other Full profiles retain the + # ordinary explicit logging-off/disable-debug behavior. + is_companion_radio_full_target "$env_name" && return 0 + [ "$ESP32_FULL_BUILD" = "1" ] || return 1 + is_companion_build "$env_name" && return 1 + [ "${PACKET_LOGGING_OVERRIDE,,}" = "on" ] && return 0 + if [ "${PACKET_LOGGING_OVERRIDE,,}" = "off" ] \ + || [ "${DISABLE_DEBUG:-0}" = "1" ]; then + return 1 + fi + uses_merged_standard_usb_logging "$env_name" +} + is_esp32_usb_wifi_companion_ota_build() { local env_name=$1 local env_name_lc=${env_name,,} @@ -2927,12 +2944,39 @@ record_build_expectation() { BUILD_EXPECTATIONS+=("$1=$2") } +record_application_expectation() { + BUILD_APPLICATION_EXPECTATIONS+=("$1=$2") +} + +declare_full_logging_application_contract() { + local env_name=$1 + BUILD_APPLICATION_EXPECTATIONS=() + if requires_full_usb_packet_logging "$env_name"; then + # Inspect the packaged application, not an ELF debug/symbol string. The + # settings alone can exist in debug-only builds with packet logging absent. + record_application_expectation "logging.usb.packets" \ + "%s: %s, len=%d (type=%d, route=%s, payload_len=%d)" + if is_companion_radio_full_target "$env_name"; then + record_application_expectation "logging.usb.control" "get usb.logging" + else + record_application_expectation "logging.usb.control" \ + "OK - USB logging %s (saved)" + if is_mqtt_bridge_target "$env_name" \ + || [ "${MQTT_BRIDGE_OVERRIDE,,}" = "on" ]; then + record_application_expectation "logging.usb.output" \ + "OK - logging.output %s (saved)" + fi + fi + fi +} + declare_build_capability_contract() { local env_name=$1 local env_platform=$2 local env_name_lc=${env_name,,} local pio_env_name + declare_full_logging_application_contract "$env_name" record_build_capability "profile.${BUILD_PROFILE_FOR_TARGET}" if [ "$env_platform" = "NRF52_PLATFORM" ] && ! is_kiss_modem_target "$env_name"; then @@ -3852,6 +3896,9 @@ write_build_capability_manifest() { for item in "${BUILD_EXPECTATIONS[@]}"; do checker_args+=(--expect "$item") done + for item in "${BUILD_APPLICATION_EXPECTATIONS[@]}"; do + checker_args+=(--expect-application "$item") + done python3 scripts/check_firmware_capabilities.py "${checker_args[@]}" } @@ -3941,6 +3988,18 @@ build_artifacts_exist() { "${OUTPUT_DIR}/${firmware_filename}" >/dev/null 2>&1 || return 1 grep -q '"verified": true' \ "${OUTPUT_DIR}/${firmware_filename}.capabilities.json" || return 1 + # Old manifests can be marked verified while lacking a newly required + # capability. Never let --resume bypass the current packaged-logging gate. + python3 - "${OUTPUT_DIR}/${firmware_filename}.capabilities.json" \ + "${BUILD_APPLICATION_EXPECTATIONS[@]}" <<'PY' || return 1 +import json, sys +manifest = json.load(open(sys.argv[1])) +proven = {(item.get("capability"), item.get("evidence")) + for item in manifest.get("verification", []) + if item.get("present") is True and item.get("source") == "packaged application"} +required = {tuple(value.split("=", 1)) for value in sys.argv[2:]} +sys.exit(0 if required <= proven else 1) +PY if [ "${REQUIRE_OTA_UPDATES:-0}" = "1" ]; then python3 - "${OUTPUT_DIR}/${firmware_filename}.capabilities.json" <<'PY' || return 1 import json, sys @@ -4104,6 +4163,7 @@ build_firmware() { local -a BUILD_CAPABILITIES=() local -a BUILD_REDUCTIONS=() local -a BUILD_EXPECTATIONS=() + local -a BUILD_APPLICATION_EXPECTATIONS=() local BUILD_PROFILE_FOR_TARGET=$BUILD_PROFILE_EFFECTIVE # Bash functions use dynamic scoping. These locals let one target be promoted @@ -4198,6 +4258,7 @@ build_firmware() { fi local embedded_version_string="${firmware_version}${embedded_build_suffix}${embedded_variant_tag}-${commit_hash}" + declare_full_logging_application_contract "$env_name" if [ "$RESUME_BUILD_OUTPUT" == "1" ] && build_artifacts_exist "$env_platform" "$firmware_filename"; then echo "Skipping ${env_name}; existing artifacts found for ${firmware_filename}." return 0 @@ -4252,6 +4313,11 @@ build_firmware() { if [ "$ESP32_FULL_BUILD" = "1" ] || is_esp32_companion_radio_full_target "$env_name"; then export MESHCORE_ESP32_FULL_BUILD=1 + if requires_full_usb_packet_logging "$env_name"; then + export MESHCORE_REQUIRE_PACKET_LOGGING=1 + else + unset MESHCORE_REQUIRE_PACKET_LOGGING + fi if is_esp32_companion_radio_full_target "$env_name"; then export MESHCORE_COMPANION_RADIO_FULL=1 else @@ -4272,6 +4338,7 @@ build_firmware() { fi else unset MESHCORE_ESP32_FULL_BUILD + unset MESHCORE_REQUIRE_PACKET_LOGGING unset MESHCORE_COMPANION_RADIO_FULL fi @@ -4334,6 +4401,7 @@ build_firmware() { restore_platformio_build_flags "$had_platformio_build_flags" "$original_platformio_build_flags" unset MESHCORE_ESP32_FULL_BUILD + unset MESHCORE_REQUIRE_PACKET_LOGGING unset MESHCORE_COMPANION_RADIO_FULL unset MESHCORE_ESP32_FULL_PARTITION_TABLE unset MESHCORE_NRF52_INTERNAL_BOOTLOADER_UPDATE diff --git a/docs/full_usb_logging_validation.md b/docs/full_usb_logging_validation.md new file mode 100644 index 000000000..fa69d176c --- /dev/null +++ b/docs/full_usb_logging_validation.md @@ -0,0 +1,78 @@ +# Full USB logging repair — 1.17.1.6 + +Audit date: 2026-09-13. Release firmware source: `306feebe6d648a247f925894f876be9d747fc8d2`. + +The original Station G2 Full Repeater and Full Room Server images omitted USB +packet logging. Both inherited `-UMESH_PACKET_LOGGING` from their ordinary MQTT +observer recipes. Full added `-DMESH_PACKET_LOGGING=1`, but PlatformIO's +`ProcessFlags` moves undefines after defines in the compiler command. The +resulting image compiled successfully with its packet logger removed. + +The previous release gate checked OTA and other features without requiring +USB logging in Full infrastructure. An old passing manifest could also be +reused by `--resume` without the new logging evidence. + +## Published-image audit + +Each downloaded/cached artifact was matched to GitHub's published SHA-256. +The check inspected application bytes, including the application inside nRF52 +DFU ZIPs. It required the packet-log formatter and USB logging controls. + +| Release group | Application images | Missing USB packet logging | +| --- | ---: | ---: | +| ESP32 Full infrastructure/utility | 157 | 2 | +| ESP32 Full Companion | 52 | 0 | +| nRF52 Full Companion | 43 | 0 | +| Total | 252 | 2 | + +Affected targets: + +- `Station_G2_repeater_observer_mqtt` +- `Station_G2_room_server_observer_mqtt` + +V4/R8 Full builds and Station G2's Full ESP-NOW bridge passed. This audit does +not count ordinary MQTT profiles that intentionally omit USB logging as +broken. Artifact inspection proves compiled support, not hardware operation +on every board. + +## Fix and regression coverage + +- Full builds that require logging remove inherited disables of + `MESH_PACKET_LOGGING` before PlatformIO parses flags. Other macros and + explicit logging-off profiles retain their policy. +- Full capability checks require the packet logger and USB controls in the + packaged application. Combined USB/WiFi profiles additionally require + the `logging.output` setter. ELF symbols or debug text cannot satisfy these + checks. +- Resumed builds must have passing application evidence for the current + logging contract, along with the existing artifact hashes and RAM checks. +- CI runs the flag, real PlatformIO/compiler, artifact, resume, and build-profile + regression suites. + +Focused verification (after installing PlatformIO and its tool-scons package): + +```sh +python3 -B test/test_full_build_flag_dedup.py +python3 -B test/test_full_logging_compile.py +python3 -B test/test_firmware_capabilities.py +python3 -B test/test_full_logging_resume.py +bash test/test_build_profiles.sh +python3 -B test/test_cascade_release_package.py +``` + +Both Station G2 profiles were rebuilt through `build.sh --full` with the +original observer recipes, including their inherited logging undefines. They +passed the new application checks, runtime RAM budgets, and both OTA slot +size checks. The new checker rejects both original published images. + +On the Bellevue Station G2, the corrected Full repeater implementation also +passed serial CLI and passive traffic checks: four RX and two TX packet log +lines were captured. Its active temporary profile retained preamble 120 and +the original schedule end time; the Pi relay services were restored. + +Corrected application SHA-256: + +```text +Repeater: 81a0a2926d4e567c069d0b10f316047881bcedce062afaa42119dddb2baadf23 +Room Server: 7ee81f1cb65fc274bd363397c3c80ce9006d575efae50fe952c8ca246613a18c +``` diff --git a/scripts/check_firmware_capabilities.py b/scripts/check_firmware_capabilities.py index e0724d93b..d3055c8fd 100644 --- a/scripts/check_firmware_capabilities.py +++ b/scripts/check_firmware_capabilities.py @@ -67,6 +67,11 @@ def parse_args() -> argparse.Namespace: metavar="CAPABILITY=TEXT", help="Require TEXT to be present in the linked image.", ) + parser.add_argument( + "--expect-application", action="append", default=[], + metavar="CAPABILITY=TEXT", + help="Require TEXT in the packaged firmware.bin or DFU application, not ELF metadata.", + ) return parser.parse_args() @@ -74,6 +79,16 @@ def stable_unique(values: list[str]) -> list[str]: return list(dict.fromkeys(value for value in values if value)) +def read_application(args): + if args.firmware_bin is not None: + return args.firmware_bin.read_bytes() + if args.dfu_package is not None: + with zipfile.ZipFile(args.dfu_package) as package: + app = json.loads(package.read("manifest.json"))["manifest"]["application"] + return package.read(app["bin_file"]) + raise ValueError("application checks require --firmware-bin or --dfu-package") + + def verify_ota_artifacts(args, methods): """Check the actual update medium; source/seeder support cannot qualify.""" if not methods: @@ -138,21 +153,31 @@ def main() -> int: checks = [] malformed = False - for expectation in args.expect: + application = b"" + if args.expect_application: + try: + application = read_application(args) + except (OSError, ValueError, KeyError, zipfile.BadZipFile) as exc: + print(f"capability check: cannot read packaged application: {exc}", file=sys.stderr) + malformed = True + expectations = [(value, image, "linked image") for value in args.expect] + expectations += [(value, application, "packaged application") for value in args.expect_application] + for expectation, content, source in expectations: if "=" not in expectation: print( - f"capability check: malformed --expect {expectation!r}", + f"capability check: malformed expectation {expectation!r}", file=sys.stderr, ) malformed = True continue capability, needle = expectation.split("=", 1) - present = bool(needle) and needle.encode("utf-8") in image + present = bool(needle) and needle.encode("utf-8") in content checks.append( { "capability": capability, "evidence": needle, "present": present, + "source": source, } ) @@ -203,7 +228,7 @@ def main() -> int: print( "capability check failed: " f"{check['capability']} promised but {check['evidence']!r} " - f"is absent from {args.image}", + f"is absent from the {check['source']}", file=sys.stderr, ) return 1 diff --git a/scripts/deduplicate_full_build_flags.py b/scripts/deduplicate_full_build_flags.py index f99967c54..a51840d49 100644 --- a/scripts/deduplicate_full_build_flags.py +++ b/scripts/deduplicate_full_build_flags.py @@ -12,6 +12,10 @@ compiler/linker inputs remain untouched. On Windows, existing include directories are also rewritten to shorter 8.3 aliases without changing their order. This keeps GCC's expanded ``cc1plus`` command below the CreateProcess limit. + +Full profiles that promise USB packet logging also remove inherited disables +before PlatformIO parses the flags. PlatformIO emits all ``-U`` options after +``-D`` options, so appending a define alone cannot enable an inherited disable. """ Import("env") # noqa: F821 @@ -125,6 +129,29 @@ def deduplicate_overlay(build_flags, overlay): return serialize_flags(unique), len(flags) - len(unique) +def require_packet_logging(build_flags): + """Make the selected Full logging contract survive ParseFlags ordering. + + Touch only this macro: other defines, undefines, quoted strings, and + option/argument pairs retain their semantics. A later artifact check also + proves that packet logging survived other scripts and link-time removal. + """ + retained = [] + for flag in logical_flags(build_flags): + if flag[0] is not COMMAND_FLAG: + if flag[0] in {"-D", "-U"} and len(flag) == 2: + macro = flag[1] + elif flag[0].startswith(("-D", "-U")): + macro = flag[0][2:] + else: + macro = "" + if macro.split("=", 1)[0] == "MESH_PACKET_LOGGING": + continue + retained.append(flag) + retained.append(("-DMESH_PACKET_LOGGING=1",)) + return serialize_flags(retained) + + def resolved_path(value, project_dir, expander=None): """Resolve a SCons path node/string without requiring SCons in tests.""" if hasattr(value, "get_abspath"): @@ -217,12 +244,18 @@ if os.environ.get("MESHCORE_ESP32_FULL_BUILD") == "1": cleaned, removed = deduplicate_overlay( original, os.environ.get("PLATFORMIO_BUILD_FLAGS", "") ) - if removed: + logging_required = os.environ.get("MESHCORE_REQUIRE_PACKET_LOGGING") == "1" + if logging_required: + cleaned = require_packet_logging(cleaned) + if removed or logging_required: env.Replace(BUILD_FLAGS=cleaned) # noqa: F821 + if removed: print( "ESP32 FULL build: removed %d repeated external build flags" % removed ) + if logging_required: + print("ESP32 FULL build: USB packet logging required; inherited disables removed") if ( os.name == "nt" and os.environ.get("MESHCORE_COMPANION_RADIO_FULL") == "1" diff --git a/test/test_build_profiles.sh b/test/test_build_profiles.sh index afee220fa..f98beb86d 100644 --- a/test/test_build_profiles.sh +++ b/test/test_build_profiles.sh @@ -595,6 +595,64 @@ while IFS= read -r env_name; do fi done < <(resolve_companion_firmwares) +# Full logging is a compiled and packaged contract, including when a legacy +# observer recipe or DISABLE_DEBUG injects an inherited packet-logging -U. +verify_full_logging_contract() { + local env_name=$1 + local ESP32_FULL_BUILD=$2 + local PACKET_LOGGING_OVERRIDE=$3 + local DISABLE_DEBUG=$4 + local expected=$5 + local combined=$6 + local MESHDEBUG_OVERRIDE=off MQTT_BRIDGE_OVERRIDE="" MQTT_DEBUG_OVERRIDE="" + local FIRMWARE_FILENAME_INFIX="" + local BUILD_PROFILE_FOR_TARGET=full + local -a BUILD_CAPABILITIES=() BUILD_EXPECTATIONS=() BUILD_APPLICATION_EXPECTATIONS=() + local expectations + + configure_unified_full_infrastructure_output "$env_name" + if requires_full_usb_packet_logging "$env_name"; then + [ "$expected" = yes ] || fail "$env_name unexpectedly requires USB logging" + else + [ "$expected" = no ] || fail "$env_name omitted its Full USB logging contract" + fi + declare_build_capability_contract "$env_name" "${PIO_ENV_PLATFORM_BY_NAME[$env_name]}" + expectations=" ${BUILD_APPLICATION_EXPECTATIONS[*]} " + if [ "$expected" = yes ]; then + [[ "$expectations" == *"logging.usb.packets="* ]] \ + || fail "$env_name does not check packet logging in the packaged application" + [[ "$expectations" == *"logging.usb.control="* ]] \ + || fail "$env_name does not check working USB logging controls" + else + [[ "$expectations" != *"logging.usb."* ]] \ + || fail "$env_name promises logging after it was explicitly omitted" + fi + if [ "$combined" = yes ]; then + [[ "$expectations" == *"logging.usb.output=OK - logging.output %s (saved)"* ]] \ + || fail "$env_name does not verify its combined output selector" + else + [[ "$expectations" != *"logging.usb.output="* ]] \ + || fail "$env_name unexpectedly promises a combined output selector" + fi +} + +for logging_target in Station_G2_repeater_observer_mqtt \ + Station_G2_room_server_observer_mqtt heltec_v4_repeater_observer_mqtt \ + heltec_v4_r8_room_server_observer_mqtt; do + verify_full_logging_contract "$logging_target" 1 "" 0 yes yes + verify_full_logging_contract "$logging_target" 1 off 1 yes yes + verify_full_logging_contract "$logging_target" 0 "" 0 no no +done +for logging_target in Station_G2_repeater_bridge_espnow heltec_v4_sensor; do + verify_full_logging_contract "$logging_target" 1 "" 0 yes no + verify_full_logging_contract "$logging_target" 1 on 1 yes no + verify_full_logging_contract "$logging_target" 1 off 0 no no + verify_full_logging_contract "$logging_target" 1 "" 1 no no +done +for logging_target in Station_G2_companion_radio_full RAK_4631_companion_radio_full; do + verify_full_logging_contract "$logging_target" 0 off 1 yes no +done + # Synthetic inventory: one ESP32 target qualified for expanded Full and one # nRF52 target which must attempt complete LoRa OTA in its current partition. SUPPORTED_PIO_ENVS=( diff --git a/test/test_firmware_capabilities.py b/test/test_firmware_capabilities.py index e13bf0783..5d03bb3a7 100644 --- a/test/test_firmware_capabilities.py +++ b/test/test_firmware_capabilities.py @@ -75,6 +75,60 @@ class FirmwareCapabilityCheckerTest(unittest.TestCase): self.assertFalse(manifest["verified"]) self.assertIn("promised", result.stderr) + def test_application_gate_rejects_elf_only_logging_evidence(self): + # Debug/symbol strings in the ELF must not qualify an image whose + # uploadable binary has had the implementation compiled or linked out. + result, manifest = self.run_checker( + b"USB logger", "--expect-application", "logging.usb.packets=USB logger", + artifacts={"firmware-bin": b"no logging implementation"}) + self.assertEqual(result.returncode, 1, result.stderr) + self.assertFalse(manifest["verified"]) + self.assertIn("packaged application", result.stderr) + + def test_application_gate_accepts_packaged_code_without_elf_marker(self): + result, manifest = self.run_checker( + b"stripped symbols", "--expect-application", "logging.usb.packets=USB logger", + artifacts={"firmware-bin": b"USB logger"}) + self.assertEqual(result.returncode, 0, result.stderr) + self.assertTrue(manifest["verified"]) + self.assertIn("logging.usb.packets", manifest["capabilities"]) + self.assertEqual(manifest["verification"][0]["source"], "packaged application") + + def test_full_logging_requires_packet_code_as_well_as_the_setting(self): + expectations = ["--expect-application", "logging.usb.control=usb.logging", + "--expect-application", "logging.usb.packets=packet logger"] + for body, accepted in [(b"usb.logging debug logger", False), + (b"packet logger", False), + (b"usb.logging packet logger", True)]: + with self.subTest(body=body): + result, manifest = self.run_checker(b"", *expectations, + artifacts={"firmware-bin": body}) + self.assertEqual(result.returncode, 0 if accepted else 1, result.stderr) + self.assertEqual(manifest["verified"], accepted) + + def test_application_checks_require_the_installable_artifact(self): + result, manifest = self.run_checker( + b"USB logger", "--expect-application", "logging.usb.packets=USB logger") + self.assertEqual(result.returncode, 2) + self.assertFalse(manifest["verified"]) + self.assertIn("require --firmware-bin or --dfu-package", result.stderr) + + def test_nrf52_logging_is_checked_inside_the_dfu_application(self): + for body, accepted in [(b"packet logger", True), (b"no logger", False)]: + archive = io.BytesIO() + with zipfile.ZipFile(archive, "w") as package: + package.writestr("manifest.json", json.dumps({"manifest": { + "application": {"bin_file": "app.bin"}}})) + package.writestr("app.bin", body) + # A marker elsewhere in the ZIP is not proof of running code. + package.writestr("notes.txt", "packet logger") + result, manifest = self.run_checker( + b"packet logger", "--platform", "NRF52_PLATFORM", + "--expect-application", "logging.usb.packets=packet logger", + artifacts={"dfu-package": archive.getvalue()}) + self.assertEqual(result.returncode, 0 if accepted else 1, result.stderr) + self.assertEqual(manifest["verified"], accepted) + def ota_artifacts(self, *, second_slot=True, image_size=48): def entry(kind, subtype, address, size): return struct.pack("