Repository navigation
Commit 810d42b
Fixes #20768
Clause-②: no
On the first boot of a new database, the SQL driver printed one
`[sql-driver] DATABASE_ERROR ... no such table: sys_migration` line on
its warn channel. The read behind it is the engine's migration-gate
read. The driver's own pre-DDL question reaches that read before the
schema pass has created any table. The driver now asks that question
inside an async scope. Inside the scope, one class of refusal goes to
`debug` instead of `warn`: a missing table, recognised by the shared
`isMissingTableError` over the envelope's declared target. Every other
refusal still warns, and so does a missing table read anywhere else. No
gate's answer changes.
## Reproduction on the base
`objectstack dev --database file:NEW.sqlite -p PORT` on
`examples/app-crm`, base `96e724475c` (every package in the app's
closure built), stdout and stderr captured separately:
| run | `DATABASE_ERROR` lines | channel |
|:--|:--|:--|
| first boot of a new file | **1** | stderr (the driver's default
`console.warn` sink) |
| second boot of the same file | 0 | none |
The line, verbatim:
```text
[sql-driver] DATABASE_ERROR — the backend refused a read on 'sys_migration' (SQLITE_ERROR). The dialect message below is kept server-side: it carries the compiled statement, and on the dialects that inline them the bound literals too (#7929, #8931): select * from `sys_migration` where `id` = 'adr-0104-file-references' limit 1 - no such table: sys_migration
```
## The mechanism: which dispatch hypotheses held
**H1 held.** For one boot, I added a temporary stack-trace line to the
built `packages/objectql/dist` (restored afterwards, `cmp`
byte-identical on all four bundles, marker count 0). The first gate read
at boot is `ObjectQL.readMigrationFlagVerified`, reached through
`readFileReferencesFlagRow` and `haveFileColumnsMoved`. It is called by
the closure that `registerDriver` hands the driver, which
`SqlDriver.resolveFileColumnsMoved` asks at the start of
`SqlDriver.initObjects`, from the schema pass's first `syncSchema`,
before any DDL. The other gate readers run after the schema pass has
created `sys_migration`, so on the first boot they read without error:
`isValueShapesMigrationVerified` from write hooks, and
`announceOpenMigrationGates` at `kernel:bootstrapped`.
**H2 falsified.** The engine cannot tell whether the table exists
without asking the backend:
- The driver's registered-table set answers "registered in this
process", not "exists". On a second boot the table exists but is not
registered yet when the question is asked. Answering "not moved" there
without a read would change the answer on a deployment whose columns
have moved, which is the failure the resolver exists to prevent.
- The schema pass has no plan at that moment: the question is asked
before the first `hasTable`.
- For an absent table, `conclusive` must be `false`. The same pass
creates the table moments later, and a memoized "not verified" would
freeze a whole boot's posture from a moment when nothing could answer.
That is what the refused read already returns, so it is unchanged.
- A catalog probe (`hasTable`) would give "not asked", but it needs a
new public driver method or a new `IDataDriver` member. That enlarges a
public surface, against this card's `Clause-②: no`, so this PR does not
add one.
**H3 held.** `SqlDriver.backendStatementFault` writes the line before
the engine sees the error. The engine's `findOne` path does not log, and
its catch in `readMigrationFlagVerified` answers `{ verified: false,
conclusive: false, columnsMoved: false }` silently. So the demotion is
in the driver, keyed on `isMissingTableError`, and limited to this read:
the async chain of the driver's own question.
**H4: measured at `c5ae3a6f8e`.** The second boot prints nothing, as on
the base. `os migrate plan --database-url file:X` on the database the
boots created prints no `DATABASE_ERROR`. On a path that does not exist
yet, the plan printed 7 lines on the base, 2 of them on `sys_migration`,
and prints 6 now. The one `sys_migration` line left is the
`adr-0104-value-shapes` read from `announceOpenMigrationGates`, outside
the driver's question. The other 5 are `sys_metadata` (4) and
`sys_metadata_activation` (1). They are not this card. See the
acceptance notes.
## Landing site: `packages/drivers/driver-sql`, not
`packages/objectql/src/engine.ts`
The dispatch expected the engine, with the driver only if a demotion was
needed. As H2 and H3 show, the demotion is needed, and the line's
producer is the driver. The premature read is the driver's own pre-DDL
question. `engine.ts` is unchanged.
## What changed
`packages/drivers/driver-sql/src/sql-driver.ts`:
- A module-level `AsyncLocalStorage` (`PRE_DDL_QUESTION_SCOPE`).
`resolveFileColumnsMoved` runs the resolver inside it, and nothing else
does. It is module-level rather than per instance because the question's
read goes to whichever driver serves the ledger, which on a
multi-datasource composition can be another instance in the same async
chain.
- `backendStatementFault` composes the envelope first. If the scope is
active and `isMissingTableError(envelope, object)` holds, it writes the
same dialect text to `this.logger.debug?.(...)` and returns the
envelope. Otherwise it warns as before. The throw, the envelope, and
what the resolver hears are unchanged.
- The logger shape gains an optional `debug` channel. The default sink
has none.
- `isMissingTableError` is imported from its home, `@objectstack/types`.
`@objectstack/metadata/errors` re-exports the same symbol, and
driver-sql cannot depend on `@objectstack/metadata`. No second message
regex.
`.changeset/20768-first-boot-migration-gate-read.md`:
`@objectstack/driver-sql` patch. `@objectstack/runtime` gains only a
test file, which its `files[]` (`dist`, `README.md`, `CHANGELOG.md`)
does not ship, so it gets no changeset entry.
## After: this branch at `c5ae3a6f8e`, built
| run | `DATABASE_ERROR` lines | `sys_migration` mentions | server ready
|
|:--|:--|:--|:--|
| `objectstack dev --database file:NEW.sqlite` (`examples/app-crm`),
first boot | 0 | 0 | yes |
| second boot of that file | 0 | 0 | yes |
| `os migrate plan` on that file | 0 | 0 | exit 0 |
Normalised for timestamps, port and file path, the first-boot stderr
differs from the base run in exactly one line: the removed one. Both
ledgers end in the same state after the first boot: both flags verified
by the fresh-datastore attestation, and `columns_moved_at` null.
## Tests
-
**`packages/drivers/driver-sql/src/sql-driver-20768-pre-ddl-question-missing-table.test.ts`**
(new, SQLite on a new temp file). The resolver is a stand-in that reads
the ledger the way the engine does.
- ① First boot: no warn line, one `debug` line (`no such table`). The
resolver gets the envelope (`code: 'DATABASE_ERROR'`, `status: 500`),
and the arm stays "not moved".
- ② Same result when the ledger is served by a second driver instance.
- ③ Second boot: a `columns_moved_at` row written between the boots
makes the arm "moved", so the read reached the row. Nothing is logged.
- Controls, each still `warn`: ④ a malformed read on an existing table
inside the question (40,000 bound variables, SQLite refuses the
statement); ⑤ a view over a dropped table inside the question (a missing
table named by another relation); ⑥ a missing table read outside the
question.
-
**`packages/runtime/src/first-boot-migration-gate-read.integration.test.ts`**
(new). A real `ObjectQL` engine over a real `SqlDriver` on a new file,
`SysMigration` registered, and `engine.syncSchemas()`, which is the same
`syncSchema`, `initObjects`, resolver, gate-read chain.
- First and second boot: no `sys_migration` `DATABASE_ERROR` on warn,
and one demoted line on the first boot only.
- Gate answers asserted on both boots: not moved and not verified on the
first; verified after a row is written between boots.
- Control: a malformed read on an existing table still warns, and so
does a missing table read after the boot. It counts only its own reads'
lines.
- Suites at `c5ae3a6f8e`:
- driver-sql: 201 files passed, 11 skipped (the live PG and MySQL cells,
not provisioned here); 3254 tests passed, 188 skipped.
- runtime `--project local`: 293 files, 4207 tests passed, 1 skipped.
- Typecheck green for driver-sql and runtime. Runtime's
`check:test-typecheck` debt is unchanged, and `tsc --listFiles` shows
both new tests inside their packages' programs.
## Reverse verification (from the committed fix)
`packages/drivers/driver-sql/src/sql-driver.ts` was restored to its base
blob with `git restore --source=96e724475c`: on-disk blob `2462eccd` =
base, marker count 0. driver-sql was rebuilt, and
`ablation-dist-preflight --absent PRE_DDL_QUESTION_SCOPE` found the
marker absent from all 6 built files.
- Driver pin: **red** on ① and ② (`expected [ Array(1) ] to deeply equal
[]`). ③ to ⑥ stayed green.
- Runtime pin: the boot test **red** (same message). The control stayed
green.
Restore: `git checkout HEAD --
packages/drivers/driver-sql/src/sql-driver.ts`. Blob `a3647fd1` = HEAD,
and `git diff HEAD` was empty. After a rebuild, the preflight found the
marker in 2 built files and a clean tree, and both pins were green
again.
The first run of this verification also turned the runtime control red:
it had counted the boot's own `sys_migration` line together with its
own. It now counts only its own reads, and the second run above is from
that commit.
## Gates
`node scripts/pm/dispatch-gates.mjs --commands` at `c5ae3a6f8e` derives
63 commands, and all 63 ran on that head with exit 0. `--ran`
reconciliation: "63 derived famil(ies) accounted for — 63 run, 0
NOT-MEASURED (a DERIVED zero — all 63 recorded an exit code and none of
them is 3)". On the first pass, `check:dual-build-cjs-loads` answered
PREREQUISITE NOT MET (9 packages had no `dist/`). I built those 9 and
re-ran it, and it exited 0.
Lint, narrowed: `eslint --no-inline-config --format json` over the 3
touched `.ts` files counted 3 files, 0 errors, 0 warnings. The
population is the config's `packages/**/*.{ts,tsx,mts,cts}` and
`**/*.{ts,...}` objects. The config never enables type-aware linting (no
`parserOptions.project`), so this diff cannot change the verdict on an
untouched file.
The branch merged `main` twice. The second merge brought in #20794, the
serial constraint. Neither merge touched this diff's files, apart from
the tracker-number wording in the same `DATABASE_ERROR` line, which this
branch now carries as `main` spells it.
## Acceptance notes
- `os migrate plan` against a database that does not exist yet still
prints 6 `DATABASE_ERROR` lines at `c5ae3a6f8e`: `sys_metadata` 4,
`sys_metadata_activation` 1, and `sys_migration` 1. The last is the
`adr-0104-value-shapes` read by `announceOpenMigrationGates` at
`kernel:bootstrapped`, which on a deferred-DDL plan runs over tables the
plan never creates. It is the same false-alarm family, on a different
door, and is reported to the seat. It is not fixed here.
- "Demoted, not deleted" holds only where a host injects a logger that
has `debug`. No production composition hands `SqlDriver` a logger today,
so with the default sink the line is dropped. The engine's catch records
nothing either.
- `PRE_DDL_QUESTION_SCOPE` covers any read in the resolver's async
chain, including one a hook starts inside it. That is intended: every
such read is issued for the question, before the schema pass has run.
---
_Generated by [Claude
Code](https://claude.ai/code/session_01DEvba2nBuD4tWzfq8r8NFY)_
---------
Co-authored-by: Claude <noreply@anthropic.com>
1 parent 7911485 commit 810d42b
4 files changed
Lines changed: 541 additions & 9 deletions
File tree
- .changeset
- packages
- drivers/driver-sql/src
- runtime/src
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
| 1 | + | |
| 2 | + | |
| 3 | + | |
| 4 | + | |
| 5 | + | |
| 6 | + | |
| 7 | + | |
| 8 | + | |
| 9 | + | |
| 10 | + | |
| 11 | + | |
| 12 | + | |
| 13 | + | |
| 14 | + | |
| 15 | + | |
| 16 | + | |
| 17 | + | |
| 18 | + | |
| 19 | + | |
| 20 | + | |
| 21 | + | |
| 22 | + | |
| Original file line number | Diff line number | Diff line change | |
|---|---|---|---|
| |||
| 1 | + | |
| 2 | + | |
| 3 | + | |
| 4 | + | |
| 5 | + | |
| 6 | + | |
| 7 | + | |
| 8 | + | |
| 9 | + | |
| 10 | + | |
| 11 | + | |
| 12 | + | |
| 13 | + | |
| 14 | + | |
| 15 | + | |
| 16 | + | |
| 17 | + | |
| 18 | + | |
| 19 | + | |
| 20 | + | |
| 21 | + | |
| 22 | + | |
| 23 | + | |
| 24 | + | |
| 25 | + | |
| 26 | + | |
| 27 | + | |
| 28 | + | |
| 29 | + | |
| 30 | + | |
| 31 | + | |
| 32 | + | |
| 33 | + | |
| 34 | + | |
| 35 | + | |
| 36 | + | |
| 37 | + | |
| 38 | + | |
| 39 | + | |
| 40 | + | |
| 41 | + | |
| 42 | + | |
| 43 | + | |
| 44 | + | |
| 45 | + | |
| 46 | + | |
| 47 | + | |
| 48 | + | |
| 49 | + | |
| 50 | + | |
| 51 | + | |
| 52 | + | |
| 53 | + | |
| 54 | + | |
| 55 | + | |
| 56 | + | |
| 57 | + | |
| 58 | + | |
| 59 | + | |
| 60 | + | |
| 61 | + | |
| 62 | + | |
| 63 | + | |
| 64 | + | |
| 65 | + | |
| 66 | + | |
| 67 | + | |
| 68 | + | |
| 69 | + | |
| 70 | + | |
| 71 | + | |
| 72 | + | |
| 73 | + | |
| 74 | + | |
| 75 | + | |
| 76 | + | |
| 77 | + | |
| 78 | + | |
| 79 | + | |
| 80 | + | |
| 81 | + | |
| 82 | + | |
| 83 | + | |
| 84 | + | |
| 85 | + | |
| 86 | + | |
| 87 | + | |
| 88 | + | |
| 89 | + | |
| 90 | + | |
| 91 | + | |
| 92 | + | |
| 93 | + | |
| 94 | + | |
| 95 | + | |
| 96 | + | |
| 97 | + | |
| 98 | + | |
| 99 | + | |
| 100 | + | |
| 101 | + | |
| 102 | + | |
| 103 | + | |
| 104 | + | |
| 105 | + | |
| 106 | + | |
| 107 | + | |
| 108 | + | |
| 109 | + | |
| 110 | + | |
| 111 | + | |
| 112 | + | |
| 113 | + | |
| 114 | + | |
| 115 | + | |
| 116 | + | |
| 117 | + | |
| 118 | + | |
| 119 | + | |
| 120 | + | |
| 121 | + | |
| 122 | + | |
| 123 | + | |
| 124 | + | |
| 125 | + | |
| 126 | + | |
| 127 | + | |
| 128 | + | |
| 129 | + | |
| 130 | + | |
| 131 | + | |
| 132 | + | |
| 133 | + | |
| 134 | + | |
| 135 | + | |
| 136 | + | |
| 137 | + | |
| 138 | + | |
| 139 | + | |
| 140 | + | |
| 141 | + | |
| 142 | + | |
| 143 | + | |
| 144 | + | |
| 145 | + | |
| 146 | + | |
| 147 | + | |
| 148 | + | |
| 149 | + | |
| 150 | + | |
| 151 | + | |
| 152 | + | |
| 153 | + | |
| 154 | + | |
| 155 | + | |
| 156 | + | |
| 157 | + | |
| 158 | + | |
| 159 | + | |
| 160 | + | |
| 161 | + | |
| 162 | + | |
| 163 | + | |
| 164 | + | |
| 165 | + | |
| 166 | + | |
| 167 | + | |
| 168 | + | |
| 169 | + | |
| 170 | + | |
| 171 | + | |
| 172 | + | |
| 173 | + | |
| 174 | + | |
| 175 | + | |
| 176 | + | |
| 177 | + | |
| 178 | + | |
| 179 | + | |
| 180 | + | |
| 181 | + | |
| 182 | + | |
| 183 | + | |
| 184 | + | |
| 185 | + | |
| 186 | + | |
| 187 | + | |
| 188 | + | |
| 189 | + | |
| 190 | + | |
| 191 | + | |
| 192 | + | |
| 193 | + | |
| 194 | + | |
| 195 | + | |
| 196 | + | |
| 197 | + | |
| 198 | + | |
| 199 | + | |
| 200 | + | |
| 201 | + | |
| 202 | + | |
| 203 | + | |
| 204 | + | |
| 205 | + | |
| 206 | + | |
| 207 | + | |
| 208 | + | |
| 209 | + | |
| 210 | + | |
| 211 | + | |
| 212 | + | |
| 213 | + | |
| 214 | + | |
| 215 | + | |
| 216 | + | |
| 217 | + | |
| 218 | + | |
| 219 | + | |
| 220 | + | |
| 221 | + | |
| 222 | + | |
| 223 | + | |
| 224 | + | |
| 225 | + | |
| 226 | + | |
| 227 | + | |
| 228 | + | |
| 229 | + | |
| 230 | + | |
| 231 | + | |
| 232 | + | |
| 233 | + | |
| 234 | + | |
| 235 | + | |
| 236 | + | |
| 237 | + | |
| 238 | + | |
| 239 | + | |
| 240 | + | |
| 241 | + | |
| 242 | + | |
| 243 | + | |
| 244 | + | |
| 245 | + | |
| 246 | + | |
| 247 | + | |
| 248 | + | |
| 249 | + | |
| 250 | + | |
| 251 | + | |
| 252 | + | |
| 253 | + | |
| 254 | + | |
| 255 | + | |
| 256 | + | |
| 257 | + | |
| 258 | + | |
| 259 | + | |
| 260 | + | |
| 261 | + | |
| 262 | + | |
| 263 | + | |
| 264 | + | |
| 265 | + | |
| 266 | + | |
| 267 | + | |
| 268 | + | |
| 269 | + | |
| 270 | + | |
| 271 | + | |
| 272 | + | |
| 273 | + | |
| 274 | + | |
| 275 | + | |
| 276 | + | |
| 277 | + | |
| 278 | + | |
| 279 | + | |
| 280 | + | |
| 281 | + | |
| 282 | + | |
| 283 | + | |
| 284 | + | |
| 285 | + | |
| 286 | + | |
| 287 | + | |
0 commit comments