Skip to content

Commit 879a805

Browse files
committed
Type the values nobody had typed, and run a runbook
The fifth pass left a list of what had never been audited. This works it: load at the size the lab actually is, the loop in front of a slow board, and an adversarial read of the one script that runs once against a database nobody has seen. Five defects, each proved by running it first. 1. A page cursor too big to be an id answered 503. Number('9223372036854775807') is 9223372036854776000, so a cursor past Number.MAX_SAFE_INTEGER stops being the number that was typed and Postgres refuses it for a bigint. The bigint maximum itself failed, and so did 1e30, which arrives as "1e+30" and is not even integer syntax. All three paginated routes: /api/audit, /api/door/events and /api/me/door-events. A cursor that big means the same thing as no cursor, which is to start from the newest, so that is what page() does with one now. 2. A null byte in any text field answered 503. A Postgres text column cannot hold U+0000 and postgres.js hands the value straight through, so signup, a profile edit and a credential label all read as the database being down. text() is the one place every free text field goes through and it now answers null for a string the database cannot store, which is what its contract already said it does for a string that is not one. readPatch checks it before the per field branches, because that is where the contact fields bypass text(). 3. A command result and the event recording it were two writes. POST /door/commands/:id/result updated door_commands and then inserted into door_events as separate statements. A detail jsonb refused left the command resolved with nothing recording it, and answered 503 saying "Nothing was changed" when the command row had been. Proved against the running stack: the command read done, the event count read zero, and the caller was told nothing had moved. Rule Four of the README is that a change and its record go in the same transaction, not beside it. change() makes that impossible to forget for audit_log and door_events was outside it. Both this and the expiry path in the same file are one transaction now. A transaction on its own would turn an unstorable detail into a command re-claimed and re-run forever, which is the poison message the second pass already fixed once for events. So the detail is dropped and logged where jsonb cannot hold it, the same way `when` replaces a time that is not a time. In POST /door/events that is a straight improvement: a card read whose detail was unstorable used to be skipped, losing the card id that enrolment depends on, and now the event lands without its decoration. 4. The first step of a 2am runbook cannot be run. the-door-service-will-not-talk-to-the-controller.md opens with `curl -s localhost:9000`. The health server binds to localhost inside the container and compose.lab.yml publishes no port, because this service accepts nothing inbound, so on the lab host that connects to nothing. The line above it reaches into the container for the logs, so the shape was known. Running the corrected command turned up a second layer: localhost inside the image resolves to IPv6 first and the health server is on IPv4, so it needs the address rather than the name. Both docs now carry the command that was run here and answered. The health answer also gains `running`, whether a pass is in flight. A slow board takes as long as it takes, and without that the answer during one is ok with a lastTickAt from before it started, which is the reading a volunteer takes from step one. 5. The import report counted intentions rather than rows. scripts/import.ts has always skipped a row it could not place and the report counted the legacy table. Against a fixture carrying a payment with no date and a grant naming a certification that is not there, it printed payments: 5 and wrote three, and said nothing about two of the four rows it dropped. Money and tool access, in the script whose whole job is to report rather than guess. The counts are what will be written now, with a leftBehind beside them, every dropped row is named with its reason, and the write walks the same lists the preflight counted so the two cannot drift. A preflight refusal is added for two certifications that normalise to one slug, which would merge two tool certifications and misplace every grant of the second. The ten production slugs are distinct, so that one is a guard rather than a fix. Measured, from the same list. The directory at a thousand members with every free text field full is a 4.1 MB answer in 0.15 s. Twenty at once cost the API container about 90 MB on top of a resting 125 MB, against the 512 MB it is limited to, and serialise from 0.49 s to 2.67 s. The choice to answer with everybody stands, and the number says not to poll it. A ?q= pattern cannot be made expensive: name and email are short, so the worst measured 115 ms. A first pass writing 200 cards is 203 requests with nothing bounding a pass as a whole. 10.4 s at 50 ms a request, 41 s at 200 ms, during which no command is claimed. Commands expire at 120 s, so at 200 cards a pass slower than about 590 ms a request expires them before claiming them. The lab holds 64 cards, so the real figure is about 1.8 s a request. Proved sound, and recorded so nobody spends the time again: the import does not need null guards on email or the timestamps. Those columns are null: false in db/schema.rb, which the fixture mirrors, and the tolerance rule in CONTRIBUTING is about *_id columns dangling, every one of which the import already handles. That was about to be changed. Image scanning is still not done. docker scout wants a login this session did not have, and it is written down in section 5 with the command. API suite 85 tests to 89. Typecheck, the copy gate and both suites green.
1 parent 1c1aa71 commit 879a805

9 files changed

Lines changed: 431 additions & 63 deletions

File tree

HANDOFF.md

Lines changed: 138 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
What exists, what is not done, what nobody has confirmed, and who has to decide.
44
Adding to this file is not an admission. It is the point.
55

6-
Last updated 2026-09-12, after the five passes in section 6.
6+
Last updated 2026-09-12, after the six passes in section 6.
77

88
## 1. State
99

@@ -19,7 +19,7 @@ the fifth pass from 2026-09-12.
1919

2020
- `make typecheck`: clean for both services.
2121
- `make voice`: clean.
22-
- The API suite, 85 tests, against a real Postgres with the schema built from
22+
- The API suite, 89 tests, against a real Postgres with the schema built from
2323
nothing by `scripts/migrate.ts`.
2424
- The door suite, 39 tests, including the whole codec over a real socket.
2525
- The CI workflow, step for step, from a clean checkout: three `npm ci`
@@ -68,6 +68,18 @@ The fifth pass ran these for the first time.
6868
the API image from the pinned `node`, and `docker create` on the pinned
6969
`postgres` and `caddy`, which is the form CI and compose both use.
7070

71+
The sixth pass ran these for the first time.
72+
73+
- **The directory at the size the lab actually is.** A thousand members, every
74+
free text field full, read as a member reads it. Numbers in section 6.
75+
- **The loop in front of a slow board**, which is what the real one is. A first
76+
pass writing two hundred cards, timed at 50 ms and at 200 ms a request.
77+
- **The health endpoint, from where the runbook says to read it.** That is how
78+
the fourth defect below was found: it cannot be read from there.
79+
- **The import against a fixture carrying the rows nobody had planted**, a
80+
payment with no date and a grant naming a certification that is not there,
81+
then applied and counted against what the report promised.
82+
7183
### What has not been run
7284

7385
Anything involving the real controller, and the import against the real dump.
@@ -250,6 +262,20 @@ These block deployment, not development. None is technical.
250262
lets a service which died mid-command pick the command back up. The case is a
251263
deploy where the old container outlives the new one, or two lab hosts pointed
252264
at one controller id, and the commands themselves are all safe to run twice.
265+
- **An optional text field that cannot be stored is dropped rather than
266+
refused.** A label or a note carrying U+0000 now makes `text` answer null, and
267+
a route that treats the field as optional writes null and answers 201. That is
268+
the same thing an over-long label has always done, so it is consistent rather
269+
than new, and it is worth knowing that the value went missing quietly. The
270+
required fields refuse with a 400.
271+
- **The directory is a 4.1 MB answer at a thousand members** with every free text
272+
field full, and twenty concurrent reads cost about 90 MB of the API
273+
container's 512 MB. Section 6 has the measurements. Nothing is wrong; it means
274+
this route is not one to poll, and there is no front end yet to poll it.
275+
- **The base images are pinned and still unscanned.** `docker scout cves` against
276+
the pinned digest is the command, and it wants a Docker Hub login this session
277+
did not have. Now that the digests are pinned, a scan is at least reproducible
278+
and says something about a known artifact.
253279
- **Nothing retires a controller.** `door_state` rows are written by the
254280
controller and removed only when that same controller stops naming a door, so
255281
a board that is unplugged sits there forever with a frozen `reported_at`.
@@ -309,8 +335,8 @@ These block deployment, not development. None is technical.
309335

310336
## 6. The audits, and what they taught
311337

312-
Five adversarial passes over the whole branch, on 2026-09-11 and 2026-09-12,
313-
after it was first written. Forty three defects, each proved with a probe or a
338+
Six adversarial passes over the whole branch, on 2026-09-11 and 2026-09-12,
339+
after it was first written. Forty eight defects, each proved with a probe or a
314340
failing test before it was fixed, and each fix covered by a test where a test
315341
can reach it.
316342

@@ -327,6 +353,7 @@ of the same.
327353
| 3 | Line by line, every file, nothing assumed | 16 |
328354
| 4 | Running the things that had only been written | 3 |
329355
| 5 | Two controllers, a soak, concurrency, and measuring | 4 |
356+
| 6 | Load at lab size, a slow board, and the import script | 5 |
330357

331358
### The patterns
332359

@@ -388,6 +415,48 @@ controllers to reach it. With two reporting, a command that does not name one
388415
answered 503, and so did a command naming a controller that does not exist, with
389416
the text "No controller has reported to this API" while two were reporting.
390417

418+
**And two more shapes of it in the sixth pass, which is seven in all.** A
419+
`?before=` cursor past `Number.MAX_SAFE_INTEGER` stopped being the number that
420+
was typed: the largest bigint arrives as 9223372036854776000, Postgres refuses
421+
it, and paging too far on any of the three paginated routes read as the database
422+
being down. The bigint maximum itself failed, so the shape was not exotic. And a
423+
body carrying U+0000 in any text field answered 503 on every route that stores
424+
one, because a Postgres text column cannot hold that byte and postgres.js hands
425+
it straight through. Seven shapes of one pattern over six passes is the argument
426+
for reading the whole class rather than the instance: the question is not "is
427+
this input rejected" but "does every value the caller controls reach the database
428+
as something the database can take".
429+
430+
**Two writes that had to be one.** Rule Four of the README is that a privileged
431+
change and its audit row go in the same transaction, not beside it, and `change`
432+
makes that impossible to forget for `audit_log`. `door_events` was left outside
433+
it. `POST /door/commands/:id/result` updated the command and then inserted the
434+
event as two statements, so a detail the database refused left the command
435+
resolved with nothing recording it, and answered 503 saying "Nothing was
436+
changed" when the command row had been. The expiry path in the same file had the
437+
same shape. Both are one transaction now. The rule was right and the reach of the
438+
thing that enforces it was too short.
439+
440+
**A runbook step that cannot be run.** `docs/runbooks/the-door-service-will-not-
441+
talk-to-the-controller.md` opens with `curl -s localhost:9000`, and that cannot
442+
work on the lab host: the health server binds to localhost inside the container
443+
and `compose.lab.yml` publishes no port, because this service accepts nothing
444+
inbound. The line above it correctly reaches into the container for the logs.
445+
Running it turned up a second layer as well, that `localhost` inside the image
446+
resolves to IPv6 first while the health server is on IPv4, so even the corrected
447+
command needed the address rather than the name. Step one of the 2am runbook,
448+
for the failure the runbook is named after.
449+
450+
**A report that counted intentions rather than rows.** `scripts/import.ts` has
451+
always skipped a row it could not place, and the report counted the legacy table.
452+
Against a fixture with a payment carrying no date and a grant naming a
453+
certification that is not there, it printed `payments: 5` and wrote three, and
454+
said nothing at all about two of the four rows it dropped. Money and tool access,
455+
in the script that runs once, against the database nobody has seen, whose whole
456+
job is to report rather than guess. The counts are what will be written now,
457+
every dropped row is named with its reason, and both come from the same
458+
predicates the write walks.
459+
391460
**Something that only grows.** Two of them, and only a soak reaches either. The
392461
simulator remembered every query it had ever answered, measured at about 105
393462
bytes a request and 11 MB per hundred thousand, which is nine days at the tick
@@ -453,6 +522,39 @@ minute of load, so nothing writes a row per poll. That last one is the property
453522
the schema was shaped around: the legacy system wrote a status snapshot on every
454523
poll and reached 2.8 million of them.
455524

525+
### What the sixth pass measured
526+
527+
**The directory at the size the lab actually is.** A thousand members, every one
528+
carrying a full 2,000 characters of current skills and desired skills, which is
529+
the worst case rather than the usual one. One read is 4.1 MB and takes 0.15
530+
seconds. Twenty at once cost the API container about 90 MB on top of its resting
531+
125 MB, against the 512 MB it is limited to, and they serialise: the first
532+
answers in 0.49 seconds and the twentieth in 2.67. Three more waves of twenty
533+
settled at 218 MB and did not climb further.
534+
535+
That is the price of the choice in `directory`, which answers with everybody
536+
rather than a page, because a cap below the size of the membership hides people
537+
from each other without saying so. The choice stands and the number is now
538+
written down. What it rules out is polling this route from a screen.
539+
540+
**`?q=` cannot be made expensive.** The pattern goes into an `ilike` with `%` and
541+
`_` unescaped, which is a known gap below, so the obvious next question is
542+
whether a pattern can be made to cost something. It cannot: `name` and `email`
543+
are short, so the worst pattern measured 115 ms through the API and a sixty
544+
repeat `_%` pattern straight at Postgres took 4 ms. It is a correctness wart,
545+
not a way to take the API down.
546+
547+
**A slow board blocks the loop for as long as it takes.** A first pass writing
548+
two hundred cards is 203 requests and nothing bounds a pass as a whole, only each
549+
request at 15 seconds. At 50 ms a request that pass is 10.4 seconds; at 200 ms it
550+
is 41 seconds, during which the five second tick is skipped eight times and no
551+
command is claimed. A command expires after 120 seconds, so the arithmetic that
552+
matters is 120 divided by the number of cards: at 200 cards a pass slower than
553+
about 590 ms a request expires commands before it claims them. The lab holds 64
554+
cards, so the real figure is about 1.8 seconds a request, and the board would
555+
have to be far slower than anybody has seen. Worth keeping in mind when the card
556+
table grows.
557+
456558
### What was proved not to be a defect
457559

458560
Each of these was about to be changed on a wrong belief. They are recorded so
@@ -485,6 +587,15 @@ nobody spends the time again.
485587
- **Commands are routed per controller correctly.** Two controllers, two
486588
simulated boards: each ran only what was queued for it, and a stale controller
487589
refusing a command does not stop the other one taking one.
590+
- **The import does not need to tolerate a null email or a null timestamp.**
591+
This was about to be changed. `LegacyUser` types `email`, `createdAt` and
592+
`updatedAt` as non-null where nearly every other field is nullable, and
593+
`user.email.trim()` would throw on a null before the preflight printed
594+
anything. But `db/schema.rb` declares those columns `null: false`, which is
595+
what `scripts/legacy-fixture.sql` mirrors, and the rule in `CONTRIBUTING.md`
596+
is narrower than it first reads: it says the legacy database has no foreign
597+
keys, so any `*_id` may dangle. The import handles every one of those. Do not
598+
add null guards to columns the legacy schema constrains.
488599

489600
### What has not been audited
490601

@@ -498,20 +609,24 @@ The honest list, and the best place for a sixth pass to start.
498609
- **No screen exists**, so nothing has exercised the cookie across subdomains,
499610
a reset link in a real mail client, or any of the flows end to end as a
500611
person.
501-
- **No load work.** The fifth pass did concurrency, which is a different thing:
502-
it raced the claims and the writes that can race, and never asked what happens
503-
at a thousand members signing in. The directory returns every member in one
504-
answer by design and nobody has measured that answer at the size the lab
505-
actually is.
506-
- **The images are pinned and still unscanned.** Pinning says the image will not
507-
move. It says nothing about what is in it, and no scanner runs anywhere.
508-
- **Nothing measures the door loop against a slow controller.** The simulator
509-
answers instantly. A real 2013 board blocks for six seconds on an arm and one
510-
second on a card miss, which is written down in `docs/legacy-system.md` and has
511-
never been put in front of the loop to see what a tick does when it overruns.
512-
- **Nobody has read the two scripts adversarially since pass three.**
513-
`scripts/import.ts` is 416 lines, it runs once, and it runs against the thing
514-
nobody has seen.
612+
- **The images are still unscanned.** The sixth pass tried and `docker scout`
613+
wanted a login. Pinning says the image will not move; it says nothing about
614+
what is in it.
615+
- **Nothing signs in at a thousand members.** The sixth pass measured the
616+
directory at that size and the concurrency of reading it. Nobody has measured
617+
the write side, or what a hundred people signing in at once costs when every
618+
one of them is an Argon2 verify at 19 MiB.
619+
- **`scripts/backup.sh` and `scripts/restore.sh` have been run as a round trip
620+
and never against anything the size of the real database.** The dump that
621+
matters is 2.8 million door log rows in the legacy system.
622+
- **The other script.** The sixth pass read `scripts/import.ts` adversarially and
623+
found the report was counting intentions. `scripts/migrate.ts` has been run and
624+
not read the same way, and it is the one that decides what a deploy does to the
625+
schema.
626+
- **Nothing reads the runbooks by running them.** One of the seven opened with a
627+
command that cannot work, and that was found by typing it. The other six have
628+
not been walked step by step against a running system, and that is now the
629+
cheapest place left to find something.
515630

516631
## 7. Open licence questions
517632

@@ -547,13 +662,16 @@ versions will not load it. The suites need the Postgres that `make up` starts.
547662
`make typecheck` is not optional: stripping types is not checking them, so a
548663
green suite on this stack says nothing about the types.
549664

550-
Five passes have been over this code and section 6 says what they covered. The
665+
Six passes have been over this code and section 6 says what they covered. The
551666
bar for a new finding is not that it looks wrong, it is that you ran it and it
552-
was. Seven things in section 6 were about to be changed on a wrong belief and
667+
was. Eight things in section 6 were about to be changed on a wrong belief and
553668
only a probe caught it. One of the fifth pass's own measurements was wrong the
554669
first time and the wrong number was the frightening one, which is the argument
555670
for running it twice.
556671

672+
The sixth pass found four of its five by typing a value nobody had typed and one
673+
by running a runbook. There is no cleverness in any of it.
674+
557675
The two things that must not break are in section 13 of `CONTRIBUTING.md`. A
558676
verified restorable backup, and the door keeping working when everything here is
559677
down. Every other rule in this repository is negotiable and those two are not.

api/src/http.ts

Lines changed: 21 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -9,9 +9,21 @@ export async function body(c: Context): Promise<Record<string, unknown>> {
99
/** Longest honest free text field. Anything above it is a mistake or an attack. */
1010
export const TEXT_LIMIT = 2000
1111

12+
/**
13+
* Whether Postgres can hold this text at all.
14+
*
15+
* A text column and a jsonb value both refuse U+0000, and postgres.js hands the
16+
* value straight through, so a body carrying one answered 503 as though the
17+
* database were unreachable. It is a value this system cannot store rather than
18+
* one it cannot reach, and the difference is the whole of what 503 means here.
19+
*/
20+
export function storable(value: string): boolean {
21+
return !value.includes('\u0000')
22+
}
23+
1224
/** A trimmed string, or null for anything that is not one. Unknown fields are ignored. */
1325
export function text(value: unknown, limit = TEXT_LIMIT): string | null {
14-
if (typeof value !== 'string') return null
26+
if (typeof value !== 'string' || !storable(value)) return null
1527
const trimmed = value.trim()
1628
return trimmed === '' || trimmed.length > limit ? null : trimmed
1729
}
@@ -49,9 +61,15 @@ const MAX_PAGE = 500
4961
/** Paginated lists take ?limit and ?before, and answer { items, next }. */
5062
export function page(c: Context): { limit: number; before: number | null } {
5163
const limit = Number(c.req.query('limit') ?? DEFAULT_PAGE)
52-
const before = Number(c.req.query('before'))
64+
const before = Math.trunc(Number(c.req.query('before')))
5365
return {
5466
limit: Number.isFinite(limit) ? Math.min(Math.max(Math.trunc(limit), 1), MAX_PAGE) : DEFAULT_PAGE,
55-
before: Number.isFinite(before) && before > 0 ? Math.trunc(before) : null,
67+
/**
68+
* A cursor is an id, and past Number.MAX_SAFE_INTEGER a JavaScript number
69+
* is not the value that was typed any more: the largest bigint arrives as
70+
* 9223372036854776000, which Postgres refuses. Every cursor that big means
71+
* the same thing as no cursor, which is to start from the newest.
72+
*/
73+
before: Number.isSafeInteger(before) && before > 0 ? before : null,
5674
}
5775
}

api/src/routes/members.ts

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@ import type { Handler } from 'hono'
55
import { change } from '../audit.ts'
66
import { byEmail, hashPassword, overRateLimit, tooWeak, type Env, type Member } from '../auth.ts'
77
import { sql } from '../db.ts'
8-
import { TEXT_LIMIT, bad, body, missing, param, text, uuid } from '../http.ts'
8+
import { TEXT_LIMIT, bad, body, missing, param, storable, text, uuid } from '../http.ts'
99
import { log } from '../log.ts'
1010
import { sendResetLink } from '../mail.ts'
1111

@@ -362,6 +362,11 @@ function readPatch(
362362
for (const field of allowed) {
363363
const value = form[field]
364364
if (value === undefined) continue
365+
// Before the per field checks, because every branch below either stores
366+
// this string or hands it to one that does.
367+
if (typeof value === 'string' && !storable(value)) {
368+
return new Error(`${field} has a character this system cannot store.`)
369+
}
365370

366371
if (field === 'roles') {
367372
if (!Array.isArray(value) || value.some((r) => !ROLES.includes(String(r)))) {

0 commit comments

Comments
 (0)