Browse Source

fix(diagnostics): name the stalled step when a bundle's connection check times out (issue #3164)

The support bundle gives each printer's connection diagnostic 15 s and
discarded the whole result on overrun, recording only "timed_out". A
14-printer farm's bundle carried that marker for every printer and
nothing else, so it could not say which check was slow.

run_connection_diagnostic now keeps an optional progress dict current
(finished checks + the step in flight). On timeout the snapshot records
stalled_in, elapsed_s and the checks that completed.
maziggy 2 days ago
parent
commit
a36c0009a5

File diff suppressed because it is too large
+ 1 - 0
CHANGELOG.md


+ 14 - 1
backend/app/services/diagnostic_snapshot.py

@@ -22,6 +22,7 @@ from __future__ import annotations
 import asyncio
 import logging
 import re
+import time
 from typing import Any
 
 from sqlalchemy import select
@@ -54,6 +55,8 @@ async def _run_connection_for(printer) -> dict:
     from backend.app.services.printer_diagnostic import run_connection_diagnostic
 
     base = {"printer_id": printer.id, "printer_name": printer.name}
+    progress: dict[str, Any] = {}
+    started = time.monotonic()
     try:
         result = await asyncio.wait_for(
             run_connection_diagnostic(
@@ -61,12 +64,22 @@ async def _run_connection_for(printer) -> dict:
                 printer=printer,
                 serial_number=printer.serial_number,
                 access_code=printer.access_code,
+                progress=progress,
             ),
             timeout=_PER_DIAGNOSTIC_TIMEOUT_SECONDS,
         )
         return {**base, "result": _serialize(result)}
     except asyncio.TimeoutError:
-        return {**base, "error": "timed_out"}
+        # Name the step that hung and keep the checks that finished before it.
+        # Without them a bundle from a farm whose every printer overran said
+        # only "timed_out" fourteen times, and nothing about why (#3164).
+        return {
+            **base,
+            "error": "timed_out",
+            "stalled_in": progress.get("stage"),
+            "elapsed_s": round(time.monotonic() - started, 1),
+            "checks": [_serialize(c) for c in progress.get("checks", [])],
+        }
     except Exception as e:
         # Log with traceback so the bundle generation isn't silent about
         # a broken probe, but never propagate.

+ 18 - 0
backend/app/services/printer_diagnostic.py

@@ -413,6 +413,7 @@ async def run_connection_diagnostic(
     serial_number: str | None = None,
     access_code: str | None = None,
     wait_for_publish_seconds: float = 0.0,
+    progress: dict | None = None,
 ) -> PrinterDiagnosticResult:
     """Run connection checks for a printer.
 
@@ -422,10 +423,20 @@ async def run_connection_diagnostic(
     Each check carries a stable ``id`` and a ``status`` of
     pass / fail / warn / skip; the frontend renders the human-readable
     title and fix text (localized) keyed on that id + status.
+
+    ``progress``, when given, is kept current while the checks run: its
+    ``checks`` key is the list of finished checks and ``stage`` names the step
+    in flight. The support bundle cancels a run that overruns its budget, and
+    this is how it can still say which step hung and keep what finished --
+    a bare "timed out" for every printer is all #3164's bundle could show.
     """
     checks: list[DiagnosticCheck] = []
+    if progress is None:
+        progress = {}
+    progress["checks"] = checks
 
     # --- Port reachability (probed in parallel) ---
+    progress["stage"] = "ports"
     camera_port, camera_protocol = _camera_port_for_printer(printer)
     mqtt_ok, ftps_state, camera_ok = await asyncio.gather(
         _check_port(ip_address, PORT_MQTT),
@@ -452,6 +463,7 @@ async def run_connection_diagnostic(
     )
 
     # --- macOS Local Network permission ---
+    progress["stage"] = "macos_local_network"
     # Appended on macOS only. Everywhere else there is nothing to say, and a
     # permanently dimmed "skipped" row would be noise for the users who make
     # up nearly all of them.
@@ -485,6 +497,7 @@ async def run_connection_diagnostic(
                 checks.append(DiagnosticCheck(id="macos_local_network", status="warn", params={"reason": "permission"}))
 
     # --- Container network mode ---
+    progress["stage"] = "network_mode"
     # Not Docker-only: Podman runs Bambuddy in exactly the same two shapes and
     # its users were told "Not running in Docker", which reads as "you are on
     # bare metal" and sent them looking for the problem somewhere else (#3092).
@@ -514,6 +527,7 @@ async def run_connection_diagnostic(
             )
 
     # --- Subnet match ---
+    progress["stage"] = "subnet"
     # Skipped in bridge mode: the container IP is the bridge IP, not the host's,
     # so the comparison is meaningless and the network_mode check already covers it.
     if network_mode == "bridge":
@@ -534,6 +548,7 @@ async def run_connection_diagnostic(
             )
 
     # --- External storage (printer-side "Store sent files on external storage") ---
+    progress["stage"] = "external_storage"
     # Install step 4. The setting has two variants depending on
     # firmware/slicer combo: on newer firmware the toggle lives on the
     # printer (P2S 01.02 / BambuStudio 2.6+), on older versions it's
@@ -632,6 +647,7 @@ async def run_connection_diagnostic(
         checks.append(DiagnosticCheck(id="external_storage", status="skip"))
 
     # --- MQTT credentials / connection ---
+    progress["stage"] = "mqtt_auth"
     if not mqtt_ok:
         # Can't reach the broker at all — the port check already reported it.
         checks.append(DiagnosticCheck(id="mqtt_auth", status="skip"))
@@ -671,6 +687,7 @@ async def run_connection_diagnostic(
         checks.append(DiagnosticCheck(id="mqtt_auth", status="skip"))
 
     # --- LAN developer mode (only readable over a live MQTT connection) ---
+    progress["stage"] = "developer_mode"
     if state is not None and state.connected:
         if state.developer_mode is True:
             dev_status = "pass"
@@ -683,6 +700,7 @@ async def run_connection_diagnostic(
         checks.append(DiagnosticCheck(id="developer_mode", status="skip"))
 
     # --- Printer is actually publishing on its report topic ---
+    progress["stage"] = "printer_publishing"
     # The mqtt_auth check above only proves TCP + TLS + auth + SUBSCRIBE
     # succeed. A printer with a wrong-cased serial — or one that simply isn't
     # publishing for some other reason — still passes mqtt_auth because the

+ 77 - 0
backend/tests/unit/test_diagnostic_snapshot.py

@@ -159,6 +159,83 @@ async def test_snapshot_emits_timed_out_marker_when_probe_exceeds_cap():
     assert out["connection_diagnostics"][0]["error"] == "timed_out"
 
 
+@pytest.mark.asyncio
+async def test_timed_out_entry_names_the_stalled_step_and_keeps_finished_checks():
+    """#3164: every printer of a 14-printer farm came back as a bare
+    `timed_out`, so the bundle could not say which step hung. The real
+    diagnostic runs here with the ports answering and the subnet lookup
+    hanging; the entry must name `subnet` and carry the port checks that
+    finished before it."""
+    import time as _time
+
+    printers = [
+        SimpleNamespace(
+            id=1,
+            name="A1",
+            model="A1",
+            ip_address="10.0.0.5",
+            serial_number="s",
+            access_code="a",
+        )
+    ]
+    db = _make_db_with_printers_and_vps(printers, [])
+
+    def hanging_subnet(*_a, **_k):
+        _time.sleep(1.0)  # blocks its worker thread well past the cap below
+        return True
+
+    with (
+        patch("backend.app.services.printer_diagnostic._check_port", new=AsyncMock(return_value=True)),
+        patch("backend.app.services.printer_diagnostic._check_ftps_tls", new=AsyncMock(return_value="ok")),
+        patch("backend.app.services.printer_diagnostic.detect_container_runtime", return_value=None),
+        patch("backend.app.services.printer_diagnostic._host_source_ip", return_value="10.0.0.2"),
+        patch("backend.app.services.printer_diagnostic._same_subnet", side_effect=hanging_subnet),
+        patch("backend.app.services.diagnostic_snapshot._PER_DIAGNOSTIC_TIMEOUT_SECONDS", 0.2),
+        patch(
+            "backend.app.services.diagnostic_snapshot._run_log_health",
+            new=AsyncMock(return_value={"findings": []}),
+        ),
+    ):
+        out = await collect_diagnostic_snapshot(db)
+
+    entry = out["connection_diagnostics"][0]
+    assert entry["error"] == "timed_out"
+    assert entry["stalled_in"] == "subnet"
+    assert 0.1 <= entry["elapsed_s"] < 1.0
+    finished = {c["id"]: c["status"] for c in entry["checks"]}
+    assert finished["port_mqtt"] == "pass"
+    assert finished["port_ftps"] == "pass"
+    assert finished["network_mode"] == "skip"
+    assert "subnet" not in finished
+
+
+@pytest.mark.asyncio
+async def test_timed_out_entry_without_progress_still_has_the_marker():
+    """A diagnostic that hangs before recording anything still yields the
+    marker with an empty check list rather than a KeyError."""
+    printers = [SimpleNamespace(id=1, name="slow", ip_address="1.1.1.1", serial_number="s", access_code="a")]
+    db = _make_db_with_printers_and_vps(printers, [])
+
+    async def hang(*a, **k):
+        import asyncio
+
+        await asyncio.sleep(5)
+
+    with (
+        patch("backend.app.services.printer_diagnostic.run_connection_diagnostic", new=AsyncMock(side_effect=hang)),
+        patch("backend.app.services.diagnostic_snapshot._PER_DIAGNOSTIC_TIMEOUT_SECONDS", 0.05),
+        patch(
+            "backend.app.services.diagnostic_snapshot._run_log_health",
+            new=AsyncMock(return_value={"findings": []}),
+        ),
+    ):
+        out = await collect_diagnostic_snapshot(db)
+
+    entry = out["connection_diagnostics"][0]
+    assert entry["stalled_in"] is None
+    assert entry["checks"] == []
+
+
 @pytest.mark.asyncio
 async def test_snapshot_masks_ip_addresses_in_all_diagnostic_fields():
     """The diagnostic schemas embed raw IPv4 in three places — the top-level

Some files were not shown because too many files changed in this diff