Skip to content

fix: wait for the database at startup; quieter logs when stopping a sync that is not running - #1333

Open
satran004 wants to merge 5 commits into
mainfrom
fix/startup-db-wait-quiet-stop
Open

satran004 wants to merge 5 commits into
mainfrom
fix/startup-db-wait-quiet-stop

Conversation

@satran004

Copy link
Copy Markdown
Member

Part of #1328.

Problems

  1. The app exits if it starts before Postgres is ready. In scenario J09 (app and Postgres killed together, as after a host crash), the app was started 10 s after Postgres. Postgres was still recovering, the first database connection failed, and the app exited. Docker Compose restarts it (restart: unless-stopped), but the standalone jar and other process managers don't.
  2. Stopping a sync that was not running logs a stack trace. yaci throws a NullPointerException when you stop a range fetch or chain sync that was never started or is already closed (Restart near the tip: batchDone() races startSync(), stops a never-started BlockRangeSync (NPE) and restarts sync with an extra rollback #1314). The trace hides real errors in the log.

What changes

  • New DatabaseStartupWait. Right after the DataSource is created, and before anything uses it, it tries to connect every 5 s for up to store.db.startup-wait-seconds (default 300; 0 turns it off), logging a short line each time. If the database is still down after that, the startup fails as before.
    • A first version used Flyway's connect-retries. Codex's review showed Spring Boot connects to resolve db/store/{vendor} before those retries apply, so they never ran. The wait is now on the DataSource itself.
  • Quieter stop. The NullPointerException from yaci for a session that is not running is logged as one warning line. Any other error when stopping still logs its stack trace.

Tests

🤖 Generated with Claude Code

satran004 and others added 2 commits November 6, 2026 22:10
…sync that is not running

- Flyway retries the first database connection (30 retries, up to 10 s apart),
  and Hikari no longer fails at pool creation. The app no longer exits when it
  starts before Postgres is ready, for example after a host restart
  (fault-injection scenario J09, #1328).
- Stopping a range fetch or chain sync that was never started or is already
  closed logs one warning line instead of a stack trace (#1314).

Part of #1328.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… stop errors

Review: Spring Boot resolves Flyway's {vendor} location through the DataSource
before Flyway's connect-retries apply, so the retries never ran. Replace them
with a small BeanPostProcessor that retries a connection right after the
DataSource is created (store.db.startup-wait-seconds, default 300, 0 = off).
Only the NullPointerException yaci throws for a session that was never started
gets the one-line log; other stop errors keep their stack trace.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@satran004 satran004 added 3.0.0-beta6 Planned for 3.0.0-beta6 fault-injection Found or verified by the auto-recovery fault-injection test labels Nov 6, 2026

Copy link
Copy Markdown

Initial automated review · Aster

Hi @satran004, thanks for the PR! 🙏 This is an automatic first check by an AI reviewer. It does not replace maintainer review and may be wrong.

Reviewed commit: f4b487aaec14577a6485c61b254376774e0181ba

No issues found in this first check.

Not tested: Code was read only; builds, tests, and database-startup fault scenarios were not run.

@satran004

Copy link
Copy Markdown
Member Author

Fault-injection re-test result

We ran the same 104 fault scenarios again on preprod (benchmark-vm): 43 during the initial sync and 61 at the tip. This time the build had all the fix PRs together: main + #1330, #1331, #1313, #1332, #1271, #1333, #1266 (branch test/recovery-combined).

  • All 104 scenarios recovered on their own. None needed a manual restart. In the first run, 7 got stuck.
  • No duplicate rows.
  • Missing blocks: only the 2 that B04 skips on purpose. B04 sends an undecodable block with continue-on-parse-error=true.
  • address_utxo_unspent is exact: 0 missing and 0 extra rows, compared with address_utxo minus tx_input.

Details and the full list of findings: #1328

This PR in the test

satran004 and others added 2 commits November 8, 2026 18:55
Review: the deadline was only checked after a failed attempt, and the
pause before the next attempt was always 5 s. With
store.db.startup-wait-seconds=1 and a refused connection the wait took
about 5 s and made a second attempt after the budget was already used up.

Now the pause is capped to the time left, and no attempt starts once the
budget is used up. A single getConnection() that hangs is still bounded by
the pool/driver connection timeout, not by this wait; the class comment
says so.

The clock and sleep are injectable so the tests check the timing without
waiting. Added tests for a 1 s budget, the capped last pause, an attempt
that uses up the budget, a real-clock 1 s budget, and interruption.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01MJrQUCWhJpLCQR5Asv7nDb
The last pause is capped to the time left, so it ends at the deadline. Try once more then instead of giving up
right after the pause, so a database that comes up within the budget is still used. No attempt starts after the
deadline.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01MJrQUCWhJpLCQR5Asv7nDb
@satran004

Copy link
Copy Markdown
Member Author

Updated after an external review of the 2.0.x backport #1346: 76cc063, 08b7df4. Each finding, its verdict and its test are in the reply on #1339.

The last pause ends at the deadline, but the thread can wake up late (scheduling, GC, a suspended process), and
the next attempt then started after the deadline. Check the clock after the pause: an attempt at the deadline is
still made, a later one is not.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01MJrQUCWhJpLCQR5Asv7nDb
@sonarqubecloud

sonarqubecloud Bot commented Nov 8, 2026

Copy link
Copy Markdown

@satran004

Copy link
Copy Markdown
Member Author

Verdict: APPROVED

reviewer1 — original-PR review at b3726b003ced4d90123961037fe82653a69e5df6.

F1 from #1346 is resolved at this head. The startup wait caps its pause and checks the clock after waking, so a retry at the deadline is permitted and one after it is rejected. The implementation and deadline tests match the approved backport.

The numbered findings refer to the counterpart review of #1346. No additional blocking finding remains.

Validation on combined main: core 244 passed, 1 skipped at d9b1d37282351992da8f45a85e0e3dbe62e5e1e2; eight other relevant suites 197 passed at f0579f9a5f42ae98694d8f35cd0c998295cc1c20, with zero failures/errors in these successful runs. Exact commands, integration resolutions and scope. These are combined-build results, not a separate standalone run of this PR.

@satran004
satran004 requested a review from huylevt November 8, 2026 23:59
@satran004

Copy link
Copy Markdown
Member Author

Fault-injection rerun on main with all seven fix PRs at their approved heads (test/recovery-combined d9b1d3728): 104 of 104 scenarios recovered, with no duplicate rows and no unexpected missing blocks. The full report is on #1328: #1328 (comment)

For this PR:

  • The Postgres scenarios all recovered: D01–D11 in both phases (Postgres down, frozen or partitioned, among others), J09 (app and Postgres killed together) and C07 (fresh JVM while the node refuses).

The baseline is unpatched main at 6836c4dd6, run on the same matrix.

This branch has not been deployed

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

Labels

3.0.0-beta6 Planned for 3.0.0-beta6 fault-injection Found or verified by the auto-recovery fault-injection test

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants