mirror of
https://github.com/maziggy/bambuddy.git
synced 2026-09-30 03:01:21 +02:00
The shape-of-payload dump shipped earlier rules out cache wipes — shaddowlink's round-1 captures show AMS data reaches the slicer byte-identical to what the printer sent. The remaining symptom (picking a generic filament in archive mode "unloads" the slot) lives on the command path, which the snapshot dump doesn't see: it writes only the cached _latest_print_state and the periodic 1Hz push. Add append_event() in _debug.py — same env flag, separate file at <log_dir>/vp_wire/<vp>_cmd.jsonl. One JSONL line per event with UTC iso timestamp, direction (slicer_to_bridge / printer_to_slicer), MQTT topic, <channel>.<command> grep handle, and parsed payload. Wired at two points: mqtt_server._handle_publish for slicer publishes (after JSON decode so the trace matches what the bridge actually parsed) and mqtt_bridge._on_printer_raw "everything else" branch for printer responses (after serial rewrite so the trace matches what the slicer sees on the wire). Pushall / get_version stay out — both are handled locally and never round-trip through the bridge. Bytes payloads get the same \x00-tolerance fix from #927 so OrcaSlicer's C-string-null publishes parse cleanly; un-parseable bytes fall back to {"raw": "..."} so every line stays valid JSON.
207 lines
9.1 KiB
Python
207 lines
9.1 KiB
Python
"""Tests for the env-flagged VP wire-payload dump helper used to triage
|
|
shape-of-payload bugs like #1622."""
|
|
|
|
import json
|
|
import os
|
|
from unittest.mock import patch
|
|
|
|
import pytest
|
|
|
|
from backend.app.core.config import settings as app_settings
|
|
from backend.app.services.virtual_printer import _debug
|
|
|
|
|
|
@pytest.fixture
|
|
def _isolated_log_dir(tmp_path, monkeypatch):
|
|
with patch.object(app_settings, "log_dir", tmp_path):
|
|
yield tmp_path
|
|
|
|
|
|
def test_disabled_by_default_writes_nothing(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.delenv("BAMBUDDY_VP_DUMP_WIRE", raising=False)
|
|
_debug.dump_wire("VP1", "out", {"hello": "world"})
|
|
assert not (_isolated_log_dir / "vp_wire").exists()
|
|
|
|
|
|
def test_enabled_writes_dict_as_pretty_json(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
payload = {"print": {"ams": {"ams": [{"id": 0, "tray": [{"id": 0, "tray_type": "PLA"}]}]}}}
|
|
_debug.dump_wire("Bambuddy P1S", "out", payload)
|
|
out = _isolated_log_dir / "vp_wire" / "Bambuddy_P1S_out.json"
|
|
assert out.is_file()
|
|
assert json.loads(out.read_text()) == payload
|
|
|
|
|
|
def test_overwrites_on_repeat_call(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("VP1", "out", {"v": 1})
|
|
_debug.dump_wire("VP1", "out", {"v": 2})
|
|
out = _isolated_log_dir / "vp_wire" / "VP1_out.json"
|
|
assert json.loads(out.read_text()) == {"v": 2}
|
|
|
|
|
|
def test_separate_files_per_direction(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("VP1", "in", {"src": "printer"})
|
|
_debug.dump_wire("VP1", "out", {"src": "slicer"})
|
|
assert (_isolated_log_dir / "vp_wire" / "VP1_in.json").is_file()
|
|
assert (_isolated_log_dir / "vp_wire" / "VP1_out.json").is_file()
|
|
|
|
|
|
def test_sanitizes_path_traversal_in_vp_name(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("../../etc/passwd", "out", {"x": 1})
|
|
vp_wire = _isolated_log_dir / "vp_wire"
|
|
files = list(vp_wire.glob("*"))
|
|
assert len(files) == 1
|
|
# The actual safety property: the written file is inside vp_wire/.
|
|
# `..` as a substring of a single filename component is harmless because
|
|
# the path separator (/) is collapsed to _ before construction.
|
|
assert files[0].resolve().parent == vp_wire.resolve()
|
|
assert "/" not in files[0].name
|
|
|
|
|
|
def test_empty_vp_name_falls_back_to_default(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("", "out", {"x": 1})
|
|
assert (_isolated_log_dir / "vp_wire" / "vp_out.json").is_file()
|
|
|
|
|
|
def test_bytes_payload_decoded(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("VP1", "in", b'{"raw": true}')
|
|
out = _isolated_log_dir / "vp_wire" / "VP1_in.json"
|
|
assert out.read_text() == '{"raw": true}'
|
|
|
|
|
|
def test_unwritable_dir_is_swallowed(_isolated_log_dir, monkeypatch):
|
|
"""A debug-instrumentation failure must not crash the bridge or 1Hz loop."""
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
# Point log_dir at a location that mkdir refuses (a regular file occupying
|
|
# the path). Failure must be swallowed.
|
|
blocker = _isolated_log_dir / "blocker"
|
|
blocker.write_text("not a dir")
|
|
with patch.object(app_settings, "log_dir", blocker):
|
|
_debug.dump_wire("VP1", "out", {"x": 1}) # must not raise
|
|
|
|
|
|
@pytest.mark.parametrize("flag_value", ["0", "false", "off", "", "no"])
|
|
def test_falsy_flag_values_disable(_isolated_log_dir, monkeypatch, flag_value):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", flag_value)
|
|
_debug.dump_wire("VP1", "out", {"x": 1})
|
|
assert not (_isolated_log_dir / "vp_wire").exists()
|
|
|
|
|
|
@pytest.mark.parametrize("flag_value", ["1", "true", "TRUE", "yes", "on", "On"])
|
|
def test_truthy_flag_values_enable(_isolated_log_dir, monkeypatch, flag_value):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", flag_value)
|
|
_debug.dump_wire("VP1", "out", {"x": 1})
|
|
assert (_isolated_log_dir / "vp_wire" / "VP1_out.json").is_file()
|
|
|
|
|
|
def test_idempotent_atomic_no_partial_file_visible(_isolated_log_dir, monkeypatch):
|
|
"""tmp+rename pattern means a reader never sees a half-written .json file."""
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.dump_wire("VP1", "out", {"x": 1})
|
|
files = sorted(p.name for p in (_isolated_log_dir / "vp_wire").iterdir())
|
|
# No leftover .tmp file after a successful write.
|
|
assert files == ["VP1_out.json"]
|
|
|
|
|
|
def test_env_check_is_per_call_not_module_load(_isolated_log_dir, monkeypatch):
|
|
"""Flag toggle must take effect on the next call without restarting; we
|
|
re-read the env var inside ``dump_wire`` rather than caching at import."""
|
|
monkeypatch.delenv("BAMBUDDY_VP_DUMP_WIRE", raising=False)
|
|
_debug.dump_wire("VP1", "out", {"v": 1})
|
|
assert not (_isolated_log_dir / "vp_wire").exists()
|
|
|
|
os.environ["BAMBUDDY_VP_DUMP_WIRE"] = "1"
|
|
try:
|
|
_debug.dump_wire("VP1", "out", {"v": 2})
|
|
assert (_isolated_log_dir / "vp_wire" / "VP1_out.json").is_file()
|
|
finally:
|
|
os.environ.pop("BAMBUDDY_VP_DUMP_WIRE", None)
|
|
|
|
|
|
# --- append_event (command-flow trace) --------------------------------------
|
|
|
|
|
|
def _read_jsonl(path):
|
|
return [json.loads(line) for line in path.read_text().splitlines() if line.strip()]
|
|
|
|
|
|
def test_append_event_disabled_by_default_writes_nothing(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.delenv("BAMBUDDY_VP_DUMP_WIRE", raising=False)
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", {"hello": "world"})
|
|
assert not (_isolated_log_dir / "vp_wire").exists()
|
|
|
|
|
|
def test_append_event_appends_one_jsonl_line_per_call(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", {"print": {"command": "ams_filament_setting"}})
|
|
_debug.append_event(
|
|
"VP1", "printer_to_slicer", "device/X/report", {"print": {"command": "ams_filament_setting", "result": "ok"}}
|
|
)
|
|
path = _isolated_log_dir / "vp_wire" / "VP1_cmd.jsonl"
|
|
rows = _read_jsonl(path)
|
|
assert len(rows) == 2
|
|
assert rows[0]["dir"] == "slicer_to_bridge"
|
|
assert rows[0]["topic"] == "device/X/request"
|
|
assert rows[0]["cmd"] == "print.ams_filament_setting"
|
|
assert rows[0]["payload"] == {"print": {"command": "ams_filament_setting"}}
|
|
assert rows[1]["dir"] == "printer_to_slicer"
|
|
assert rows[1]["cmd"] == "print.ams_filament_setting"
|
|
|
|
|
|
def test_append_event_parses_bytes_payload(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
raw = b'{"info": {"command": "get_version", "sequence_id": "0"}}'
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", raw)
|
|
rows = _read_jsonl(_isolated_log_dir / "vp_wire" / "VP1_cmd.jsonl")
|
|
assert rows[0]["payload"] == {"info": {"command": "get_version", "sequence_id": "0"}}
|
|
assert rows[0]["cmd"] == "info.get_version"
|
|
|
|
|
|
def test_append_event_unparseable_payload_kept_as_raw(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.append_event("VP1", "printer_to_slicer", "device/X/report", b"not-json-just-bytes")
|
|
rows = _read_jsonl(_isolated_log_dir / "vp_wire" / "VP1_cmd.jsonl")
|
|
assert rows[0]["payload"] == {"raw": "not-json-just-bytes"}
|
|
assert rows[0]["cmd"] == "?"
|
|
|
|
|
|
def test_append_event_handles_trailing_null_from_orca(_isolated_log_dir, monkeypatch):
|
|
"""Same #927 quirk as ``_handle_publish``: OrcaSlicer can ship publishes with a
|
|
trailing C-string null. The trace must still parse so the dump matches what
|
|
the bridge actually saw, not raw text."""
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", b'{"info":{"command":"get_version"}}\x00')
|
|
rows = _read_jsonl(_isolated_log_dir / "vp_wire" / "VP1_cmd.jsonl")
|
|
assert rows[0]["payload"] == {"info": {"command": "get_version"}}
|
|
|
|
|
|
def test_append_event_sanitizes_vp_name(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.append_event("../../etc/passwd", "slicer_to_bridge", "device/X/request", {"x": 1})
|
|
files = list((_isolated_log_dir / "vp_wire").glob("*_cmd.jsonl"))
|
|
assert len(files) == 1
|
|
assert "/" not in files[0].name
|
|
|
|
|
|
def test_append_event_includes_iso_timestamp(_isolated_log_dir, monkeypatch):
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", {"x": 1})
|
|
rows = _read_jsonl(_isolated_log_dir / "vp_wire" / "VP1_cmd.jsonl")
|
|
ts = rows[0]["ts"]
|
|
# ISO-8601 with timezone (Z or +00:00 suffix from UTC).
|
|
assert "T" in ts and (ts.endswith("+00:00") or ts.endswith("Z"))
|
|
|
|
|
|
def test_append_event_failure_swallowed(_isolated_log_dir, monkeypatch):
|
|
"""Debug instrumentation must never crash the bridge or slicer loop."""
|
|
monkeypatch.setenv("BAMBUDDY_VP_DUMP_WIRE", "1")
|
|
blocker = _isolated_log_dir / "blocker"
|
|
blocker.write_text("not a dir")
|
|
with patch.object(app_settings, "log_dir", blocker):
|
|
_debug.append_event("VP1", "slicer_to_bridge", "device/X/request", {"x": 1}) # must not raise
|