Skip to content

[Bug]: Hard shutdown on macOS corrupts state.sqlite: SQLite never uses F_FULLFSYNC #13544

Description

@Zedyas

Before submitting

  • I searched existing issues and did not find a duplicate.
  • I included enough detail to reproduce or investigate the problem.

Area

apps/server

Summary

A hard shutdown on macOS (no clean shutdown, no kernel panic report) left state.sqlite with zero-filled pages inside orchestration_events, projection_thread_messages, and projection_thread_activities. Every server start afterwards failed with SQLITE(11) database disk image is malformed, and the desktop app never opened a window.

SQLite in WAL mode is designed to stay consistent through power loss, but only if its syncs reach stable storage in order. On macOS, fsync() does not flush the drive's write cache. Only fcntl(F_FULLFSYNC) does, and SQLite uses it only when PRAGMA fullfsync or PRAGMA checkpoint_fullfsync is on. T3 Code sets neither (Sqlite.ts L15-L17), and both are 0 in the shipped runtime.

This is not #11084. The server traces show a single server lifecycle up to the shutdown (details below).

Steps to reproduce

Not deterministic, because it depends on losing writes that are still in the drive's cache:

  1. Run the desktop app on macOS with an active agent turn that produces tool results with inline images (~300 KB thread.activity-appended events).
  2. Lose power or force a hard reset while events are being written.
  3. Relaunch.

kill -9 of the server process does not reproduce this. The kernel page cache survives process death, so every completed write() still reaches the drive. Only losing the drive's volatile cache does. SQLite's own crash testing simulates power loss at the VFS layer for this reason.

Expected behavior

After power loss the database is consistent. At most the last few commits are missing.

Actual behavior

B-tree pages in the file point at pages that contain only zeros. The server exits with code 1 on every start. The desktop app restarted it 124 times over 92 minutes and never created a window. Startup-path details and a working recovery procedure are in my comment on #961.

Evidence

Timeline (UTC, 2026-09-25)

Time Source Event
00:23:52.7 macOS unified log Last entry before the gap. Normal activity, no errors.
00:23:55.5 desktop.trace.ndjson Last desktop span. Normal IPC traffic.
00:24:00.117 orchestration_events Last persisted event (seq 85055).
~01:00 Me I was away until here. I came back to a black screen, restarted, and got the startup options screen (startup disk / Options / shut down).
01:00:56 kern.boottime Boot. last has no shutdown record. No .panic report. pmset -g log has no sleep or shutdown entry; battery was at 93%.
01:01:37 server-child.log First server start after boot fails with SQLITE(11).
01:01 – 02:33 desktop.trace.ndjson 124 desktop.backendInstance.start spans, ~40 s apart, until manual recovery.

Server traces covering 23:48:54 – 00:23:46 contain no startup, bootstrap, or migration spans, so only one server lifecycle was writing the database before the shutdown.

PRAGMA integrity_check (complete result, summarized)

Tree 3 page 203283: btreeInitPage() returns error code 11        # 11 lines like this
Tree 3 page 203376 cell 0: overflow list length is 1 but should be 92
Tree 29 page 203469 cell 0: overflow list length is 1 but should be 92
Page 203088: never used                                           # 363 pages, 203088–203468
wrong # of entries in index idx_orch_events_stream_version       # + 11 other indexes on the 3 tables

Tree 3 = orchestration_events, 27 = projection_thread_messages, 29 = projection_thread_activities.

Page contents of the damaged file

  • The file is 204,012 pages (4096 B). The page count in the header matches the file size.
  • All 11 pages that fail btreeInitPage() are 4096 zero bytes.
  • 377 pages in 203,086–203,468 are entirely zero, in contiguous runs: 203086–203178, 203180–203275, 203278–203279, 203281, 203283–203375, 203377–203468.
  • Runs of ~92 pages match one overflow chain of a ~310 KB activity payload, which is what the two "should be 92" errors describe.
  • The interior b-tree pages that reference these pages, and the header carrying the new page count, were persisted. The contents of the pages they reference were not. The first open after boot would have restored the pages from the WAL if a valid WAL copy had survived.

This is a write-ordering failure at the storage level: some writes to the file reached stable storage and earlier or neighboring writes did not. On macOS, fsync() does not prevent this. From man 2 fsync:

Applications, such as databases, that require a strict ordering of writes should use F_FULLFSYNC to ensure that their data is written in the order they expect.

Effective settings in the shipped runtime

Measured by running node:sqlite from the app binary (ELECTRON_RUN_AS_NODE=1) and applying the same pragmas as Sqlite.ts:

sqlite_version()       3.53.4
journal_mode           wal
synchronous            2   (FULL)
fullfsync              0
checkpoint_fullfsync   0

Context for #5104: synchronous is already FULL under node:sqlite, so that PR would not have changed the effective setting. The missing piece is F_FULLFSYNC.

Cost of the fix (disk-backed benchmark)

#5104 was closed with a request to "show the streaming-write cost of the chosen setting". Setup:

  • T3's own runtime (node:sqlite, SQLite 3.53.4, Electron 44.4.2), database file on the internal APFS SSD.
  • Same pragmas as Sqlite.ts, plus the setting under test. Default wal_autocheckpoint (1000 pages).
  • 1,500 single-row autocommit inserts into an orchestration_events-shaped table. 10% are 310 KB payloads and 90% are 500 B. For comparison, in the real database 0.8% of events are over 100 KB, but they hold 60% of payload bytes.
  • 3 rounds, median shown.
Setting Commits/s p50 p99 max
Current (synchronous=FULL, no fullfsync) 8,063 0.04 ms 4.4 ms 5.0 ms
checkpoint_fullfsync = ON 4,485 0.04 ms 9.7 ms 11.5 ms
fullfsync = ON 282 3.1 ms 11.6 ms 19.0 ms
synchronous = NORMAL + fullfsync = ON 4,302 0.02 ms 11.8 ms 15.7 ms
  • synchronous=FULL in WAL mode calls fsync() on every commit. A p50 of 0.04 ms for that commit is only possible because the drive cache is not flushed. With F_FULLFSYNC the same commit takes ~3.1 ms.
  • Real demand on this machine: 5,696 events on the day of the incident. The busiest minute had 171 events (~2.9/s), and the median active minute had 40.
  • DatabaseSync is synchronous, so the cost is event-loop time. At the busiest minute, fullfsync = ON adds about 171 × 3.1 ms ≈ 0.53 s per minute (<1%), multiplied by the number of commits per event. checkpoint_fullfsync = ON only adds cost at checkpoints.
Benchmark script

Run with the app's runtime: ELECTRON_RUN_AS_NODE=1 "/Applications/T3 Code (Nightly).app/Contents/MacOS/T3 Code (Nightly)" fsync-bench.cjs <dir>

const { DatabaseSync } = require('node:sqlite');
const fs = require('node:fs');
const path = require('node:path');
const crypto = require('node:crypto');

const dir = process.argv[2];
const EVENTS = 1500;
const LARGE_EVERY = 10;
const SMALL = 500;
const LARGE = 310 * 1024;

const configs = [
  { name: 'current (FULL, fullfsync=0)', pragmas: [] },
  { name: 'checkpoint_fullfsync=ON', pragmas: ['PRAGMA checkpoint_fullfsync = ON'] },
  { name: 'fullfsync=ON', pragmas: ['PRAGMA fullfsync = ON'] },
  { name: 'NORMAL + fullfsync=ON', pragmas: ['PRAGMA synchronous = NORMAL', 'PRAGMA fullfsync = ON'] },
];

const small = crypto.randomBytes(SMALL).toString('base64').slice(0, SMALL);
const large = crypto.randomBytes(LARGE).toString('base64').slice(0, LARGE);

function run(config, round) {
  const file = path.join(dir, `bench-${round}-${configs.indexOf(config)}.sqlite`);
  for (const suffix of ['', '-wal', '-shm']) fs.rmSync(file + suffix, { force: true });
  const db = new DatabaseSync(file);
  db.exec('PRAGMA busy_timeout = 5000; PRAGMA foreign_keys = ON; PRAGMA journal_mode = WAL;');
  for (const p of config.pragmas) db.exec(p);
  db.exec(`CREATE TABLE orchestration_events (
    sequence INTEGER PRIMARY KEY AUTOINCREMENT,
    event_id TEXT NOT NULL UNIQUE,
    event_type TEXT NOT NULL,
    payload_json TEXT NOT NULL)`);
  const insert = db.prepare('INSERT INTO orchestration_events (event_id, event_type, payload_json) VALUES (?, ?, ?)');
  const latencies = [];
  const started = process.hrtime.bigint();
  for (let i = 0; i < EVENTS; i++) {
    const payload = i % LARGE_EVERY === LARGE_EVERY - 1 ? large : small;
    const t0 = process.hrtime.bigint();
    insert.run(crypto.randomUUID(), 'thread.activity-appended', payload);
    latencies.push(Number(process.hrtime.bigint() - t0) / 1e6);
  }
  const totalMs = Number(process.hrtime.bigint() - started) / 1e6;
  db.close();
  for (const suffix of ['', '-wal', '-shm']) fs.rmSync(file + suffix, { force: true });
  latencies.sort((a, b) => a - b);
  const pct = (q) => latencies[Math.min(latencies.length - 1, Math.floor(q * latencies.length))];
  return { totalMs, p50: pct(0.5), p99: pct(0.99), max: latencies.at(-1) };
}

const results = new Map(configs.map((c) => [c.name, []]));
for (let round = 0; round < 3; round++) {
  for (const config of configs) results.get(config.name).push(run(config, round));
}
const median = (xs) => [...xs].sort((a, b) => a - b)[Math.floor(xs.length / 2)];
for (const [name, runs] of results) {
  const total = median(runs.map((r) => r.totalMs));
  console.log(name, Math.round(EVENTS / (total / 1000)), 'commits/s',
    'p50', median(runs.map((r) => r.p50)).toFixed(2),
    'p99', median(runs.map((r) => r.p99)).toFixed(2),
    'max', median(runs.map((r) => r.max)).toFixed(1));
}

Proposed fix

// apps/server/src/persistence/Layers/Sqlite.ts
yield* sql`PRAGMA busy_timeout = 5000;`;
yield* sql`PRAGMA foreign_keys = ON;`;
yield* sql`PRAGMA journal_mode = WAL;`;
// macOS fsync() does not flush the drive cache. Without F_FULLFSYNC a power loss can
// persist checkpointed page references without the pages they point to.
yield* sql`PRAGMA checkpoint_fullfsync = ON;`;
  • checkpoint_fullfsync = ON is the minimum for integrity. During a checkpoint, SQLite syncs the WAL before copying pages into the database file, and syncs the database file before the WAL can be reset. Both syncs become real flushes. A power loss can still drop the last few commits since the previous checkpoint. WAL frame checksums detect that cleanly, so it does not corrupt the file.
  • fullfsync = ON also makes every commit durable, at ~3 ms per commit on the event loop.
  • Both pragmas are per-connection and not stored in the file, so they must run on every connection that writes state.sqlite.
  • Both have no effect on platforms without F_FULLFSYNC, so no platform check is needed.

What I could not verify

  • I cannot prove this specific shutdown would have been survived with checkpoint_fullfsync = ON. The evidence is the write-ordering signature above plus the documented macOS fsync() behavior.
  • Cause of the hard stop: unknown. I was away from the computer when the logs stop (00:23:52 UTC). When I came back around 01:00 UTC the screen was black, and restarting brought up the startup options screen. So the final power-off may have been me, but the system had already stopped logging ~36 minutes earlier, and no panic report was saved.

Impact

Blocks work completely

Version or commit

0.0.43-nightly.20260924.2213. main @ 568c9bc sets the same three pragmas.

Environment

macOS 26.6.2 (25G83), MacBook Pro M3 (Mac15,3), 16 GB, internal SSD (APFS). Electron 44.4.2, Node 24.21.0, SQLite 3.53.4 via node:sqlite. state.sqlite was 835 MB.

Logs or stack traces

ERROR (#4): PersistenceSqlError: SQL error in OrchestrationEventStore.readFromSequence:query: SQLITE(11) database disk image is malformed
    at .../app.asar/apps/server/dist/bin.mjs:56754:10
  [cause]: effect/sql/SqlError: Failed to execute statement
    [cause]: effect/sql/SqlError/UnknownError: Failed to execute statement
      [cause]: Error: database disk image is malformed
backend child process failure output end  details="pid=1792 code=1"

Workaround

Salvage the database with the sqlite3 CLI. Steps are in my comment on #961. Loss in this case: 23 events (seq 85017–85039, a 30 s window of one thread), 1 message row, and 16 activity rows. Every other table was recovered with identical row counts.

Additional context


A note from me: I am not a developer at all, but it felt worth helping out when I ran into an unusual issue and Claude helped me debug it. So apologies if anything here is just flat out wrong. I genuinely don't understand most of the technical detail, so I'm really sorry if I'm wasting your time.

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    acceptedfeature request acceptedbugSomething is broken or behaving incorrectly.via-triageFiled through npx t3 triage

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions