fix(backup): report the rows a failed K-profile step already committed (#2656)

`_apply` commits the database categories before the K-profile phase, and the
comment there is right about why: `get_kprofiles` is 3 x 5 s per printer per
nozzle and SQLite's `busy_timeout` is 15 s, so holding the writer across the
MQTT phase would fail every concurrent writer in the app.

But `run_restore`'s handler returns `{"success": False, ..., "results": {}}`
for anything raised after that point, and the per-call guards inside
`_restore_kprofiles` do not cover the whole phase. Two consequences, and the
second is worse:

* The user is told the restore failed and handed an empty `results` while the
  archive, spool and settings rows are durable on disk. The honest-reporting
  theme this whole feature is built on inverted on exactly the path where it
  matters most.
* `_reconfigure_mqtt_relay` sits inside the same `try`, downstream of the
  raise. A restore that rewrote the mqtt_* rows left the relay pointed at the
  pre-restore broker until something else reconfigured it.

`_apply` now contains the K-profile phase: fold the error into that category's
tally as `failed` plus a `kprofilesStepFailed` note, and let the results it has
already committed be returned and reported. Every profile the payload carried
and the phase did not account for is counted failed — silence would have been
the same lie in a smaller font. `_reconfigure_mqtt_relay` is reached again
because `_apply` returns normally. The rollback in the handler discards only
the phase's own read transaction, so a database error cannot leave the session
in a state that turns the caller's commit into the very report this prevents.

`kprofilesSendFailed` was the obvious note to reuse and is the wrong one: it
names a nozzle, a printer and a serial that a phase-level failure does not
have, and "failed to send" is untrue of a step that never got as far as
sending. One new leaf x 13 locales instead.

Belt-and-braces on the trigger that found this:
`sum(len(c.get("profiles") or []) ...)` raises TypeError on a hand-edited or
truncated backup whose `profiles` is not a list, and it runs before the guards.
Counting defensively makes that a skipped category rather than an exception
thrown over committed rows.

Control kept explicit: a failure *before* the commit still rolls back, still
reports nothing restored, and still does not touch the relay.

Tests: +5 (280 -> 285 across the three restore files, 328 -> 337 across
`-k github`). Fail-pre-fix 4 — 3 for the containment, 1 for the defensive
count, checked separately. i18n parity 13 locales at 5771 leaves.

Bundle rebuilt for the new leaf: index-CHCEEMgx.js -> index-DhOfNgMz.js. CSS
hash unchanged.
This commit is contained in:
jmoore-skild
2026-08-04 08:57:34 -04:00
parent 0be6ccd090
commit 3bb087db54
17 changed files with 205 additions and 77 deletions
+44 -2
View File
@@ -858,7 +858,32 @@ class GitHubRestoreService:
self._progress = "Sending K-profiles to printers..."
tally = _CategoryTally()
await self._restore_kprofiles(db, payload, tally)
try:
await self._restore_kprofiles(db, payload, tally)
except Exception as e:
# Everything above is committed and cannot be un-committed, so
# letting this reach run_restore's handler would report
# "nothing was restored" over durable archive, spool and
# settings rows — and skip the post-commit MQTT reconfigure,
# leaving the relay on the pre-restore broker. The K-profile
# phase is the last thing that runs, so containing it here is
# what keeps the result honest about what actually landed.
logger.exception("The K-profile step failed after the database categories were committed")
# Discards the phase's own read transaction. The rows above went
# in at the commit two statements up; this only stops a session
# left in a failed state by a database error from turning the
# caller's commit into that same false report.
await db.rollback()
outstanding = self._kprofile_profile_count(
content for path, content in payload.items() if _KPROFILE_PATH_RE.match(path)
)
outstanding -= tally.restored + tally.skipped + tally.failed
tally.failed += max(outstanding, 0)
tally.note(
"kprofilesStepFailed",
f"The K-profile step could not be completed: {e}",
reason=str(e)[:200],
)
results[RestoreCategory.KPROFILES.value] = tally
return results
@@ -1482,7 +1507,7 @@ class GitHubRestoreService:
)
for serial, entries in sorted(by_serial.items()):
profile_total = sum(len(c.get("profiles") or []) for _, c in entries)
profile_total = self._kprofile_profile_count(c for _, c in entries)
printer = printers.get(serial)
if printer is None:
@@ -1604,6 +1629,23 @@ class GitHubRestoreService:
reason=detail,
)
@staticmethod
def _kprofile_profile_count(contents) -> int:
"""Count the profiles across parsed K-profile files.
Defensive on purpose. A hand-edited or truncated backup can carry a
``profiles`` value that is not a list, and this count runs *before* the
per-call guards in the loop below — after ``_apply`` has already
committed the database categories. A malformed file has to be a skipped
category, not an exception thrown over committed rows.
"""
total = 0
for content in contents:
profiles = content.get("profiles") if isinstance(content, dict) else None
if isinstance(profiles, list):
total += len(profiles)
return total
@staticmethod
async def _kprofile_ack(client, seq: str, serial: str, nozzle: str) -> tuple[bool, str]:
"""Read the printer's verdict on one batch write.
+134
View File
@@ -2322,6 +2322,140 @@ class TestApplyOrdering:
assert db.commit.await_count == 0
class TestKprofilePhaseFailure:
"""The K-profile phase runs after _apply has committed everything else.
So an exception there used to reach run_restore's handler, which reports
``success: False`` with an empty ``results`` — over archive, spool and
settings rows that are durable on disk. The honest-reporting theme of this
feature inverted on exactly the path where it matters, and the post-commit
MQTT reconfigure (downstream of the raise, inside the same try) was skipped,
leaving the relay pointed at the pre-restore broker.
"""
_SETTINGS = {"version": "1.0", "settings": {"mqtt_broker": "restored.local", "currency": "EUR"}}
def _payload(self, profiles=None):
return {
SETTINGS_PATH: dict(self._SETTINGS),
"kprofiles/00M09A123456789/0.4.json": {
"profiles": [{"filament_id": "GFA00", "name": "Bambu PLA"}] if profiles is None else profiles
},
}
def _session_patch(self, db_session):
cm = AsyncMock()
cm.__aenter__ = AsyncMock(return_value=db_session)
cm.__aexit__ = AsyncMock(return_value=None)
return patch("backend.app.services.github_restore.async_session", return_value=cm)
async def _configured_service(self, db_session, payload):
from backend.app.models.github_backup import GitHubBackupConfig
config = GitHubBackupConfig(repository_url="https://github.com/o/r", access_token="tok", provider="github")
db_session.add(config)
await db_session.commit()
service = _service()
service._resolve_ref = AsyncMock(return_value=("a" * 40, "", None))
service._read_categories = AsyncMock(return_value=(payload, ""))
return service, config.id
@pytest.mark.asyncio
async def test_the_committed_categories_are_still_reported(self, db_session):
service = _service()
service._restore_kprofiles = AsyncMock(side_effect=RuntimeError("mqtt exploded"))
results = await service._apply(
db_session,
self._payload(),
[RestoreCategory.SETTINGS, RestoreCategory.KPROFILES],
False,
)
assert results[RestoreCategory.SETTINGS.value].restored == 2
rows = {s.key: s.value for s in (await db_session.execute(select(Settings))).scalars().all()}
assert rows == {"mqtt_broker": "restored.local", "currency": "EUR"}, "committed before the phase that failed"
@pytest.mark.asyncio
async def test_the_failure_is_counted_and_explained(self, db_session):
service = _service()
service._restore_kprofiles = AsyncMock(side_effect=RuntimeError("mqtt exploded"))
results = await service._apply(
db_session,
self._payload(profiles=[{"filament_id": "GFA00"}, {"filament_id": "GFB99"}]),
[RestoreCategory.SETTINGS, RestoreCategory.KPROFILES],
False,
)
tally = results[RestoreCategory.KPROFILES.value]
assert tally.failed == 2, "every profile the payload carried is unaccounted for"
assert tally.restored == 0
assert _codes(tally) == ["kprofilesStepFailed"]
assert tally.notes[0]["params"]["reason"] == "mqtt exploded"
@pytest.mark.asyncio
async def test_the_relay_is_reconfigured_even_though_the_phase_failed(self, db_session):
"""The reconfigure sits downstream of the raise in run_restore's try."""
service, config_id = await self._configured_service(db_session, self._payload())
service._restore_kprofiles = AsyncMock(side_effect=RuntimeError("mqtt exploded"))
relay = MagicMock()
relay.configure = AsyncMock(return_value=True)
with self._session_patch(db_session), patch("backend.app.services.mqtt_relay.mqtt_relay", relay):
result = await service.run_restore(
config_id, "a" * 40, [RestoreCategory.SETTINGS, RestoreCategory.KPROFILES]
)
assert result["success"] is True
assert result["results"][RestoreCategory.SETTINGS.value]["restored"] == 2
assert result["results"][RestoreCategory.KPROFILES.value]["failed"] == 1
relay.configure.assert_awaited_once()
assert relay.configure.await_args.args[0]["mqtt_broker"] == "restored.local"
@pytest.mark.asyncio
async def test_a_failure_before_the_commit_still_reports_nothing_restored(self, db_session):
"""Control: rolling back and saying so is right when nothing landed."""
service, config_id = await self._configured_service(db_session, self._payload())
service._restore_settings = AsyncMock(side_effect=RuntimeError("read failed"))
relay = MagicMock()
relay.configure = AsyncMock(return_value=True)
with self._session_patch(db_session), patch("backend.app.services.mqtt_relay.mqtt_relay", relay):
result = await service.run_restore(
config_id, "a" * 40, [RestoreCategory.SETTINGS, RestoreCategory.KPROFILES]
)
assert result["success"] is False
assert result["results"] == {}
assert (await db_session.execute(select(Settings))).scalars().first() is None
relay.configure.assert_not_awaited()
@pytest.mark.asyncio
async def test_a_malformed_profiles_value_is_a_skipped_category_not_a_raise(self, db_session, printer_factory):
"""Belt-and-braces: the pre-loop count ran ahead of the per-call guards.
``sum(len(c.get("profiles") or []) ...)`` raises TypeError on a
hand-edited or truncated backup whose ``profiles`` is not a list — and it
raises after the database categories are already on disk.
"""
await printer_factory(serial_number="00M09A123456789")
client = MagicMock()
client.state.connected = True
client.set_kprofiles_batch = MagicMock(return_value="7")
client.get_kprofiles = AsyncMock(return_value=[])
tally = _CategoryTally()
with patch("backend.app.services.github_restore.printer_manager") as manager:
manager.get_client = MagicMock(return_value=client)
await _service()._restore_kprofiles(db_session, self._payload(profiles=5), tally)
client.set_kprofiles_batch.assert_not_called()
assert (tally.restored, tally.failed) == (0, 0)
assert "kprofilesStepFailed" not in _codes(tally)
class TestResolveRef:
@pytest.mark.asyncio
async def test_concrete_sha_passes_through_without_an_api_call(self):