fix(vp): re-fire FINISH after project_file ack so slicer releases (#1658)

  Reporter on Bambu Studio 2.7.1.57 + X1C saw the Send modal stuck at
  "Downloading" after sending to a Queue-mode VP. Delete-from-queue and
  even Auto-Dispatch ON + a successful real print didn't release it.

  Root cause: BS 2.7.x flipped the Send sequence from
    MQTT project_file -> FTP upload -> done
  to
    FTP verify_job -> FTP .3mf -> MQTT project_file.

  The #1280 fix sets gcode_state=FINISH in on_file_received (after the
  FTP upload). Under the new order, the synthetic project_file ack in
  _send_print_response then runs and overwrites _gcode_state back to
  PREPARE. The 1 Hz cached-as-base push stream carries PREPARE forever,
  the slicer never sees the FINISH transition it waits for, and the
  modal sits stuck. Auto-Dispatch ON shares the cause: the real
  printer's PREPARE->RUNNING->FINISH on the bridge gets masked by the
  local _gcode_state override in _send_status_report.

  Re-fire set_gcode_state("FINISH", filename, prepare_percent="100")
  1.5 s after the project_file ack for every non-proxy mode (queue /
  archive / review). The 1.5 s window lets the slicer see at least one
  PREPARE push on the 1 Hz cycle so the transition reads as
  PREPARE -> FINISH, matching what the slicer expects. Proxy mode is
  exempt -- there the real printer drives the bridge state and a
  synthetic FINISH would clobber a real PREPARE/RUNNING transition.

  The scheduler cancels any in-flight timer when a new project_file
  arrives so a retrying slicer doesn't end with two competing FINISH
  timers. The pending timer is also cancelled on stop_server.

backend/app/services/virtual_printer/manager.py

@@ -14,6 +14,7 @@ from typing import TYPE_CHECKING
 from backend.app.core.config import settings as app_settings
 from backend.app.models.virtual_printer import (
     VP_MODE_ARCHIVE,
+    VP_MODE_PROXY,
     VP_MODE_QUEUE,
     normalize_vp_mode,
 )
@@ -204,6 +205,10 @@ class VirtualPrinterInstance:
         self._ssdp_proxy: SSDPProxy | None = None
         self._tasks: list[asyncio.Task] = []
 
+        # Pending timer that re-fires gcode_state=FINISH after a project_file
+        # ack. See ``_schedule_finish_release`` for the #1658 rationale.
+        self._finish_release_task: asyncio.Task | None = None
+
     @property
     def serial(self) -> str:
         """Full serial number for this virtual printer."""
@@ -285,9 +290,17 @@ class VirtualPrinterInstance:
         modes ignore the print command, so we skip the stash there to keep
         the dict from accumulating one entry per print over the VP's
         uptime.
+
+        Also schedules the #1658 follow-up that re-fires gcode_state=FINISH a
+        moment after the synthetic project_file ack — for every non-proxy
+        mode — so the slicer's "Downloading" UI releases on the slicer's
+        FTP-first-then-MQTT send order.
         """
         logger.info("[VP %s] Print command for: %s", self.name, filename)
-        if normalize_vp_mode(self.mode) != VP_MODE_QUEUE:
+        mode = normalize_vp_mode(self.mode)
+        if mode != VP_MODE_PROXY and filename and self._mqtt is not None:
+            self._schedule_finish_release(filename)
+        if mode != VP_MODE_QUEUE:
             return
         # Drop the oldest stash if the cache is growing — happens when the
         # slicer sends project_file for a filename whose FTP upload was
@@ -307,6 +320,48 @@ class VirtualPrinterInstance:
         if event:
             event.set()
 
+    def _schedule_finish_release(self, filename: str, delay: float = 1.5) -> None:
+        """Re-set gcode_state=FINISH on the VP after the project_file ack.
+
+        #1280 set FINISH after the FTP upload completes — that was correct
+        for the slicer flow at the time (MQTT project_file → FTP → done).
+        Bambu Studio 2.7.x flipped the order to FTP → FTP → MQTT project_file,
+        which means ``_send_print_response`` runs *after* the FINISH set in
+        ``on_file_received`` and overwrites the state back to PREPARE. The
+        slicer's 1 Hz status stream then carries PREPARE forever and the
+        send modal sits at "Downloading" until the VP is restarted (#1658).
+
+        Re-firing FINISH after a short delay closes the gap: the slicer sees
+        the synthetic PREPARE in the project_file ack (and likely one PREPARE
+        push on the 1 Hz cycle), then the next push carries FINISH and the
+        modal releases. Proxy mode is exempt — there the real printer drives
+        the state through the bridge and a synthetic FINISH would clobber a
+        real PREPARE/RUNNING transition coming back from the printer.
+
+        Cancels any in-flight timer before scheduling a new one so a slicer
+        that fires project_file twice in quick succession only ends in one
+        FINISH.
+        """
+        if self._mqtt is None:
+            return
+        if self._finish_release_task is not None and not self._finish_release_task.done():
+            self._finish_release_task.cancel()
+        self._finish_release_task = asyncio.create_task(
+            self._delayed_finish_release(filename, delay),
+            name=f"vp-{self.id}-finish-release",
+        )
+
+    async def _delayed_finish_release(self, filename: str, delay: float) -> None:
+        """Sleep, then set gcode_state=FINISH. Used by ``_schedule_finish_release``."""
+        try:
+            await asyncio.sleep(delay)
+        except asyncio.CancelledError:
+            return
+        if self._mqtt is None:
+            return
+        self._mqtt.set_gcode_state("FINISH", filename=filename, prepare_percent="100")
+        logger.debug("[VP %s] Re-set gcode_state=FINISH after project_file ack (%s)", self.name, filename)
+
     async def _archive_file(self, file_path: Path, source_ip: str) -> None:
         """Archive file immediately."""
         if not self._session_factory:
@@ -832,6 +887,9 @@ class VirtualPrinterInstance:
 
     async def stop_server(self) -> None:
         """Stop server-mode services."""
+        if self._finish_release_task is not None and not self._finish_release_task.done():
+            self._finish_release_task.cancel()
+            self._finish_release_task = None
         if self._mqtt_bridge:
             try:
                 await self._mqtt_bridge.stop()

backend/tests/unit/services/test_virtual_printer.py

@@ -206,6 +206,104 @@ class TestVirtualPrinterInstance:
 
         instance._mqtt.set_gcode_state.assert_not_called()
 
+    @pytest.mark.asyncio
+    async def test_on_print_command_schedules_finish_release_non_proxy(self, instance):
+        """#1658: Bambu Studio 2.7.x flipped the slicer's Send flow to
+        FTP → FTP → MQTT project_file. Under that order the synthetic
+        project_file ack overwrites the FINISH set by #1280 in
+        ``on_file_received`` back to PREPARE, leaving the slicer's
+        "Downloading" modal stuck forever. Re-firing FINISH a moment after
+        the ack releases the modal.
+        """
+        instance.mode = "archive"
+        instance._mqtt = MagicMock()
+        instance._mqtt.set_gcode_state = MagicMock()
+
+        with patch.object(instance, "_delayed_finish_release", new_callable=AsyncMock) as mock_delayed:
+            await instance.on_print_command("test.3mf", {"command": "project_file"})
+
+        mock_delayed.assert_called_once()
+        # First positional arg should be the filename; second is the delay seconds.
+        args = mock_delayed.call_args.args
+        assert args[0] == "test.3mf"
+        assert isinstance(args[1], int | float)
+
+    @pytest.mark.asyncio
+    async def test_on_print_command_proxy_mode_does_not_reschedule_finish(self, instance):
+        """Proxy mode hands push_status straight from the real printer through
+        the bridge. Re-firing a synthetic FINISH would clobber a real
+        PREPARE / RUNNING transition coming back from the printer, so the
+        scheduler is exempt for proxy mode."""
+        instance.mode = "proxy"
+        instance._mqtt = MagicMock()
+
+        with patch.object(instance, "_delayed_finish_release", new_callable=AsyncMock) as mock_delayed:
+            await instance.on_print_command("test.3mf", {"command": "project_file"})
+
+        mock_delayed.assert_not_called()
+
+    @pytest.mark.asyncio
+    async def test_on_print_command_no_mqtt_does_not_schedule(self, instance):
+        """If the MQTT server isn't running yet (transient race during boot),
+        the scheduler must skip silently — no AttributeError, no orphan task."""
+        instance.mode = "queue"
+        instance._mqtt = None
+
+        # Should not raise.
+        await instance.on_print_command("test.3mf", {"command": "project_file"})
+        assert instance._finish_release_task is None
+
+    @pytest.mark.asyncio
+    async def test_schedule_finish_release_cancels_previous_timer(self, instance):
+        """A slicer that fires project_file twice (e.g. retry after a transient
+        FTP hiccup) must only result in one FINISH transition — the earlier
+        in-flight timer is cancelled when the next one is scheduled."""
+        instance.mode = "queue"
+        instance._mqtt = MagicMock()
+
+        instance._schedule_finish_release("first.3mf", delay=10.0)
+        first_task = instance._finish_release_task
+        assert first_task is not None
+
+        instance._schedule_finish_release("second.3mf", delay=10.0)
+        second_task = instance._finish_release_task
+
+        assert second_task is not first_task
+        # Give the loop one tick so the cancelled task settles.
+        await asyncio.sleep(0)
+        assert first_task.cancelled() or first_task.done()
+        # Clean up the still-pending second task so the test doesn't leak it.
+        second_task.cancel()
+        try:
+            await second_task
+        except asyncio.CancelledError:
+            pass
+
+    @pytest.mark.asyncio
+    async def test_delayed_finish_release_sets_finish_state(self, instance):
+        """End-to-end: after the delay elapses, set_gcode_state is called with
+        FINISH and prepare_percent=100, matching the wire-format the slicer's
+        Print flow consumes to release "Downloading"."""
+        instance._mqtt = MagicMock()
+        instance._mqtt.set_gcode_state = MagicMock()
+
+        await instance._delayed_finish_release("queued.3mf", delay=0.0)
+
+        instance._mqtt.set_gcode_state.assert_called_once_with("FINISH", filename="queued.3mf", prepare_percent="100")
+
+    @pytest.mark.asyncio
+    async def test_on_print_command_no_filename_does_not_schedule(self, instance):
+        """A project_file command without a subtask_name (defensive — real
+        slicers always send one) must not schedule a no-op FINISH that would
+        carry an empty filename on the next 1 Hz push."""
+        instance.mode = "queue"
+        instance._mqtt = MagicMock()
+
+        with patch.object(instance, "_delayed_finish_release", new_callable=AsyncMock) as mock_delayed:
+            await instance.on_print_command("", {"command": "project_file"})
+
+        mock_delayed.assert_not_called()
+
     @pytest.mark.asyncio
     async def test_archive_file_skips_non_3mf(self, instance):
         """Verify non-3MF files are skipped and cleaned up."""