kayg/calternal
Watch
1
0
Fork
You've already forked calternal
 0
Code Issues 190 Pull requests 61 Projects Releases Packages Wiki Activity Actions 26

plan: durable save-log entry (tick < 40 ms) #938

Open
kayg wants to merge 1 commit from plan/save-log-durable-entry into dev
pull from: plan/save-log-durable-entry
merge into: kayg:dev
Conversation 3 Commits 1 Files changed 1 +262
kayg commented 2026-11-04 16:54:37 +00:00
Owner
Copy link

A tick still waits on several durable writes after #898. This design accepts a validated executor change with one FULL transaction in index.db, then applies history and exact markdown bytes in order outside the reply path. No product code changes.

Plan: docs/plans/save-log-durable-entry.md. Extends #898 and integrates #928 (#918/#919); the overlap search found no separate durable-entry plan.

first slice design / measured result
scope and size tasks.set-status plus all owner notes; full images, 4 MiB encoded / 32 participants; pre-accept fallback for dirty/large plans
cost O(encoded bytes + participants × log retained actions), indexed pending replay
safety redo + reply + permanent receipt + events in one FULL transaction; pending reads, guarded placement, history receipts, restore/downgrade fences
measured storage p95 one FULL vs three barriers: quiet 6.19 vs 16.17 ms; shared-disk contention 14.61 vs 41.20 ms
measured-component tick estimate quiet 18.33 ms; contended 26.71 ms, versus 40 ms. This sums separately measured p95 components, not an end-to-end candidate p95
controls real same-binary dev-vs-dev tick p95 delta -0.1% quiet / +0.7% contended; all raw samples retained
still required implemented tick p95 < 40 ms on the 10k fixture; typing and every affected path flat or better; crash/replay/double-apply suites

Full evidence, commands, source/binary hashes and attached raw artifacts. kayg explicitly requested measured summary tables in this plan in the follow-up; raw artifacts stay in the PR comment. The earlier blocked measurement status is superseded.

Five numbered review questions carry recommendations: ack meaning, restore exception, numeric version aliases, initial scope/caps, permanent receipts/downgrade safety. These are proposals for kayg, not approved implementation decisions.

Validation: git diff --check origin/dev...HEAD passed; clean worktree, one documentation file changed. No product gate or notes-typing flatness claimed. Measurements ran only on the perf VMs with both official locks held; the small profiler was built on dev-01 through Nix and ~/bin/slot. All task-owned build/measurement/load/lock units are inactive, scratch Homes/databases and large copied VM binaries removed. Never merge as part of this task.

A tick still waits on several durable writes after #898. This design accepts a validated executor change with one FULL transaction in index.db, then applies history and exact markdown bytes in order outside the reply path. No product code changes. Plan: [docs/plans/save-log-durable-entry.md](https://git.kayg.org/kayg/calternal/src/branch/plan/save-log-durable-entry/docs/plans/save-log-durable-entry.md). Extends #898 and integrates #928 (#918/#919); the overlap search found no separate durable-entry plan. | first slice | design / measured result | |---|---| | scope and size | tasks.set-status plus all owner notes; full images, 4 MiB encoded / 32 participants; pre-accept fallback for dirty/large plans | | cost | O(encoded bytes + participants × log retained actions), indexed pending replay | | safety | redo + reply + permanent receipt + events in one FULL transaction; pending reads, guarded placement, history receipts, restore/downgrade fences | | measured storage p95 | one FULL vs three barriers: quiet 6.19 vs 16.17 ms; shared-disk contention 14.61 vs 41.20 ms | | measured-component tick estimate | quiet 18.33 ms; contended 26.71 ms, versus 40 ms. This sums separately measured p95 components, not an end-to-end candidate p95 | | controls | real same-binary dev-vs-dev tick p95 delta -0.1% quiet / +0.7% contended; all raw samples retained | | still required | implemented tick p95 < 40 ms on the 10k fixture; typing and every affected path flat or better; crash/replay/double-apply suites | [Full evidence, commands, source/binary hashes and attached raw artifacts](https://git.kayg.org/kayg/calternal/pulls/938#issuecomment-78559). kayg explicitly requested measured summary tables in this plan in the follow-up; raw artifacts stay in the PR comment. The earlier blocked measurement status is superseded. Five numbered review questions carry recommendations: ack meaning, restore exception, numeric version aliases, initial scope/caps, permanent receipts/downgrade safety. These are proposals for kayg, not approved implementation decisions. Validation: `git diff --check origin/dev...HEAD` passed; clean worktree, one documentation file changed. No product gate or notes-typing flatness claimed. Measurements ran only on the perf VMs with both official locks held; the small profiler was built on dev-01 through Nix and ~/bin/slot. All task-owned build/measurement/load/lock units are inactive, scratch Homes/databases and large copied VM binaries removed. Never merge as part of this task.
save-log-spike-2026-11-04.zip
133 KiB
plan: durable save-log entry with one acceptance commit
Some checks failed
CI / server (pull_request) Has been cancelled
Details
CI / rust (pull_request) Has been cancelled
Details
CI / web (pull_request) Has been cancelled
Details
Markdown extraction contract / markdown-native-contract (pull_request) Has been cancelled
Details
Markdown extraction contract / markdown-editor-contract (pull_request) Has been cancelled
Details
8dd7dcec53
kayg commented 2026-11-04 16:58:35 +00:00
Author
Owner
Copy link

source review and measurement status

Head: 31258faef88dfe1e97c6f8f7f685f29ee7f31b75. Docs only, one file. git diff --check origin/dev...HEAD passed; no product tests or builds were run for this document.

Read the engine action/retry path, commit_once and store schema/writer; Notes executor admission/recovery/publication, history receipts, room loading/executor/save acks; fsio staging/exchange; Notes search generations/watchers; Tasks status capture/result; ADRs 0011/0020/0021/0044/0047 and storage guidance. Compared dev 9377d711, #898 2432b5a4 and #928 d88a4c44, including #898 comments 77003/77110/77166/77221 and #918/#919 issue text. #928 had no PR comments when read.

Decisions proposed for review, not kayg-approved implementation decisions:

  • one transaction must include redo, permanent retry result and events. Merely adding FULL ahead of today's file records/history/publication leaves the old waits in place;
  • unopened tasks need a capture that freezes the seed without first waiting on the ordinary history seed. Otherwise cold ticks miss the new path;
  • current action results contain a later history version. The separate version range plus epoch is a compatibility change and requires every enabled adapter/client to support it;
  • pending reads and search source generations must show accepted content, while filesystem editors can lag;
  • surviving accepted local redo is not disposable provider work on #918 epoch rotation. Backup restore still deliberately chooses an older point in time;
  • an outside-write conflict retains both versions and needs resolution. Unconditional convergence while outside editors keep changing files is not a safe promise.

spike status: blocked, no new measurements

Both perf VMs were reachable using timeout 60 netbird ssh with the brief's retry policy. Disk checks: perf-01 74 GiB available; perf-02 33 GiB available. The perf-01 acquisition queued behind the active n887-index-hold / n887-matrix measurement (a candidate process was running). Another mail932-hold acquisition was also queued. No other agent's process or lock was stopped. This task did not acquire both shared locks and therefore did not run the probe, a product dev-vs-dev control, or notes typing gates. There are no new latency numbers or gate passes to report.

The existing #898 measurements remain the evidence for flush cost, not fresh results: span breakdown, comment 77110, quiet rerun, comment 77166, follow-up rerun and control caveat, comment 77221. In particular, that source describes about nine remaining flushes for one executor write, rather than an implemented three-flush executor baseline.

disposable storage spike for the next free window

This is a storage analogue, not a replacement for a product dev-vs-dev control. It compares one FULL commit of frozen pre/post bytes plus a history-sized payload with that same commit plus file fsync and parent fsync. Two identical baseline labels let a reviewer see drift within the analogue. It covers 4 KiB and 64 KiB files; five warmups then 100 samples per batch, order baseline-a, baseline-b, entry, entry, baseline-b, baseline-a. Default WAL checkpoints stay enabled.

Run only after holding ~/bin/perf-lock on perf-01 then perf-02 together, with df -h / passing: ~/bin/slot python3 ~/save-log-design-1104-spike.py. Use the existing Nix-provided Python; no compilation or package install is needed. It removes its scratch databases and keeps a small JSON result. Post that JSON here, not in the repository. Release both locks before leaving. Follow with the actual dev-vs-dev/product gates in the plan; this analogue omits background history/file/completion work and cannot establish throughput, typing, or tick p95.

SHA-256 of the following exact script: 4af3672091380b422fdb76fdf5302cc840f37e497a447e16ed1ba5e2960efb5c.

throwaway spike.py (artifact, not repository code) 
"""Disposable storage-only probe. It does not run the product or prove its gates."""
import sqlite3,os,time,json,statistics,tempfile,shutil,hashlib,platform
from pathlib import Path
root=Path(tempfile.mkdtemp(prefix='save-log-spike-',dir=Path.home()))
def pct(xs,p): return sorted(xs)[min(len(xs)-1,int(len(xs)*p))]
results=[]
try:
 for size in (4096,65536):
  payload=json.dumps({'v':1,'home':'fixture','id':'action-fixture','path':'task.md','base':1,'pre':('a'*(size-1)+'\n'),'post':('b'*(size-1)+'\n'),'history_redo':('c'*size),'events':[{'kind':'notes.saved','item':'fixture'}],'reply':{'changed':True}}).encode()
  for batch,label in enumerate(('dev-a','dev-b','entry','entry','dev-b','dev-a')):
   folder=root/(str(size)+'-'+str(batch));folder.mkdir()
   db=sqlite3.connect(folder/'index.db',isolation_level=None)
   db.executescript("PRAGMA journal_mode=WAL; PRAGMA synchronous=NORMAL; CREATE TABLE journal(seq INTEGER PRIMARY KEY AUTOINCREMENT,kind TEXT,item TEXT,data TEXT); CREATE TABLE redo(seq INTEGER PRIMARY KEY,payload BLOB); CREATE TABLE receipt(key TEXT PRIMARY KEY,digest TEXT,result TEXT);")
   target=folder/'task.md';target.write_bytes(b'a'*(size-1)+b'\n')
   fd=os.open(folder,os.O_DIRECTORY)
   xs=[]; commits=[];files=[];dirs=[]
   for i in range(105):
    start=time.perf_counter_ns()
    db.execute('PRAGMA synchronous=FULL')
    db.execute('BEGIN IMMEDIATE')
    db.execute('INSERT INTO journal(kind,item,data) VALUES (?,?,?)',('notes.saved','fixture','{}'))
    seq=db.execute('SELECT last_insert_rowid()').fetchone()[0]
    db.execute('INSERT INTO redo VALUES (?,?)',(seq,payload))
    db.execute('INSERT INTO receipt VALUES (?,?,?)',(str(i),'fixture','{"changed":true}'))
    db.execute('COMMIT');db.execute('PRAGMA synchronous=NORMAL')
    committed=time.perf_counter_ns();f=committed;d=committed
    if label!='entry':
     tmp=folder/'task.tmp'
     with open(tmp,'wb') as out:
      out.write(b'b'*(size-1)+b'\n');out.flush();os.fsync(out.fileno())
     f=time.perf_counter_ns();os.replace(tmp,target);os.fsync(fd);d=time.perf_counter_ns()
    if i>=5:
     xs.append((d-start)/1e6);commits.append((committed-start)/1e6);files.append((f-committed)/1e6);dirs.append((d-f)/1e6)
   results.append({'file_bytes':size,'entry_bytes':len(payload),'batch':batch,'label':label,'n':100,'p50_ms':statistics.median(xs),'p95_ms':pct(xs,.95),'p99_ms':pct(xs,.99),'commit_p50_ms':statistics.median(commits),'file_p50_ms':statistics.median(files),'dir_p50_ms':statistics.median(dirs)})
   print(json.dumps(results[-1]),flush=True)
   os.close(fd);db.close();shutil.rmtree(folder)
 report={'utc':time.strftime('%Y-%m-%dT%H:%M:%SZ',time.gmtime()),'host':platform.node(),'python':platform.python_version(),'sqlite':sqlite3.sqlite_version,'script_sha256':hashlib.sha256(Path(__file__).read_bytes()).hexdigest(),'batches':results,'limitations':['storage-only analogue; dev-a/dev-b are identical three-barrier controls, not product dev binaries','entry excludes background history/file/completion work; no throughput or typing claim','real WAL checkpoints enabled; existing unrelated host disk load not controlled by VM locks']}
 Path.home().joinpath('save-log-design-1104-result.json').write_text(json.dumps(report,indent=2))
finally:
 shutil.rmtree(root)

Cleanup verified at 2026-11-04 22:30 IST: this task’s save-log-design-1104-hold unit is inactive on both perf VMs; both task-owned readiness markers removed. No measurement process or scratch database was started, and no task-owned VM job remains.

## source review and measurement status Head: `31258faef88dfe1e97c6f8f7f685f29ee7f31b75`. Docs only, one file. `git diff --check origin/dev...HEAD` passed; no product tests or builds were run for this document. Read the engine action/retry path, `commit_once` and store schema/writer; Notes executor admission/recovery/publication, history receipts, room loading/executor/save acks; fsio staging/exchange; Notes search generations/watchers; Tasks status capture/result; ADRs 0011/0020/0021/0044/0047 and storage guidance. Compared dev `9377d711`, #898 `2432b5a4` and #928 `d88a4c44`, including #898 comments 77003/77110/77166/77221 and #918/#919 issue text. #928 had no PR comments when read. Decisions proposed for review, not kayg-approved implementation decisions: - one transaction must include redo, permanent retry result and events. Merely adding FULL ahead of today's file records/history/publication leaves the old waits in place; - unopened tasks need a capture that freezes the seed without first waiting on the ordinary history seed. Otherwise cold ticks miss the new path; - current action results contain a later history version. The separate version range plus epoch is a compatibility change and requires every enabled adapter/client to support it; - pending reads and search source generations must show accepted content, while filesystem editors can lag; - surviving accepted local redo is not disposable provider work on #918 epoch rotation. Backup restore still deliberately chooses an older point in time; - an outside-write conflict retains both versions and needs resolution. Unconditional convergence while outside editors keep changing files is not a safe promise. ### spike status: blocked, no new measurements Both perf VMs were reachable using `timeout 60 netbird ssh` with the brief's retry policy. Disk checks: perf-01 74 GiB available; perf-02 33 GiB available. The perf-01 acquisition queued behind the active `n887-index-hold` / `n887-matrix` measurement (a candidate process was running). Another `mail932-hold` acquisition was also queued. No other agent's process or lock was stopped. This task did not acquire both shared locks and therefore did not run the probe, a product dev-vs-dev control, or notes typing gates. There are **no new latency numbers or gate passes** to report. The existing #898 measurements remain the evidence for flush cost, not fresh results: [span breakdown, comment 77110](https://git.kayg.org/kayg/calternal/pulls/898#issuecomment-77110), [quiet rerun, comment 77166](https://git.kayg.org/kayg/calternal/pulls/898#issuecomment-77166), [follow-up rerun and control caveat, comment 77221](https://git.kayg.org/kayg/calternal/pulls/898#issuecomment-77221). In particular, that source describes about nine remaining flushes for one executor write, rather than an implemented three-flush executor baseline. ### disposable storage spike for the next free window This is a storage analogue, **not a replacement for a product dev-vs-dev control**. It compares one FULL commit of frozen pre/post bytes plus a history-sized payload with that same commit plus file fsync and parent fsync. Two identical baseline labels let a reviewer see drift within the analogue. It covers 4 KiB and 64 KiB files; five warmups then 100 samples per batch, order baseline-a, baseline-b, entry, entry, baseline-b, baseline-a. Default WAL checkpoints stay enabled. Run only after holding `~/bin/perf-lock` on perf-01 then perf-02 together, with `df -h /` passing: `~/bin/slot python3 ~/save-log-design-1104-spike.py`. Use the existing Nix-provided Python; no compilation or package install is needed. It removes its scratch databases and keeps a small JSON result. Post that JSON here, not in the repository. Release both locks before leaving. Follow with the actual dev-vs-dev/product gates in the plan; this analogue omits background history/file/completion work and cannot establish throughput, typing, or tick p95. SHA-256 of the following exact script: `4af3672091380b422fdb76fdf5302cc840f37e497a447e16ed1ba5e2960efb5c`. <details><summary>throwaway spike.py (artifact, not repository code)</summary> ```python """Disposable storage-only probe. It does not run the product or prove its gates.""" import sqlite3,os,time,json,statistics,tempfile,shutil,hashlib,platform from pathlib import Path root=Path(tempfile.mkdtemp(prefix='save-log-spike-',dir=Path.home())) def pct(xs,p): return sorted(xs)[min(len(xs)-1,int(len(xs)*p))] results=[] try: for size in (4096,65536): payload=json.dumps({'v':1,'home':'fixture','id':'action-fixture','path':'task.md','base':1,'pre':('a'*(size-1)+'\n'),'post':('b'*(size-1)+'\n'),'history_redo':('c'*size),'events':[{'kind':'notes.saved','item':'fixture'}],'reply':{'changed':True}}).encode() for batch,label in enumerate(('dev-a','dev-b','entry','entry','dev-b','dev-a')): folder=root/(str(size)+'-'+str(batch));folder.mkdir() db=sqlite3.connect(folder/'index.db',isolation_level=None) db.executescript("PRAGMA journal_mode=WAL; PRAGMA synchronous=NORMAL; CREATE TABLE journal(seq INTEGER PRIMARY KEY AUTOINCREMENT,kind TEXT,item TEXT,data TEXT); CREATE TABLE redo(seq INTEGER PRIMARY KEY,payload BLOB); CREATE TABLE receipt(key TEXT PRIMARY KEY,digest TEXT,result TEXT);") target=folder/'task.md';target.write_bytes(b'a'*(size-1)+b'\n') fd=os.open(folder,os.O_DIRECTORY) xs=[]; commits=[];files=[];dirs=[] for i in range(105): start=time.perf_counter_ns() db.execute('PRAGMA synchronous=FULL') db.execute('BEGIN IMMEDIATE') db.execute('INSERT INTO journal(kind,item,data) VALUES (?,?,?)',('notes.saved','fixture','{}')) seq=db.execute('SELECT last_insert_rowid()').fetchone()[0] db.execute('INSERT INTO redo VALUES (?,?)',(seq,payload)) db.execute('INSERT INTO receipt VALUES (?,?,?)',(str(i),'fixture','{"changed":true}')) db.execute('COMMIT');db.execute('PRAGMA synchronous=NORMAL') committed=time.perf_counter_ns();f=committed;d=committed if label!='entry': tmp=folder/'task.tmp' with open(tmp,'wb') as out: out.write(b'b'*(size-1)+b'\n');out.flush();os.fsync(out.fileno()) f=time.perf_counter_ns();os.replace(tmp,target);os.fsync(fd);d=time.perf_counter_ns() if i>=5: xs.append((d-start)/1e6);commits.append((committed-start)/1e6);files.append((f-committed)/1e6);dirs.append((d-f)/1e6) results.append({'file_bytes':size,'entry_bytes':len(payload),'batch':batch,'label':label,'n':100,'p50_ms':statistics.median(xs),'p95_ms':pct(xs,.95),'p99_ms':pct(xs,.99),'commit_p50_ms':statistics.median(commits),'file_p50_ms':statistics.median(files),'dir_p50_ms':statistics.median(dirs)}) print(json.dumps(results[-1]),flush=True) os.close(fd);db.close();shutil.rmtree(folder) report={'utc':time.strftime('%Y-%m-%dT%H:%M:%SZ',time.gmtime()),'host':platform.node(),'python':platform.python_version(),'sqlite':sqlite3.sqlite_version,'script_sha256':hashlib.sha256(Path(__file__).read_bytes()).hexdigest(),'batches':results,'limitations':['storage-only analogue; dev-a/dev-b are identical three-barrier controls, not product dev binaries','entry excludes background history/file/completion work; no throughput or typing claim','real WAL checkpoints enabled; existing unrelated host disk load not controlled by VM locks']} Path.home().joinpath('save-log-design-1104-result.json').write_text(json.dumps(report,indent=2)) finally: shutil.rmtree(root) ``` </details> Cleanup verified at 2026-11-04 22:30 IST: this task’s `save-log-design-1104-hold` unit is inactive on **both** perf VMs; both task-owned readiness markers removed. No measurement process or scratch database was started, and no task-owned VM job remains.
kayg commented 2026-11-04 17:27:37 +00:00
Author
Owner
Copy link

measured spike: quiet and shared-disk contention

The blocked status in comment 78441 is superseded. Both official locks were acquired in order (perf-01, then perf-02) and held together for every measurement. Repeated foreground waits stayed below 480 s; every NetBird SSH step used timeout 60 with up to three attempts. Measurement units, the contention worker and both lock units are now stopped. No product code changed.

Raw samples, per-batch output, frozen entry, scripts, profiler source and hash manifest. Archive SHA-256: 0e38e877596e1f8cbe7d944da215ec48f783c851ff44dd2f73b3ba262a6ff20f.

what ran

  • perf-01 measured; perf-02 supplied one controlled I/O worker, through ~/bin/slot, while this task held its lock. That worker overwrote a bounded 64 MiB file in 4 MiB blocks and fsynced each block. It ran 214.5 s at 227.2 MiB/s logical guest writes; worker fsync p50/p95 15.92/21.93 ms. The file was removed on stop. This reproduces measured shared-disk contention, not every possible host load.
  • Quiet: 2026-11-04 22:47:10–22:48:14 IST. Contended: 22:49:59–22:51:54 IST. A 100-sample 4 KiB fsync probe before/after each window checked the disk condition.
  • Real local HTTP tasks.set-status calls on one 4 KiB task, alternating done/todo, fresh state for each batch, five warmups then 40 timed actions. Case order: dev-a, dev-b, #898 plain, #898 profiled, #898 profiled, #898 plain, dev-b, dev-a. Each pooled label has 80 samples/window. All cases completed without retries or HTTP failures.
  • Dev control is one identical binary twice, SHA ef22c21cabe7711730ce68c4a16fc473ec55c042aa9b4bb9a64211335d3780a7, built on dev-01 from 41f2efa387b74175971a838f602535089d0d5fb4. The relevant engine/store/notes/tasks/fsio trees are identical to this plan's dev base 9377d711 (git diff empty).
  • #898 binary SHA d05915117b4ef077a20ef03623873f4392b2e2e3e24d4d0b44606acb9016a0ff, from 1b81f85213, matching #898 comment 77110. This is the previously built binary, not a claim that its later worktree head 2432b5a4 was rebuilt. Both product binaries were relayed dev-01 → control → perf-01 with SHA-256 checked.
  • A small C profiler, built on dev-01 through Nix and ~/bin/slot cc -shared -fPIC -O2, intercepts fsync/fdatasync, performs the actual kernel calls, and records start/end intervals to /dev/shm. It changes no sync flags and writes no trace to the tested disk. Tick residual = request wall time minus the union of intersecting sync intervals, so overlapping waits count once. The attachment contains every interval.
  • The storage probe uses an actual frozen executor record plus reply/events: 67,398 encoded bytes, one 4,268-byte markdown file. This is a conservative payload stand-in for the proposed format, not an implemented new encoder. One FULL WAL transaction inserts event, redo, publication receipt and retry result. Compare that transaction alone against the same transaction plus atomic file write/fsync and parent fsync. SQLite default autocheckpoints stay enabled. Eight warmups, then 120 samples/batch; order three-a, three-b, one, one, three-b, three-a. Pooled n = 240 one-commit, 480 three-barrier per window. SQLite version is in the raw result.

storage, ms (pooled nearest-rank tails, no samples discarded)

disk one FULL p50 / p95 / p99 three barriers p50 / p95 / p99 p95 delta
quiet 2.35 / 6.19 / 16.95 10.69 / 16.17 / 24.52 -61.7%
contended 7.07 / 14.61 / 36.88 30.47 / 41.20 / 50.07 -64.5%

“Three barriers” is the requested storage comparison, not the complete current executor. The real #898 requests recorded 11 sync calls each in this fixture, including existing file records/history/publication.

disk probe, p50 / p95 ms before after
quiet 3.98 / 4.14 3.99 / 4.34
contended 10.35 / 15.19 10.57 / 18.85

After stopping the load, the recovery probe was 6.80 / 9.17 ms. VM locks cannot prevent unrelated host I/O; the observed probes and controls define these windows.

controls and real current tick path

disk dev-a p50 / p95 dev-b p50 / p95 dev-b delta p50 / p95
quiet 181.45 / 287.29 188.84 / 287.04 +4.1% / -0.1%
contended 300.05 / 416.15 298.98 / 419.24 -0.4% / +0.7%

The duplicate three-barrier storage control's p95 delta is -3.2% quiet and +5.7% contended. The one-commit change is much larger than either control spread.

disk #898 plain tick p50 / p95 #898 profiled tick p50 / p95 profiled non-flush residual p95
quiet 55.04 / 58.80 55.40 / 73.07 12.14
contended 130.47 / 145.06 130.65 / 153.75 12.10

The plain/profiled p95 differs, especially in the quiet window; no correction or tail exclusion was applied. Residuals are a measured decomposition, not proof that all sync intervals were on the critical path.

measured-component tick estimate versus 40 ms

disk residual p95 + one FULL p95 component estimate headroom to 40 ms
quiet 12.14 + 6.19 18.33 ms 21.67 ms
contended 12.10 + 14.61 26.71 ms 13.29 ms

This is a sum of two separately measured p95 components, not a measured candidate p95 and not a mathematical bound on its tail. It supports the one-commit design for this clean, warm 4 KiB single-task case. It does not prove the 10k-fixture gate, cold capture, multiple owner notes, new accepted-read/version costs, throughput/drain stability, or notes typing flatness. Those remain hard first-implementation-PR gates. The contended commit p99 alone is 36.88 ms, so no all-requests-under-40 claim is justified.

exact reproduction commands

With both ~/bin/perf-lock units held, and Nix-provided Python first in PATH:

# perf-01, first without load, then with the worker running on perf-02
~/bin/slot bash ~/perf/save-log-spike-1104/window.sh quiet
~/bin/slot bash ~/perf/save-log-spike-1104/window.sh contended
# perf-02 contention worker, externally holding that VM's official lock too
~/bin/slot python3 ~/perf/save-log-spike-1104/disk_load.py
# perf-01, after stopping the worker and before releasing locks
~/bin/slot python3 ~/perf/save-log-spike-1104/quiet_check.py recovered-quiet

The archived window.sh contains every real-action/storage command, and manifest.json identifies source and binary hashes. Storage databases and per-batch Homes were removed by each script. The large copied VM binaries have been removed. Raw artifacts remain attached here; kayg explicitly requested the measured summary tables in the plan in this follow-up, superseding the brief's design-only-table rule for this document.

Final documentation head: 3de4e91edb6cdec8f53ef6f25bee17687ea23e4e. git diff --check origin/dev...HEAD passed; worktree clean, only docs/plans/save-log-durable-entry.md changed. Verified every task-owned build, smoke, quiet, contended, load and lock unit inactive; no scratch Home/storage directory remains.

## measured spike: quiet and shared-disk contention The blocked status in comment 78441 is superseded. Both official locks were acquired in order (perf-01, then perf-02) and held together for every measurement. Repeated foreground waits stayed below 480 s; every NetBird SSH step used `timeout 60` with up to three attempts. Measurement units, the contention worker and both lock units are now stopped. No product code changed. [Raw samples, per-batch output, frozen entry, scripts, profiler source and hash manifest](https://git.kayg.org/attachments/520e89d3-62ae-49d8-a99d-07fd57becce8). Archive SHA-256: `0e38e877596e1f8cbe7d944da215ec48f783c851ff44dd2f73b3ba262a6ff20f`. ### what ran - perf-01 measured; perf-02 supplied one controlled I/O worker, through `~/bin/slot`, while this task held its lock. That worker overwrote a bounded 64 MiB file in 4 MiB blocks and fsynced each block. It ran 214.5 s at 227.2 MiB/s logical guest writes; worker fsync p50/p95 15.92/21.93 ms. The file was removed on stop. This reproduces measured shared-disk contention, not every possible host load. - Quiet: 2026-11-04 **22:47:10–22:48:14 IST**. Contended: **22:49:59–22:51:54 IST**. A 100-sample 4 KiB fsync probe before/after each window checked the disk condition. - Real local HTTP `tasks.set-status` calls on one 4 KiB task, alternating done/todo, fresh state for each batch, five warmups then 40 timed actions. Case order: dev-a, dev-b, #898 plain, #898 profiled, #898 profiled, #898 plain, dev-b, dev-a. Each pooled label has 80 samples/window. All cases completed without retries or HTTP failures. - Dev control is **one identical binary twice**, SHA `ef22c21cabe7711730ce68c4a16fc473ec55c042aa9b4bb9a64211335d3780a7`, built on dev-01 from `41f2efa387b74175971a838f602535089d0d5fb4`. The relevant engine/store/notes/tasks/fsio trees are identical to this plan's dev base `9377d711` (`git diff` empty). - #898 binary SHA `d05915117b4ef077a20ef03623873f4392b2e2e3e24d4d0b44606acb9016a0ff`, from **1b81f852133ca2df3fe3226fb1b4eee143d7a2c5**, matching #898 comment 77110. This is the previously built binary, not a claim that its later worktree head 2432b5a4 was rebuilt. Both product binaries were relayed dev-01 → control → perf-01 with SHA-256 checked. - A small C profiler, built on dev-01 through Nix and `~/bin/slot cc -shared -fPIC -O2`, intercepts `fsync`/`fdatasync`, performs the actual kernel calls, and records start/end intervals to `/dev/shm`. It changes no sync flags and writes no trace to the tested disk. Tick residual = request wall time minus the **union** of intersecting sync intervals, so overlapping waits count once. The attachment contains every interval. - The storage probe uses an actual frozen executor record plus reply/events: **67,398 encoded bytes**, one **4,268-byte** markdown file. This is a conservative payload stand-in for the proposed format, not an implemented new encoder. One FULL WAL transaction inserts event, redo, publication receipt and retry result. Compare that transaction alone against the same transaction plus atomic file write/fsync and parent fsync. SQLite default autocheckpoints stay enabled. Eight warmups, then 120 samples/batch; order three-a, three-b, one, one, three-b, three-a. Pooled n = 240 one-commit, 480 three-barrier per window. SQLite version is in the raw result. ### storage, ms (pooled nearest-rank tails, no samples discarded) | disk | one FULL p50 / p95 / p99 | three barriers p50 / p95 / p99 | p95 delta | |---|---|---|---| | quiet | **2.35 / 6.19 / 16.95** | 10.69 / 16.17 / 24.52 | -61.7% | | contended | **7.07 / 14.61 / 36.88** | 30.47 / 41.20 / 50.07 | -64.5% | “Three barriers” is the requested storage comparison, **not the complete current executor**. The real #898 requests recorded **11 sync calls each** in this fixture, including existing file records/history/publication. | disk probe, p50 / p95 ms | before | after | |---|---|---| | quiet | 3.98 / 4.14 | 3.99 / 4.34 | | contended | 10.35 / 15.19 | 10.57 / 18.85 | After stopping the load, the recovery probe was 6.80 / 9.17 ms. VM locks cannot prevent unrelated host I/O; the observed probes and controls define these windows. ### controls and real current tick path | disk | dev-a p50 / p95 | dev-b p50 / p95 | dev-b delta p50 / p95 | |---|---|---|---| | quiet | 181.45 / 287.29 | 188.84 / 287.04 | +4.1% / -0.1% | | contended | 300.05 / 416.15 | 298.98 / 419.24 | -0.4% / +0.7% | The duplicate three-barrier storage control's p95 delta is -3.2% quiet and +5.7% contended. The one-commit change is much larger than either control spread. | disk | #898 plain tick p50 / p95 | #898 profiled tick p50 / p95 | profiled non-flush residual p95 | |---|---|---|---| | quiet | 55.04 / 58.80 | 55.40 / 73.07 | **12.14** | | contended | 130.47 / 145.06 | 130.65 / 153.75 | **12.10** | The plain/profiled p95 differs, especially in the quiet window; no correction or tail exclusion was applied. Residuals are a measured decomposition, not proof that all sync intervals were on the critical path. ### measured-component tick estimate versus 40 ms | disk | residual p95 + one FULL p95 | component estimate | headroom to 40 ms | |---|---|---|---| | quiet | 12.14 + 6.19 | **18.33 ms** | **21.67 ms** | | contended | 12.10 + 14.61 | **26.71 ms** | **13.29 ms** | This is a **sum of two separately measured p95 components**, not a measured candidate p95 and not a mathematical bound on its tail. It supports the one-commit design for this clean, warm 4 KiB single-task case. It does not prove the 10k-fixture gate, cold capture, multiple owner notes, new accepted-read/version costs, throughput/drain stability, or notes typing flatness. Those remain hard first-implementation-PR gates. The contended commit p99 alone is 36.88 ms, so no all-requests-under-40 claim is justified. ### exact reproduction commands With both `~/bin/perf-lock` units held, and Nix-provided Python first in PATH: ```sh # perf-01, first without load, then with the worker running on perf-02 ~/bin/slot bash ~/perf/save-log-spike-1104/window.sh quiet ~/bin/slot bash ~/perf/save-log-spike-1104/window.sh contended # perf-02 contention worker, externally holding that VM's official lock too ~/bin/slot python3 ~/perf/save-log-spike-1104/disk_load.py # perf-01, after stopping the worker and before releasing locks ~/bin/slot python3 ~/perf/save-log-spike-1104/quiet_check.py recovered-quiet ``` The archived `window.sh` contains every real-action/storage command, and `manifest.json` identifies source and binary hashes. Storage databases and per-batch Homes were removed by each script. The large copied VM binaries have been removed. Raw artifacts remain attached here; kayg explicitly requested the measured summary tables in the plan in this follow-up, superseding the brief's design-only-table rule for this document. Final documentation head: `3de4e91edb6cdec8f53ef6f25bee17687ea23e4e`. `git diff --check origin/dev...HEAD` passed; worktree clean, only `docs/plans/save-log-durable-entry.md` changed. Verified every task-owned build, smoke, quiet, contended, load and lock unit inactive; no scratch Home/storage directory remains.
kayg commented 2026-11-07 19:33:45 +00:00
Author
Owner
Copy link

housekeeping #1009: rebased+green, left open for review.

rebased durable-entry design proposal; no implementation claim.

head: 940ef22bd24cf7ed956dfa9286d55c8ea14b5d7d. rebased onto dev cd7f84432febfc63b788fbb9b9f9950452982d74 and pushed with the original exact force-with-lease.

validation on the Mac VM, through Nix and the shared Mac lock/slot: root bun install --frozen-lockfile; in apps/web, bun run check, bun run lint, bun run build, bun run test; PERF_DIST=<worktree>/apps/web/dist bash perf/web.sh --bundle-only --gate. all passed. this documentation-only branch has no targeted browser specs or Rust implementation changes. exact commands, logs, and dev bundle control.

original-head missing-commit/patch inventory, file pr-938.md.

housekeeping #1009: rebased+green, left open for review. rebased durable-entry design proposal; no implementation claim. head: `940ef22bd24cf7ed956dfa9286d55c8ea14b5d7d`. rebased onto dev `cd7f84432febfc63b788fbb9b9f9950452982d74` and pushed with the original exact force-with-lease. validation on the Mac VM, through Nix and the shared Mac lock/slot: root `bun install --frozen-lockfile`; in `apps/web`, `bun run check`, `bun run lint`, `bun run build`, `bun run test`; `PERF_DIST=<worktree>/apps/web/dist bash perf/web.sh --bundle-only --gate`. all passed. this documentation-only branch has no targeted browser specs or Rust implementation changes. [exact commands, logs, and dev bundle control](https://git.kayg.org/attachments/64244177-fd81-4992-860e-4d5d22ca01cd). [original-head missing-commit/patch inventory](https://git.kayg.org/attachments/fe3c09dc-dea3-47a0-92e2-b44a777083e5), file `pr-938.md`.
Some checks failed
CI / server (pull_request) Has been cancelled
Details
CI / rust (pull_request) Has been cancelled
Details
CI / web (pull_request) Has been cancelled
Details
Markdown extraction contract / markdown-native-contract (pull_request) Has been cancelled
Details
Markdown extraction contract / markdown-editor-contract (pull_request) Has been cancelled
Details
Merge conflict checking is in progress. Try again in few moments.
View command line instructions

Checkout

From your project repository, check out a new branch and test the changes.
git fetch -u origin plan/save-log-durable-entry:plan/save-log-durable-entry
git switch plan/save-log-durable-entry

Merge

Merge the changes and update on Forgejo.

Warning: The "Autodetect manual merge" setting is not enabled for this repository, you will have to mark this pull request as manually merged afterwards.

git switch dev
git merge --no-ff plan/save-log-durable-entry
git switch plan/save-log-durable-entry
git rebase dev
git switch dev
git merge --ff-only plan/save-log-durable-entry
git switch plan/save-log-durable-entry
git rebase dev
git switch dev
git merge --no-ff plan/save-log-durable-entry
git switch dev
git merge --squash plan/save-log-durable-entry
git switch dev
git merge --ff-only plan/save-log-durable-entry
git switch dev
git merge plan/save-log-durable-entry
git push origin dev
Sign in to join this conversation.
Reviewers
No reviewers
Labels
Clear labels   
backend
Rust server

  
design
Mockups, UI and TASTE

  
docs
ADRs, CONTEXT, TASTE

  
idea
Parked idea, never worked until promoted

  
infra
Deploy, CI, VMs

  
perf
Performance and budgets

  
reliability
Data integrity, corruption traps

  
web
Web client

No labels
backend
design
docs
idea
infra
perf
reliability
web
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
kayg/calternal!938
No description provided.