fix(database): enable SQLite WAL before schema reconciliation

2026-10-21 08:04:26 +02:00
parent a15336cc94
commit f51e0506cc
10 changed files with 594 additions and 3 deletions
@@ -1,6 +1,6 @@
 # Patched-source integrated run — 21 October

-This is investigation evidence, not final acceptance. The ordinary351-case run started05:32:57UTC against [patched entry](evidence/patched-entry.json), with zero configured retries. The run is still active at this observation; passing partial output does not establish a passing suite.
+This is investigation evidence, not final acceptance. The ordinary351-case run started05:32:57UTC against [patched entry](evidence/patched-entry.json), with zero configured retries. It was explicitly stopped05:55:08UTC after144passing and3failing logged cases; passing partial output does not establish a passing suite. [Raw hashes](evidence/lock-observation.json) and the [subsequent bounded repair](SQLITE_CONCURRENCY.md) preserve the distinction between this failed attempt and successor verification.

 ## Reproduced SQLite failures

@@ -0,0 +1,30 @@
+# SQLite startup concurrency repair
+
+## Scope and reproduced failure
+
+The [patched-source run](CURRENT_FAILURES.md) was explicitly stopped05:55:08UTC after144passing and3failing logged cases out of351discovered cases. This is an interrupted failure, not a completed result. [Portable raw hashes](evidence/lock-observation.json) retain its command, traces and log even when later execution archives their paths.
+
+Two unchanged client assertions receive SQLite error5/HTTP500: owned restored-job readback and language preference persistence. Read-only inspection of the isolated database reports `journal_mode=delete`, `locking_mode=normal`. Actual bootstrap opens the file during reconciliation before EF's normal database creation path can establish WAL. A deterministic regression invokes that bootstrap without starting a listener, worker or provider, holds a SELECT cursor on one connection and attempts the actual usage reservation on another. Before repair it reproduces the browser's `SqliteDataRecord.Dispose → NextResult → AffectedCountModificationCommandBatch → AiUsageMeter.ReserveAsync` failure. The separate startup assertion reports expected`wal`, actual`delete`.
+
+The precise competing connection in the browser was not identified. The deterministic mechanism and unsafe journal mode are demonstrated; no claim is made that WAL eliminates all possible SQLite writer contention.
+
+## Bounded change and preservation
+
+Startup executes `PRAGMA journal_mode = WAL` once before SQLite reconciliation. The existing provider branch excludes MariaDB/MySQL. No schema, stored field, tenant filter, Identity contract, quota rule, summary output, write payload or save semantics changes. There is no new retry, swallowed exception, relaxed timeout or disabled assertion. Existing `VACUUM INTO` backup already supports WAL; [database guidance](../../../database/migrations.md) explains consistent snapshots.
+
+The new ordinary backend cases verify fresh and populated startup, reopening persistent mode after a deliberately DELETE-mode database, unchanged owned/foreign rows and completed migration history; usage INSERT and Identity preference UPDATE while the SELECT cursor remains open; committed WAL contents in an independent integrity-checked backup that does not change after later source writes. Local file cleanup stays within the uniquely named disposable fixture directory.
+
+## Validation
+
+| Run | Actual result | Qualification |
+|---|---|---|
+| Original focused RED,05:58:07–05:58:24UTC | 4PASS/2FAIL/0skipped | Startup mode and actual held-reader usage write fail; backup cases pass |
+| Initial focused successor,05:58:44–05:58:53UTC | 5PASS/1FAIL/0skipped | Actual concurrent writes pass; populated-mode verification still used the external connection that set DELETE |
+| Reopened-verification successor,05:59:34–05:59:41UTC | 6PASS/0FAIL/0skipped | Fixture closes the DELETE-setting connection before restart and reopens for the original expected`wal` assertion; no production change or weaker expectation |
+| Fresh full backend,05:59:54–06:00:10UTC | **1060PASS/0FAIL/0skipped** | Current patched Release assemblies; plus3from1057:2startup/concurrency cases and1backup case |
+| Ordinary affected browser vector,06:00:43–06:03:24UTC | **17PASS/0FAIL/0skipped/0flaky** | Actual Audit, application forms and paginated Users cases; zero configured retries |
+| Release build,06:03:48–06:03:50UTC | PASS/0warnings/0errors | API and backend test projects, locked existing restore, warnings treated as errors |
+
+[Portable repair evidence](evidence/sqlite-repair.json) records the exact command/TRX/log paths and byte hashes for every backend attempt and the17-case native vector. Release build is recorded under `.artifacts/phase7/current/backend-career/p702-release-20261021T060348Z/`; its historical helper label does not make it Phase2 evidence. Complete351-case regression and the separate lanes remain required.
+
+PRES-E02/E08/E09, S03/S04/S05, W01/W04 and the wider57-group matrix remain binding. This finite regression does not supply human/device acceptance or production restore, ingress/configuration/schema/rollback evidence. Production readiness stays **NO-GO**. No Phase8 or withheld P5-13 implementation is introduced.
@@ -0,0 +1,55 @@
+{
+  "observedUtc": "2026-10-21T05:57:11.930894+00:00",
+  "entry": "patched-entry.json",
+  "command": {
+    "name": "main",
+    "command": [
+      "rtk",
+      "proxy",
+      "node",
+      "node_modules/@playwright/test/cli.js",
+      "test",
+      "--retries=0",
+      "--reporter=list,json",
+      "--output=E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\ui\\main-results"
+    ],
+    "startedUtc": "2026-10-21T05:32:58.246829+00:00",
+    "finishedUtc": "2026-10-21T05:55:08.627992+00:00",
+    "exitCode": 1,
+    "failureLog": "E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\ui\\main.log"
+  },
+  "partialLogObservations": {
+    "passed": 144,
+    "failed": 3,
+    "configuredInventory": 351
+  },
+  "qualification": "Explicitly interrupted failed run at05:55:08UTC; not a completed suite. No assertion was retried or suppressed. Later independent lanes did not start. Raw paths may move to attempts during the next run; byte hashes remain authoritative.",
+  "sqliteReadOnlyObservation": {
+    "path": "C:/Users/Connor/AppData/Local/Temp/jobtracker-e2e-16580-mvhoel1k/jobtracker.db",
+    "journalMode": "delete",
+    "lockingMode": "normal",
+    "qualification": "Read-only connection immediately closed. This identifies journal mode, not the competing lock holder or extended error code."
+  },
+  "raw": [
+    {
+      "path": ".artifacts/phase7/current/ui/main.log",
+      "sha256": "26c263a3ea76804ce0c44628b265108a2d11d092194d2bbc898b091939a50651"
+    },
+    {
+      "path": ".artifacts/phase7/current/ui/main-command.json",
+      "sha256": "93b00dcfe0233e2cd345946904cdcf7be0921dc8335c739c1408465f2c7baa97"
+    },
+    {
+      "path": ".artifacts/phase7/current/ui/main-results/phase7-admin-audit--P7-10--d26fe-y-user-requests-stay-denied-chromium/trace.zip",
+      "sha256": "a8d68428c620ca623ae1be822b7792e0499bd98d5413bf4e101709ae3530e314"
+    },
+    {
+      "path": ".artifacts/phase7/current/ui/main-results/phase7-admin-users--P7-10--ff1fd-nd-protected-admin-controls-chromium/trace.zip",
+      "sha256": "2885e25285ffa40101749385142c2cb308d012cabc49da8a8f90f06e7a44a718"
+    },
+    {
+      "path": ".artifacts/phase7/current/ui/main-results/phase7-application-forms---65823-without-asset-GET-or-writes-chromium/trace.zip",
+      "sha256": "341e0ee675b6478e2d115bbde836c54ef5f7c001fe6b7b5eeb794366a3f69cda"
+    }
+  ]
+}
@@ -0,0 +1,104 @@
+{
+  "schemaVersion": 1,
+  "checkpoint": "p7-12",
+  "status": "PASS",
+  "checkedUtc": "2026-10-21T06:04:19.064310+00:00",
+  "commands": [
+    {
+      "name": "secret-scan",
+      "command": [
+        "rtk",
+        "proxy",
+        "C:\\Users\\Connor\\AppData\\Local\\Programs\\Python\\Python312\\python.exe",
+        "-X",
+        "utf8",
+        "scripts/supply-chain.py",
+        "scan-secrets"
+      ],
+      "startedUtc": "2026-10-21T06:04:15.650300+00:00",
+      "finishedUtc": "2026-10-21T06:04:18.265071+00:00",
+      "exitCode": 0,
+      "log": ".artifacts/phase7/current/static/20261021T060415Z/secret-scan.log",
+      "logSha256Raw": "be5119e6057287d397e87759f855c91e634e3bfac61c8be7584d05592ba2dfcd"
+    },
+    {
+      "name": "working-whitespace",
+      "command": [
+        "rtk",
+        "proxy",
+        "git",
+        "diff",
+        "--check"
+      ],
+      "startedUtc": "2026-10-21T06:04:18.265562+00:00",
+      "finishedUtc": "2026-10-21T06:04:18.351167+00:00",
+      "exitCode": 0,
+      "log": ".artifacts/phase7/current/static/20261021T060415Z/working-whitespace.log",
+      "logSha256Raw": "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"
+    },
+    {
+      "name": "staged-whitespace",
+      "command": [
+        "rtk",
+        "proxy",
+        "git",
+        "diff",
+        "--cached",
+        "--check"
+      ],
+      "startedUtc": "2026-10-21T06:04:18.351659+00:00",
+      "finishedUtc": "2026-10-21T06:04:18.433899+00:00",
+      "exitCode": 0,
+      "log": ".artifacts/phase7/current/static/20261021T060415Z/staged-whitespace.log",
+      "logSha256Raw": "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"
+    },
+    {
+      "name": "phase7-whitespace",
+      "command": [
+        "rtk",
+        "proxy",
+        "git",
+        "diff",
+        "--check",
+        "b5319981ad3d1bd635daff861453d23c0de5320b"
+      ],
+      "startedUtc": "2026-10-21T06:04:18.434374+00:00",
+      "finishedUtc": "2026-10-21T06:04:18.638948+00:00",
+      "exitCode": 0,
+      "log": ".artifacts/phase7/current/static/20261021T060415Z/phase7-whitespace.log",
+      "logSha256Raw": "e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855"
+    }
+  ],
+  "untrackedSecretScan": {
+    "files": 0,
+    "findings": 0
+  },
+  "documentation": {
+    "files": 45,
+    "relativeLinks": 691,
+    "errors": []
+  },
+  "preservation": {
+    "groups": 57,
+    "statuses": {
+      "PARTIAL": 56,
+      "PASS": 0,
+      "FAIL": 0,
+      "DEFERRED": 1
+    },
+    "originalRoutesPreserved": true,
+    "currentConcreteRoutes": 33
+  },
+  "production": {
+    "main": "5f835e54a9b74e6b71418422e28431b2af06453f",
+    "originMain": "5f835e54a9b74e6b71418422e28431b2af06453f",
+    "status": "NO-GO",
+    "qualification": "Local fetched refs; direct push observation recorded separately."
+  },
+  "hashPolicy": "Portable JSON UTF8 LF; raw log hashes measure exact saved bytes.",
+  "limits": [
+    "Pattern scanner skips binary and files over2MiB; not historical Git/production secrets.",
+    "Local links check target existence, not URL/heading anchors.",
+    "Static evidence is not runtime/manual/device/provider/production acceptance."
+  ]
+}
@@ -0,0 +1,220 @@
+{
+  "observedUtc": "2026-10-21T06:03:47.685086+00:00",
+  "backend": [
+    {
+      "name": "p712-sqlite-wal-red-20261021T055807Z",
+      "command": [
+        "rtk",
+        "proxy",
+        "C:/Users/Connor/.dotnet/dotnet.exe",
+        "test",
+        "JobTrackerApi.Tests/JobTrackerApi.Tests.csproj",
+        "--configuration",
+        "Release",
+        "--no-restore",
+        "--filter",
+        "FullyQualifiedName~SqliteStartupConcurrencyTests|FullyQualifiedName~DatabaseBackupRunnerTests",
+        "--logger",
+        "trx;LogFileName=career.trx",
+        "--results-directory",
+        "E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\backend-career\\p712-sqlite-wal-red-20261021T055807Z"
+      ],
+      "startedUtc": "2026-10-21T05:58:07.053581+00:00",
+      "finishedUtc": "2026-10-21T05:58:24.710760+00:00",
+      "exitCode": 1,
+      "logSha256": "fc09eea2f4090a1b28458cb3d3330c4066f12c9ebf5eb4b370b1f024992e19ab",
+      "counts": {
+        "total": 6,
+        "passed": 4,
+        "failed": 2,
+        "notExecuted": 0
+      },
+      "resultSha256": "3df5bf5e12e3a61da8188c97182963852a836ba0dd5f5a1b8c68111d59d62159",
+      "raw": [
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-red-20261021T055807Z/command.json",
+          "sha256": "496d0c473184e8e8a47f7a371e3ae685d50c6560c08c5efebdd49504b81bef74"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-red-20261021T055807Z/career.log",
+          "sha256": "fc09eea2f4090a1b28458cb3d3330c4066f12c9ebf5eb4b370b1f024992e19ab"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-red-20261021T055807Z/career.trx",
+          "sha256": "3df5bf5e12e3a61da8188c97182963852a836ba0dd5f5a1b8c68111d59d62159"
+        }
+      ]
+    },
+    {
+      "name": "p712-sqlite-wal-green-20261021T055844Z",
+      "command": [
+        "rtk",
+        "proxy",
+        "C:/Users/Connor/.dotnet/dotnet.exe",
+        "test",
+        "JobTrackerApi.Tests/JobTrackerApi.Tests.csproj",
+        "--configuration",
+        "Release",
+        "--no-restore",
+        "--filter",
+        "FullyQualifiedName~SqliteStartupConcurrencyTests|FullyQualifiedName~DatabaseBackupRunnerTests",
+        "--logger",
+        "trx;LogFileName=career.trx",
+        "--results-directory",
+        "E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\backend-career\\p712-sqlite-wal-green-20261021T055844Z"
+      ],
+      "startedUtc": "2026-10-21T05:58:44.038215+00:00",
+      "finishedUtc": "2026-10-21T05:58:53.717954+00:00",
+      "exitCode": 1,
+      "logSha256": "515d76ceb2153821639bc700f593c761181728f73ba634dba69e325ea3ae26f8",
+      "counts": {
+        "total": 6,
+        "passed": 5,
+        "failed": 1,
+        "notExecuted": 0
+      },
+      "resultSha256": "9e1a6cf48888ee2e0793e98eb44da489fd1008611af2ccfa4d7f2f47cc987f52",
+      "raw": [
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-20261021T055844Z/command.json",
+          "sha256": "e41307845a10ac889e78b20e09f4c871c378823987a9f8daece4029d4f1f8a2e"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-20261021T055844Z/career.log",
+          "sha256": "515d76ceb2153821639bc700f593c761181728f73ba634dba69e325ea3ae26f8"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-20261021T055844Z/career.trx",
+          "sha256": "9e1a6cf48888ee2e0793e98eb44da489fd1008611af2ccfa4d7f2f47cc987f52"
+        }
+      ]
+    },
+    {
+      "name": "p712-sqlite-wal-green-reopened-20261021T055934Z",
+      "command": [
+        "rtk",
+        "proxy",
+        "C:/Users/Connor/.dotnet/dotnet.exe",
+        "test",
+        "JobTrackerApi.Tests/JobTrackerApi.Tests.csproj",
+        "--configuration",
+        "Release",
+        "--no-restore",
+        "--filter",
+        "FullyQualifiedName~SqliteStartupConcurrencyTests|FullyQualifiedName~DatabaseBackupRunnerTests",
+        "--logger",
+        "trx;LogFileName=career.trx",
+        "--results-directory",
+        "E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\backend-career\\p712-sqlite-wal-green-reopened-20261021T055934Z"
+      ],
+      "startedUtc": "2026-10-21T05:59:34.116441+00:00",
+      "finishedUtc": "2026-10-21T05:59:41.908713+00:00",
+      "exitCode": 0,
+      "logSha256": "7e0bc56242ee07b416cc5f525020bcbe26719e373a633e512a105456be9d99f5",
+      "counts": {
+        "total": 6,
+        "passed": 6,
+        "failed": 0,
+        "notExecuted": 0
+      },
+      "resultSha256": "f665c8fee93546b483e437a57fbbd8565f744e420e84126687ce58ee7c4de2cb",
+      "raw": [
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-reopened-20261021T055934Z/command.json",
+          "sha256": "c2a5f73f1507a1415fdd2a754b308ce964e5623c575675e29ccc5fbcdffebbca"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-reopened-20261021T055934Z/career.log",
+          "sha256": "7e0bc56242ee07b416cc5f525020bcbe26719e373a633e512a105456be9d99f5"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-green-reopened-20261021T055934Z/career.trx",
+          "sha256": "f665c8fee93546b483e437a57fbbd8565f744e420e84126687ce58ee7c4de2cb"
+        }
+      ]
+    },
+    {
+      "name": "p712-sqlite-wal-full-20261021T055954Z",
+      "command": [
+        "rtk",
+        "proxy",
+        "C:/Users/Connor/.dotnet/dotnet.exe",
+        "test",
+        "JobTrackerApi.Tests/JobTrackerApi.Tests.csproj",
+        "--configuration",
+        "Release",
+        "--no-build",
+        "--logger",
+        "trx;LogFileName=career.trx",
+        "--results-directory",
+        "E:\\Storage\\Projects\\Active\\Job tracker\\.artifacts\\phase7\\current\\backend-career\\p712-sqlite-wal-full-20261021T055954Z"
+      ],
+      "startedUtc": "2026-10-21T05:59:54.473875+00:00",
+      "finishedUtc": "2026-10-21T06:00:10.139200+00:00",
+      "exitCode": 0,
+      "logSha256": "23e0cee4d8a88d88d8b770235a44402114d01d5bfdf8462d98e30daeb678d94f",
+      "counts": {
+        "total": 1060,
+        "passed": 1060,
+        "failed": 0,
+        "notExecuted": 0
+      },
+      "resultSha256": "b9109fc0a1c8c24129f6ef5a450540a5826cad3de599c3a84d4652ae8682ec66",
+      "raw": [
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-full-20261021T055954Z/command.json",
+          "sha256": "163bcbce9dce2a553c078dbb4a0cb9835fb5d45947d401c03d2b33c84e07529c"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-full-20261021T055954Z/career.log",
+          "sha256": "23e0cee4d8a88d88d8b770235a44402114d01d5bfdf8462d98e30daeb678d94f"
+        },
+        {
+          "path": ".artifacts/phase7/current/backend-career/p712-sqlite-wal-full-20261021T055954Z/career.trx",
+          "sha256": "b9109fc0a1c8c24129f6ef5a450540a5826cad3de599c3a84d4652ae8682ec66"
+        }
+      ]
+    }
+  ],
+  "affectedBrowser": {
+    "stats": {
+      "startTime": "2026-10-21T06:00:43.909Z",
+      "duration": 160381.752,
+      "expected": 17,
+      "skipped": 0,
+      "unexpected": 0,
+      "flaky": 0
+    },
+    "raw": [
+      {
+        "path": ".artifacts/phase7/current/ui/lock-repair.json",
+        "sha256": "ffee3294ad9d65fbd5773b3a44c71b74bb24bfcd4b2c41c2a11166d62142627c"
+      },
+      {
+        "path": ".artifacts/phase7/current/ui/lock-repair.log",
+        "sha256": "144fb525ba4f91a716aee3f79769cea249547c884cc108b8512617a4f62a133b"
+      }
+    ]
+  },
+  "runtimeSources": [
+    {
+      "path": "JobTrackerApi/Services/StartupInitializationExtensions.cs",
+      "sha256": "41557a2d51ddf988bcf129115bfb496add4fe053bd0bb295c0751e5de23e0679"
+    },
+    {
+      "path": "JobTrackerApi.Tests/SqliteStartupConcurrencyTests.cs",
+      "sha256": "536a801f74b9499340e53c2dcf1e138d00498bc1413558d64db69732f80adc1a"
+    },
+    {
+      "path": "JobTrackerApi.Tests/DatabaseBackupRunnerTests.cs",
+      "sha256": "3107d265b272775eead9b26e0b56f8560db15f9102f0f421fe7fcfc63ec9bbc3"
+    }
+  ],
+  "countDelta": {
+    "previousBackend": 1057,
+    "currentBackend": 1060,
+    "newStartupConcurrencyCases": 2,
+    "newWalBackupCases": 1
+  },
+  "qualification": "Focused vectors overlap ordinary full-suite cases and are never added to its count. Full browser acceptance, manual/device evaluation and production release qualification remain separate."
+}
@@ -160,13 +160,15 @@
  },
  "backend": {
    "baseline": 1033,
-    "current": 1057,
+    "current": 1060,
    "addedCases": {
      "careerEvidenceSQLite": 1,
      "companyCompatibilitySQLite": 3,
      "documentsOwnerProjection": 12,
      "emailDraftRotationAndUTC": 7,
-      "operationNotificationUTC": 1
+      "operationNotificationUTC": 1,
+      "sqliteStartupConcurrency": 2,
+      "committedWalBackup": 1
    }
  },
  "sidecar": {