Skip to content

Commit 1ddabf1

Browse files
Merge pull request #11 from crydensync/fix/graceful-shutdown
Fix/graceful shutdown
2 parents 5914203 + 40d636a commit 1ddabf1

11 files changed

Lines changed: 572 additions & 70 deletions

File tree

README.md

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -86,7 +86,9 @@ No migration step exists on SQLite. `main.go` calls cryden's own `sqlite.Migrate
8686

8787
The connection is opened with three pragmas, all of them load-bearing: `foreign_keys(1)` (off by default, so the schema's `ON DELETE` clauses would silently not run), `busy_timeout(5000)` (zero by default, so a concurrent writer gets an immediate `SQLITE_BUSY` instead of waiting), and `journal_mode(WAL)`. The server verifies the first two on every boot with cryden's own `CheckPragmas` and refuses to start if the DSN and the driver have drifted apart.
8888

89-
**Backing up a SQLite deployment means copying `api.db`, `api.db-wal` and `api.db-shm` together**, or checkpointing first. With WAL, recent writes — including, on a fresh deployment, the entire schema — live in the `-wal` file until a checkpoint folds them into the main file, and there is no graceful shutdown here yet to force one on exit. Copying `api.db` alone can silently produce an empty database.
89+
**Backing up a SQLite deployment means copying `api.db`, `api.db-wal` and `api.db-shm` together**, or checkpointing first. With WAL, recent writes — including, on a fresh deployment, the entire schema — live in the `-wal` file until a checkpoint folds them into the main file. Copying `api.db` alone can silently produce an empty database in that window.
90+
91+
A clean stop is what closes that window: on `SIGTERM` or `SIGINT` the server stops accepting connections, waits up to 30 seconds for the requests already in flight, stops the webhook worker and digest scheduler, and closes the database — which on SQLite is the checkpoint that folds the `-wal` file back into `api.db` and removes the sidecar files. So `systemctl stop`, `docker stop` and Ctrl-C all leave a `api.db` that is complete on its own. A `kill -9`, a crash or a power loss does not, which is why the paragraph above still stands.
9092

9193
## Second factors
9294

askai/askai.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -246,9 +246,9 @@ func (s *Service) Ask(ctx context.Context, req Request) (widget.Answer, error) {
246246

247247
// Close releases the connection pool behind the cached providers. The
248248
// cached pair is replaced and closed on every rebuild, so this is only
249-
// about the last one — and nothing calls it yet, because this repo still
250-
// has no graceful shutdown for it to hang off. It exists so that adding
251-
// one does not have to start by widening this type's API.
249+
// about the last one — main.go calls it during shutdown, after the server
250+
// has drained and the background workers have stopped, so no question can
251+
// be in flight against a provider this is about to close.
252252
func (s *Service) Close() error {
253253
s.mu.Lock()
254254
defer s.mu.Unlock()

digest/schedule.go

Lines changed: 6 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -56,11 +56,12 @@ type Scheduler struct {
5656
// start. A history that grows with restarts rather than with time is not
5757
// a history of anything.
5858
//
59-
// main.go hands this context.Background(), because this repo has no
60-
// graceful shutdown yet — the same caveat, and the same reasoning, as the
61-
// webhook worker's goroutine. Nothing here needs stopping today: an
62-
// interrupted run loses at most one digest, and the next interval builds
63-
// another.
59+
// main.go hands this the context the shutdown signal cancels, so a SIGTERM
60+
// stops it between runs. Nothing here needed to be stoppable for
61+
// correctness — an interrupted run records nothing and the next interval
62+
// builds another — but a build cut off halfway is worse than one that
63+
// never started, because half a window in the history reads as a quiet
64+
// week rather than as a missing one.
6465
func (s *Scheduler) Run(ctx context.Context) {
6566
if s.Interval <= 0 || s.Store == nil || s.Build == nil {
6667
return

docs/development/CURRENT-STATE.md

Lines changed: 95 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -391,9 +391,10 @@ deployment does on its next restart, so it is called out in `README.md`,
391391

392392
The digest's new table (`012`) has **never been applied to a real
393393
database**, the same as `009``011` — there is no Postgres in this
394-
sandbox — and the digest schedule is a goroutine on
395-
`context.Background()`, because this repo still has no graceful
396-
shutdown. `PROGRESS.md` says both plainly.
394+
sandbox. The digest schedule used to be a goroutine on
395+
`context.Background()`; it now takes the context the shutdown signal
396+
cancels, so the paragraph that follows in the Tier 6 section applies here
397+
too. `PROGRESS.md` says both plainly.
397398

398399
### Stage 2 — the providers and the widget config
399400

@@ -568,9 +569,10 @@ foreign key rather than accepting any id, so that the tested branch is
568569
the one production runs. `-race` was not run this session.
569570

570571
**Still not built** (unchanged from Tier 4, not part of this tier):
571-
graceful shutdown, and per-user rate limiting on anything that calls a
572-
model. The widget's own serving endpoint was in this list when Tier 5
573-
landed and is not any more — see the next section.
572+
per-user rate limiting on anything that calls a model. Graceful shutdown
573+
was on this list and is not any more — see the last section of this file.
574+
The widget's own serving endpoint was in this list when Tier 5 landed and
575+
is not any more — see the next section.
574576

575577
## The ask-ai widget's serving endpoint — carried forward from Tier 4
576578

@@ -653,18 +655,18 @@ single most important thing about it.
653655
see the intent that actually reached the query surface. It is also the
654656
hook a host running a different LLM backend needs, which is why it is
655657
exported rather than a test-only accessor.
656-
- **`Service.Close()` exists and nothing calls it.** There is still no
657-
graceful shutdown for it to hang off, so it is there so that adding
658-
one does not have to start by widening this type's API.
658+
- **`Service.Close()` is called by the teardown in `main.go`.** It
659+
releases the last cached provider pool, after the server has drained
660+
and the background workers have stopped, so no question can be in
661+
flight against a provider that is being closed.
659662

660663
**What is still owed, said plainly.** No per-user rate limiting on this
661664
route: it spends money per question and is bounded only by the global
662665
per-IP edge limiter. That needs policy — per-user or per-deployment, and
663666
what number — which is a deployment's call rather than something to
664-
invent here. `Service.Close()` is never called, for the shutdown reason
665-
above. The Anthropic provider still has never called Anthropic, so the
666-
live path from a question to a real model is exercised only through the
667-
`Providers` seam with doubles; the wire shape is covered by
667+
invent here. The Anthropic provider still has never called Anthropic, so
668+
the live path from a question to a real model is exercised only through
669+
the `Providers` seam with doubles; the wire shape is covered by
668670
`aiprovider`'s own tests against a local fake.
669671

670672
## Tier 6 — SQLite backend, core auth only
@@ -753,11 +755,86 @@ this repo's server was started on a real SQLite file and passed the full
753755
`internal/smoketest` run — health, signup, duplicate rejection, login,
754756
wrong password, verify, session list, missing-header rejection, refresh
755757
rotation, reuse detection, family revocation, and both OAuth refusals.
756-
`-race` was still not run. Graceful shutdown is still unbuilt, and on
757-
SQLite it now has a second reason to exist: with no `Close()` there is
758-
no checkpoint on exit, so a fresh deployment's entire schema can sit in
758+
`-race` was still not run. Graceful shutdown was not built by this tier,
759+
and on SQLite it had a second reason to exist: with no `Close()` there is
760+
no checkpoint on exit, so a fresh deployment's entire schema could sit in
759761
the `-wal` file — durable, but a backup that copies `api.db` alone can
760-
silently produce an empty database. `README.md` warns about that where
761-
an operator will see it. Per-user rate limiting on `POST /v1/ask-ai` is
762+
silently produce an empty database. `README.md` warns about that where an
763+
operator will see it. That gap is now closed — see the last section of
764+
this file — but the warning stays, because a `kill -9` still leaves the
765+
WAL uncheckpointed and the advice to copy all three files is still the
766+
right advice. Per-user rate limiting on `POST /v1/ask-ai` is
762767
unchanged.
763768

769+
770+
## Graceful shutdown — the finding Tier 3 opened and Tier 6 sharpened
771+
772+
This is not a tier. It is the one item that appeared as owed in three
773+
separate tier write-ups (Tiers 3, 5 and 6), so it is recorded once, here,
774+
and the three write-ups now point at it instead of restating it.
775+
776+
**What it was.** `main.go` ended at
777+
`log.Fatal(http.ListenAndServe(...))`. That single line meant three
778+
things, and only the first was obvious:
779+
780+
1. **No signal handling.** A `SIGTERM` — which is what every process
781+
manager sends, including `docker stop` and a Kubernetes rolling
782+
deploy — killed the process where it stood. Every request in flight
783+
died with it.
784+
2. **`os.Exit` runs no defers.** `log.Fatalf` calls `os.Exit(1)`, so the
785+
`defer db.Close()` two lines above it had never run once in this
786+
repo's life. Every clean shutdown leaked the pool.
787+
3. **On SQLite, no close means no checkpoint.** The `-wal` file is
788+
durable — SQLite recovers from it — but the schema and every row a
789+
deployment had written lived only there. After two boots of the
790+
smoke run, `api.db` was still 4096 bytes while `api.db-wal` held
791+
461KB. A backup that copied `api.db` alone produced an empty
792+
database that opened without error.
793+
794+
Only the third is visible from outside, and it is the one that would
795+
have cost somebody data.
796+
797+
**What it is now.** `signal.NotifyContext` on `SIGINT`/`SIGTERM` produces
798+
one `appCtx` that everything hangs off. `net.Listen` is separated from
799+
`srv.Serve` so a listen failure is an error to report rather than a
800+
`Fatal` that skips teardown. The main goroutine selects on either
801+
`Serve` returning on its own or the signal; on the signal it calls
802+
`drain`, which is `srv.Shutdown` bounded by `shutdownDrainTimeout`
803+
(30s, a constant in `shutdown.go` with its own reasoning) and falls back
804+
to `srv.Close` when the bound is hit. Only then does teardown run, in
805+
the order the components need: `stopSignals()`, `workers.Wait()` for the
806+
webhook worker and the digest scheduler, then `askAI.Close()`,
807+
`redisClient.Close()`, and `db.Close()` last — that last one being the
808+
WAL checkpoint.
809+
810+
**The three properties `shutdown_test.go` pins**, because they are the
811+
whole reason `drain` is a function instead of three lines in `main`:
812+
813+
- A request already in flight still gets its 200 after the signal
814+
arrives, and the drain does not return before it finishes. The test
815+
waits for the handler to actually be running rather than sleeping, so
816+
it is not racing the client.
817+
- A request that will not finish does not hold the process open. The
818+
bound is honored and the error names the wait, because the operator
819+
reading it is looking at a deploy that took too long.
820+
- A listener that fails on its own reports that error rather than
821+
having it translated into a clean shutdown by the
822+
`http.ErrServerClosed` check.
823+
824+
**Verified end to end, not just by unit test.** The binary was built,
825+
started on a fresh `/tmp/walcheck.db`, driven through the full
826+
`internal/smoketest` run (13/13), sent a real `SIGTERM`, and then the
827+
database was opened **read-only with no sidecar files present**: 7
828+
migrations recorded, 1 user, 2 sessions, all read back out of the
829+
single `.db` file. Before the change the same sequence left 4096 bytes
830+
and a 461KB `-wal`.
831+
832+
**What this does not do.** It does not make `shiplog`'s writes
833+
asynchronous — the comment there has been updated from "there is no
834+
shutdown path to hang off" to "the buffer and the flush policy are the
835+
missing pieces, not the lifecycle", which is a different and smaller
836+
problem. It does not add a readiness endpoint separate from `/v1/health`,
837+
so a load balancer's behavior during the drain is unchanged. And
838+
`shutdownDrainTimeout` is a constant rather than an env var on purpose:
839+
if the ask-ai widget's model calls ever stop being bounded by the
840+
provider's own client timeout, that becomes a knob.

docs/development/NEXT.md

Lines changed: 17 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -239,9 +239,10 @@ Two details were decided rather than assumed, and are recorded in
239239
> behaviour is tested against `httptest` and an in-memory double
240240
> **rather than against Postgres `FOR UPDATE SKIP LOCKED`**, the
241241
> in-memory double cannot reproduce two workers racing (one mutex), and
242-
> this repo still has **no graceful shutdown** — owed before the
243-
> shipped-events sink could move off the request goroutine. `PROGRESS.md`
244-
> has all of it.
242+
> this repo has **no graceful shutdown** — built since, see
243+
> `CURRENT-STATE.md`'s last section; the async-sink half of this note is
244+
> still owed and is now only about the buffer and the flush policy.
245+
> `PROGRESS.md` has all of it.
245246
>
246247
> Two deliberate deviations from the spec below, both argued in
247248
> `PROGRESS.md`: `webhook_deliveries` uses a `BIGSERIAL` surrogate
@@ -346,8 +347,9 @@ Two details were decided rather than assumed, and are recorded in
346347
>
347348
> What is still owed from Stage 1:
348349
>
349-
> - the digest schedule is a goroutine on `context.Background()`, because
350-
> this repo still has no graceful shutdown.
350+
> - ~~the digest schedule is a goroutine on `context.Background()`~~
351+
> built since: it takes the context the shutdown signal cancels, see
352+
> `CURRENT-STATE.md`'s last section.
351353
>
352354
> Three things this tier changed that were not in the spec below, all
353355
> recorded because they are behaviour rather than plumbing:
@@ -669,15 +671,13 @@ avoid duplicating.
669671
run from a minimal base), published to a registry on the same tag
670672
trigger. `docker run --env-file .env -p 8080:8080 <image>` should be
671673
the entire setup instructions.
672-
- **Graceful shutdown, pulled forward from Tier 3/4's owed list**:
673-
this is the tier where it stops being a nice-to-have. A distributed
674-
binary or container is exactly what a real orchestrator (Kubernetes,
675-
Fly, Railway, plain systemd) sends `SIGTERM` to on every deploy, and
676-
right now `main.go` ends at `log.Fatal(ListenAndServe(...))` with the
677-
webhook worker and digest scheduler both running on
678-
`context.Background()` — nothing stops them cleanly. Wire a real
679-
shutdown context, cancel it on `SIGTERM`/`SIGINT`, and give
680-
in-flight requests and the background workers a bounded grace period
681-
before exiting. Don't ship distribution before this; a container
682-
that gets killed mid-migration or mid-webhook-delivery on every
683-
rolling deploy is a worse experience than the one being fixed.
674+
- ~~**Graceful shutdown, pulled forward from Tier 3/4's owed list**~~
675+
built ahead of this tier, on its own branch, because the original
676+
reasoning here was that shipping distribution first would ship a
677+
container whose every `docker stop` kills in-flight requests.
678+
`main.go` no longer ends at `log.Fatal(ListenAndServe(...))`, and both
679+
background workers take the context the signal cancels; see
680+
`CURRENT-STATE.md`'s last section. **What remains for this tier is the
681+
packaging**: the `Dockerfile`'s `ENTRYPOINT` must run the binary
682+
directly rather than through a shell, or `docker stop` signals
683+
`/bin/sh` and the whole thing gains nothing.

docs/development/PROGRESS.md

Lines changed: 54 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1393,3 +1393,57 @@ false. 501 is a statement about the deployment, and it is true.
13931393
entries — was left as found, still a Tier 1 documentation pass.
13941394
- `.env.example` documents the two backends at the top.
13951395
- New `migrations/sqlite/README.md`.
1396+
1397+
## 2026-09-17 — graceful shutdown (not a tier)
1398+
1399+
On `feat/tier6-sqlite-backend`'s working tree, branched off as its own
1400+
change. This is the item Tiers 3, 5 and 6 each recorded as owed; it was
1401+
done now rather than inside Tier 7 because Tier 7's own spec says not to
1402+
ship distribution before it — a container whose every `docker stop`
1403+
kills in-flight requests is the bug the packaging would have shipped.
1404+
1405+
**What was wrong, in three parts.** `main.go` ended at
1406+
`log.Fatal(http.ListenAndServe(...))`. (1) No signal handling, so
1407+
`SIGTERM` killed the process mid-request. (2) `log.Fatalf` calls
1408+
`os.Exit`, which runs no defers, so the `defer db.Close()` above it had
1409+
never once run. (3) On SQLite, no close means no WAL checkpoint — this
1410+
was the finding that started it: after two boots of the smoke run,
1411+
`api.db` was still 4096 bytes while `api.db-wal` held 461KB, so a backup
1412+
copying `api.db` alone produced a database that opened without error and
1413+
was empty.
1414+
1415+
**What was built.** `signal.NotifyContext` on `SIGINT`/`SIGTERM` gives
1416+
one `appCtx` that the HTTP server and both background workers hang off.
1417+
`net.Listen` is separated from `srv.Serve` so a listen failure is
1418+
reported rather than being a `Fatal` that skips teardown. The main
1419+
goroutine selects on either `Serve` returning on its own or the signal;
1420+
on the signal it calls `drain` (`shutdown.go`), which is `srv.Shutdown`
1421+
bounded by a 30s constant and falls back to `srv.Close` when the bound
1422+
is hit. Teardown then runs in the order the components need:
1423+
`stopSignals()`, `workers.Wait()`, `askAI.Close()`, `redisClient.Close()`,
1424+
`db.Close()` last. Both `sync.WaitGroup.Go` (Go 1.25) and the hoisting of
1425+
`redisClient`/`askAI` exist so the teardown has something to close.
1426+
1427+
**Verified end to end, not just by unit test.** Built the binary,
1428+
started it on a fresh `/tmp/walcheck.db`, ran the full `internal/smoketest`
1429+
(13/13), sent a real `SIGTERM` to the actual server PID, then opened the
1430+
database **read-only with no `-wal`/`-shm` present**: 7 migrations
1431+
recorded, 1 user, 2 sessions. The sidecar files were gone entirely, which
1432+
is the checkpoint. `shutdown_test.go` also pins the three properties
1433+
`drain` exists for: an in-flight request still gets its 200 and the
1434+
drain waits for it; a request that will not finish is abandoned at the
1435+
bound with an error naming the wait; a listener that fails on its own
1436+
reports that error instead of having it translated to a clean shutdown.
1437+
1438+
**Also corrected**: four doc comments that asserted this repo has no
1439+
shutdown path and are now false (`askai.Service.Close`,
1440+
`webhook.Worker.Run`, `digest.Scheduler.Run`, and `shiplog`'s
1441+
synchronous-write argument). The `shiplog` one changed its *reasoning*,
1442+
not just its wording — the missing piece for an async sink is now the
1443+
buffer and the flush policy, not a lifecycle to hang it off — so that is
1444+
recorded rather than deleted.
1445+
1446+
**Not done.** `-race` still has not been run. `shutdownDrainTimeout` is
1447+
a constant, not a knob, on purpose. No readiness endpoint separate from
1448+
`/v1/health`, so load-balancer behaviour during the drain is unchanged.
1449+
`go build ./... && go vet ./... && go test ./...` are all clean.

0 commit comments

Comments
 (0)