openrundev / openrundev/openrun

WAL still grows unbounded on v0.18.14: truncate checkpoint permanently blocked by the long-lived read txn (follow-up to #100)

Open
#104 2 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Go
Stars
975
Forks
33
PR merge metrics
No merged PRs in 30d

Description

Following up on #100, which added the SQLite self-maintenance loop (01efb72). We upgraded to v0.18.14 on 2026-07-30 specifically to pick that up. Fifteen days later the metadata WAL had reached 1.68 GB and took our whole server down for a morning.

I want to be clear that the fix is doing its job as written — the maintenance loop detected the condition and warned us, loudly and repeatedly. The problem is that detection is all it can do: the truncate checkpoint can never win against the long-lived read transaction that pins the frames, so the WAL grows without bound anyway.

What we saw

internal/system/sqlite.go:373 fired 119 times over ~20 hours:

FIRST 2026-08-13T13:01:25Z   670.9 MB
      2026-08-13T20:21:25Z  1360.4 MB
      2026-08-14T01:01:25Z  1591.0 MB
LAST  2026-08-14T09:01:25Z  1602.3 MB

A passive checkpoint at the peak:

sqlite> PRAGMA wal_checkpoint(PASSIVE);
0|406276|22        -- 406,276 frames pinned, 22 moved

Once the WAL got large enough, keystore reads and writes began failing intermittently:

error cleaning up expired kv entries: database is locked (517)   sync.go:278
error updating app status: database is locked (517)              sync.go:376
error querying keystore: sql: no rows in result set              oauth.go:309   (continuous)
state token mismatch                                             oauth.go:440

Because sessions and OAuth state live in keystore, and every app and auth provider shares the one clace_metadata.db, this presents as total auth failure across every app at once — every request looks unauthenticated and gets redirected to the OAuth provider. Users see a rendered app shell whose every subsequent fetch 302s. It is not obvious from the symptom that the cause is a WAL.

The only fix we have is stopping the server:

systemctl stop openrun
sqlite3 clace_metadata.db 'PRAGMA wal_checkpoint(TRUNCATE);'   # 0|0|0
systemctl start openrun

That took the WAL 1.68 GB → 0 and the main DB stayed 231 MB (so it really is repeated rewrites of the same pages, not real data). This is the sixth time we have run that procedure.

The gap

sqliteMaintenanceLoop runs PRAGMA wal_checkpoint(TRUNCATE) every truncateEvery passes, and when a reader holds frames it logs at Debug level and moves on:

if truncatePass {
    if busy != 0 {
        logger.Debug().Str("db", invoker).Msg("sqlite truncate checkpoint blocked by a long-lived transaction")
    }

So on a default log level the operator sees the Warn about WAL size but never the Debug line explaining why it cannot be fixed — and there is no in-process mechanism that can release the pinning transaction. The loop is a smoke alarm with no extinguisher.

Questions / suggestions

  1. Can the pinning read transaction be bounded? That feels like the actual defect — #100 identified it, and the maintenance loop mitigates the symptom rather than the cause. If some long-lived reader can be given a maximum lifetime, or periodically released and reacquired, the truncate checkpoint would get its window.
  2. Promote the "blocked by a long-lived transaction" line from Debug to Warn, at least when it coincides with the WAL-size warning. Together they tell the whole story; separately, the visible half looks like something the operator can fix.
  3. Would you consider surfacing this on an endpoint (health/metrics) rather than only the log? WAL bytes plus last-successful-truncate timestamp would let people alert on it without log scraping.
  4. Is there anything an operator can do to make the truncate succeed without stopping the server? If a stop is genuinely the only remedy, saying so explicitly in the warning text would help — we spent hours on the wrong end of this before working it out.

Happy to test a patch, gather more diagnostics, or run with increased log verbosity on this host — it reproduces reliably for us roughly every two to five weeks.

Environment: OpenRun v0.18.14, Ubuntu 24.04, single EC2 host, SQLite metadata store, ~25 apps (mixed container + static), Google/Okta/Auth0 OIDC providers. No [metadata] overrides — running the shipped defaults from openrun.default.toml (32 MB journal_size_limit, 60 s interval, truncate every 10).

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Read internal/system/sqlite.go around line 373 and the sqliteMaintenanceLoop, then compare the reported PRAGMA wal_checkpoint(TRUNCATE) behavior with the long-lived reader. Trace the keystore and OAuth call sites in sync.go and oauth.go; done means the agreed remediation is implemented and the blocked-checkpoint condition has a clear operator-facing outcome.

Written by the indexing model from the issue text.

Assessment

Tech stack
go, sqlite
Domain
authentication, backend, databases, observability
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Quiet
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.