Skip to content

fix(state_sync): preserve the original exception when migration rollback fails - #6130

Open
zhaoruizhe81 wants to merge 2 commits into
SQLMesh:mainfrom
zhaoruizhe81:fix/issue-6096-masked-rollback
Open

zhaoruizhe81 wants to merge 2 commits into
SQLMesh:mainfrom
zhaoruizhe81:fix/issue-6096-masked-rollback

Conversation

@zhaoruizhe81

Copy link
Copy Markdown

Description

What

In StateMigrator.migrate() (sqlmesh/core/state_sync/db/migrator.py), the exception handler called self.rollback() unguarded. On a fresh state DB, update_versions() has already written a non-zero schema_version when a later statement fails, so rollback() finds no *_backup tables and raises SQLMeshError("There are no prior migrations to roll back to.") from inside the handler — replacing the original exception before raise SQLMeshError("SQLMesh migration failed.") from e is ever reached. The original error only survives in __context__, which the CLI does not print (_default_exception_handler shows str(ex) only).

Changes:

  • Wrap the handler's self.rollback() call in its own try/except and log the failure with logger.exception, so a failed rollback can no longer mask the original error.
  • Guard the handler's second analytics.collector.on_migration_end(...) call the same way — when analytics is the original failure source it would otherwise raise again from inside the handler and bypass the wrapping below.
  • Include the original error in the raised message, SQLMeshError(f"SQLMesh migration failed: {e}"), keeping e as __cause__, so the cause is visible without SQLMESH_DEBUG=1.

The rollback-semantics changes suggested in the issue (treating "no backup tables" as non-fatal on a fresh state, and when update_versions() commits) are intentionally left out — they change behavior and deserve a separate discussion.

Why

Fixes #6096. On a fresh state DB — the path every new deployment and fresh CI database takes — any bootstrap-time error was turned into an undiagnosable rollback message. In the reported case a one-line PermissionError on an unwritable SQLMESH_HOME cost an instrumented debug run to find.

Test Plan

  • New test test_migration_failure_after_update_versions in tests/core/state_sync/test_state_sync.py: patches on_migration_end to fail right after update_versions() and asserts the raised error carries the original exception as __cause__ (with the message containing it). test_first_migration_failure only covers failures before update_versions(), where rollback() takes the clean schema_version == 0 path and the bug cannot trigger.
  • Red/green verified locally (Python 3.9, editable install of this repo):
    • On unpatched main (commit d69c262): pytest tests/core/state_sync/test_state_sync.py::test_migration_failure_after_update_versions fails with sqlmesh.utils.errors.SQLMeshError: There are no prior migrations to roll back to. raised from migrator.py:123 (self.rollback()) → migrator.py:152.
    • With this patch: the same test passes (2 passed together with test_first_migration_failure).
  • Reproduction from the issue (fresh DuckDB state DB, patched on_migration_end raising RuntimeError("BOOM original error"), then Context(...).migrate()):
    • Before: CAUGHT: SQLMeshError: There are no prior migrations to roll back to. / __cause__: NoneType: None
    • After: CAUGHT: SQLMeshError: SQLMesh migration failed: BOOM original error / __cause__: RuntimeError: BOOM original error
  • pytest tests/core/state_sync -q: 103 passed.
  • pre-commit run --all-files (the make style hooks): ruff Passed, ruff-format Passed; mypy reports no errors in the two touched files. (Note: my local venv does not have the full dev extra installed — pyspark/dbt/dateparser stubs are missing — so full-tree mypy shows pre-existing import-stub errors unrelated to this change; I did not run the full make fast-test suite locally.)

Checklist

  • I have run make style and fixed any issues
  • I have added tests for my changes (if applicable)
  • All existing tests pass (make fast-test)
  • My commits are signed off (git commit -s) per the DCO

…ack fails

On a fresh state DB the exception handler in StateMigrator.migrate()
called self.rollback() unguarded. update_versions() has already written
a non-zero schema_version by then, so rollback() finds no *_backup
tables and raises "There are no prior migrations to roll back to."
from inside the handler, replacing the original exception before
'raise SQLMeshError(...) from e' is reached. The CLI only prints
str(ex), so the real cause was invisible without SQLMESH_DEBUG=1.

- Wrap the handler's rollback() in its own try/except and log failures
  with logger.exception so rollback can no longer mask the error.
- Guard the handler's second on_migration_end() call the same way, so
  analytics failures cannot re-raise from inside the handler.
- Include the original error in the raised message and keep it as
  __cause__.

Fixes SQLMesh#6096

Signed-off-by: zhaoruizhe <zhaoruizhe81@gmail.com>

@Vamsi-klu Vamsi-klu left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good fix. Getting "There are no prior migrations to roll back to." instead of the actual error on a fresh state DB is rough, and having the cause in the message helps a lot when SQLMESH_DEBUG isn't set. Agree with leaving the rollback semantics for a separate PR. Main thing for me is that a failed rollback now only ends up in the log file, so someone might not realize their state could be half migrated. Details inline, plus a small test nit.

try:
self.rollback()
except Exception:
logger.exception("Migration rollback failed.")

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is fine for the fresh state case from the issue. But it also catches a real rollback failure on an existing state, where backups exist and the restore dies partway. Before, you'd at least see that rollback failed. Now you only get "SQLMesh migration failed: ..." and the rollback error is just in the logs. Could we also put it on the console, something like self.console.log_warning("Migration rollback failed, state may be partially migrated. Check the logs."), or fold it into the raised message?

"on_migration_end",
side_effect=[Exception("mocked error"), None],
)
with pytest.raises(SQLMeshError, match="SQLMesh migration failed.") as exc_info:

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The . here is a regex wildcard, so this only matches the new "failed: ..." message by accident. match=r"SQLMesh migration failed: mocked error" would be tighter and you could drop the extra "mocked error" assert. Might also be worth a caplog check that "Migration rollback failed." got logged, so the swallowed rollback path is covered.

Per review: when a migration fails and the rollback also fails on an
existing state (backups present but the restore dies partway), the
rollback error previously only went to the logs. Now the handler:

- logs a console warning ('Migration rollback failed, state may be
  partially migrated. Check the logs.') so interactive users see it,
- folds the rollback error into the raised SQLMeshError message
  ('... Rolling back to the previous state also failed: ...').

Also tighten the migration-failure test matchers (the trailing '.' was
a regex wildcard that matched the new ': ...' messages by accident) and
add a regression test for the rollback-failure path asserting the
warning lands in the log and the rollback error is chained into the
raised message.
@zhaoruizhe81

Copy link
Copy Markdown
Author

Thanks for the review — both points addressed in 9dcbe19:

  1. Rollback failure visibility: on a failed rollback the handler now logs Migration rollback failed, state may be partially migrated. Check the logs. via console.log_warning and folds the rollback error into the raised message (SQLMesh migration failed: <e>. Rolling back to the previous state also failed: <rollback error>), so both interactive and non-interactive users see it.

  2. Tests: matchers tightened to the literal SQLMesh migration failed: mocked error, and the redundant string assert is dropped. Added test_migration_failure_with_rollback_failure covering the real rollback-failure path (existing state, no usable backups): it asserts the folded message and that Migration rollback failed. is logged.

Note on the fresh-state case: rollback() succeeds there via the schema_version == 0 cleanup branch, so the swallowed-rollback path only triggers on existing states — that's the scenario the new test pins down.

Local: pytest tests/core/state_sync/test_state_sync.py → 92 passed; ruff check/format clean.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Fresh-state migration failures are masked by a bogus rollback error (original exception discarded, never logged)

2 participants