From 3ba89c60a19a8bfae8a4e446e7ea45175fba5c06 Mon Sep 17 00:00:00 2001 From: jmoore-skild Date: Wed, 29 Jul 2026 15:14:49 -0400 Subject: [PATCH] fix(backup): release the SQLite writer before the K-profile MQTT phase (#2656) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit _apply ran archives and spools first, which autoflushes their INSERTs and so opens SQLite's single write transaction, then called _restore_kprofiles — which awaits get_kprofiles per printer per nozzle at timeout=5.0 with max_retries=3, i.e. up to ~15 s each against a printer that ignores the request. The commit only came afterwards, in run_restore. busy_timeout is 15 s (core/database.py:21), so a restore covering a couple of unresponsive printers held the writer past it and unrelated writes elsewhere in the app failed with "database is locked". Commit the database categories before the MQTT phase starts. The K-profile work is not in that transaction anyway — it leaves over MQTT — so the only thing lost is rolling those categories back when a K-profile send fails, and that rollback was never the right behaviour: extrusion_cali_set has already reached the printer by then, so undoing the database half would just make the two disagree. --- backend/app/services/github_restore.py | 21 +++++++++++ backend/tests/unit/test_github_restore.py | 45 +++++++++++++++++++++++ 2 files changed, 66 insertions(+) diff --git a/backend/app/services/github_restore.py b/backend/app/services/github_restore.py index 52b6f871d..ed256d216 100644 --- a/backend/app/services/github_restore.py +++ b/backend/app/services/github_restore.py @@ -429,6 +429,10 @@ class GitHubRestoreService: } except Exception as e: + # Rolls back whatever is still uncommitted. That is every + # database category unless K-profiles were also selected, in + # which case _apply has already committed them before talking + # to the printers — see the comment there. logger.exception("Restore failed for config %s ref %s", config_id, resolved) await db.rollback() log.status = "failed" @@ -513,6 +517,23 @@ class GitHubRestoreService: # Last, because it leaves the database and publishes over MQTT. if RestoreCategory.KPROFILES in categories: + # Commit the database categories FIRST, and not just for tidiness. + # Everything above has already autoflushed its INSERTs, so SQLite is + # holding the single write transaction — and _restore_kprofiles then + # awaits get_kprofiles per printer per nozzle, which is + # timeout=5.0 * max_retries=3, i.e. up to ~15 s each against an + # unresponsive printer. busy_timeout is 15 s (core/database.py), so a + # farm with a couple of sulking printers would hold the writer past + # it and every concurrent writer in the app would fail with + # "database is locked". + # + # The cost is that a K-profile failure no longer rolls back the + # categories that already succeeded. That is the correct trade + # anyway: extrusion_cali_set has left for the printer by then and + # cannot be rolled back either, so a rollback would only have made + # the database disagree with the hardware. + await db.commit() + self._progress = "Sending K-profiles to printers..." tally = _CategoryTally() await self._restore_kprofiles(db, payload, tally) diff --git a/backend/tests/unit/test_github_restore.py b/backend/tests/unit/test_github_restore.py index e904d704b..12103c0f6 100644 --- a/backend/tests/unit/test_github_restore.py +++ b/backend/tests/unit/test_github_restore.py @@ -1090,6 +1090,51 @@ class TestMutex: assert "restore is currently running" in result["message"] +class TestApplyOrdering: + """_apply must not hold SQLite's write transaction across the MQTT phase.""" + + def _recording_service(self, calls: list[str]): + service = _service() + # Sync side effects on purpose: an AsyncMock returns a coroutine its + # side_effect hands back rather than awaiting it, so an async recorder + # would never run. + service._restore_archives = AsyncMock(side_effect=lambda *a, **k: calls.append("archives")) + service._restore_spools = AsyncMock(side_effect=lambda *a, **k: calls.append("spools")) + service._restore_settings = AsyncMock(side_effect=lambda *a, **k: calls.append("settings")) + service._restore_kprofiles = AsyncMock(side_effect=lambda *a, **k: calls.append("kprofiles")) + return service + + @pytest.mark.asyncio + async def test_commits_database_categories_before_talking_to_printers(self): + """get_kprofiles is 3 x 5 s per printer/nozzle; busy_timeout is 15 s.""" + calls: list[str] = [] + service = self._recording_service(calls) + db = MagicMock() + db.commit = AsyncMock(side_effect=lambda: calls.append("commit")) + + await service._apply( + db, + {}, + [RestoreCategory.ARCHIVES, RestoreCategory.SPOOLS, RestoreCategory.KPROFILES], + False, + ) + + assert calls == ["archives", "spools", "commit", "kprofiles"] + + @pytest.mark.asyncio + async def test_does_not_split_the_transaction_without_kprofiles(self): + """A database-only restore stays one transaction, committed by run_restore.""" + calls: list[str] = [] + service = self._recording_service(calls) + db = MagicMock() + db.commit = AsyncMock(side_effect=lambda: calls.append("commit")) + + await service._apply(db, {}, [RestoreCategory.ARCHIVES, RestoreCategory.SETTINGS], False) + + assert calls == ["archives", "settings"] + assert db.commit.await_count == 0 + + class TestResolveRef: @pytest.mark.asyncio async def test_concrete_sha_passes_through_without_an_api_call(self):