amadan

carlos / platform Public

instance-control orders legacy run starts against stops per host; release obligations retire at their record's expiry; the legacy proof ends with Shutdown (#292)

Astra's round 2 review (REJECT), on the owner's ruling for P1:

P1. Cancelling the agent's /start did not join root's start handler, which
could still submit its systemd start after a /stop for the host had
answered, so the agent's proof could pass and the late job launch an
unleased writer. instance-control now orders legacy run (generation 0)
starts against stops per host (internal/instancectl/legacystart.go):
every /start registers an attempt whose context a /stop can cancel and
checks that context immediately before it submits; a /stop refuses new
starts while it runs, cancels and joins every attempt in flight (bounded,
legacyJoinBudget, answering an error if one is still running), and only
then stops the unit, which replaces any job a joined attempt submitted;
and a start whose request was accepted before a stop of the host
(connection accept order, stamped by Serve's ConnContext) is refused once
that stop has run, however late its handler gets going. Generation verbs,
seeds, sidecars and claims are untouched. Changed: Server (fields), Serve
(ConnContext), handleStart, handleStop; new: legacyAttempt, connContext,
nextConnSeq, requestSeq, beginLegacyStart, fenceLegacyStarts. Root-side:
instance-control needs a restart on roll.

P2. A release obligation is retired once its lease record has passed its
own expiry, even if the DELETE still fails: Held.RetryRelease answers
lease.ErrReleaseLapsed and drops the record, and the activator removes the
obligation and logs it as retired, never as given back.

And: the legacy proof runs under the sooner of its 30 s budget and
Shutdown's own context, so no proof outlives Shutdown; one cut short is
unproven and the lease is kept.

Tests: TestALegacyStartDelayedPastItsCancellationNeverSubmitsAfterAStop,
TestALegacyStartFromBeforeAStopIsRefused (instancectl),
TestAnOwedReleaseIsRetiredOnceItsRecordHasExpired (lease),
TestOwedReleasesAreRetiredOnceTheirRecordsExpire and
TestTheLegacyProofEndsWithShutdownsBudget (activator).
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
claude b12360d406b1bb1ee5adcec262cab950ebb07fa3 parent e26bbd6
10 files changed, +510 −11
  • internal/activator/activator.go +15 −2
  • internal/activator/activator_test.go +24 −2
  • internal/activator/containment.go +11 −2
  • internal/activator/shutdown_lease_test.go +66 −0
  • internal/instancectl/legacystart.go +144 −0
  • internal/instancectl/legacystart_test.go +114 −0
  • internal/instancectl/server.go +44 −1
  • internal/instancectl/server_test.go +19 −1
  • internal/lease/lease.go +20 −3
  • internal/lease/release_retry_test.go +53 −0

CI failed — run details

CI log 
=== gate ===
cd launchctx && go vet ./... && go test ./... -count=1
ok  	amadan.net/carlos/platform.git/launchctx	0.011s
?   	amadan.net/carlos/platform.git/launchctx/controlname	[no test files]
?   	amadan.net/carlos/platform.git/launchctx/wireid	[no test files]
go vet ./...
gofmt -l .: clean
go test ./... -count=1 -timeout 30m
ok  	github.com/carlosframework/platform	364.140s
?   	github.com/carlosframework/platform/cmd/changelog	[no test files]
ok  	github.com/carlosframework/platform/cmd/console	5.226s
ok  	github.com/carlosframework/platform/cmd/moveprobe	93.404s
ok  	github.com/carlosframework/platform/cmd/zddprobe	0.773s
ok  	github.com/carlosframework/platform/internal/activator	239.118s
ok  	github.com/carlosframework/platform/internal/agentsock	0.066s
ok  	github.com/carlosframework/platform/internal/alerting	0.009s
ok  	github.com/carlosframework/platform/internal/analytics	0.366s
ok  	github.com/carlosframework/platform/internal/appconfig	2.672s
ok  	github.com/carlosframework/platform/internal/apperr	0.129s
ok  	github.com/carlosframework/platform/internal/applog	0.333s
ok  	github.com/carlosframework/platform/internal/awsinv	0.004s
ok  	github.com/carlosframework/platform/internal/boxchoice	0.008s
ok  	github.com/carlosframework/platform/internal/boxid	0.836s
?   	github.com/carlosframework/platform/internal/boxid/boxidtest	[no test files]
?   	github.com/carlosframework/platform/internal/boxid/internal/signtest	[no test files]
ok  	github.com/carlosframework/platform/internal/boxvolumes	0.018s
ok  	github.com/carlosframework/platform/internal/caps	0.020s
ok  	github.com/carlosframework/platform/internal/certwarm	0.003s
ok  	github.com/carlosframework/platform/internal/cgroup	0.779s
ok  	github.com/carlosframework/platform/internal/changelog	0.490s
ok  	github.com/carlosframework/platform/internal/clamd	0.066s
?   	github.com/carlosframework/platform/internal/cliflag	[no test files]
ok  	github.com/carlosframework/platform/internal/console	375.046s
?   	github.com/carlosframework/platform/internal/controlname	[no test files]
?   	github.com/carlosframework/platform/internal/controlsock	[no test files]
ok  	github.com/carlosframework/platform/internal/dbdoor	6.265s
ok  	github.com/carlosframework/platform/internal/dbdoor/dbdoortest	0.015s
ok  	github.com/carlosframework/platform/internal/dbverify	0.015s
ok  	github.com/carlosframework/platform/internal/dnsrec	0.008s
ok  	github.com/carlosframework/platform/internal/docsite	0.004s
ok  	github.com/carlosframework/platform/internal/domains	2.400s
ok  	github.com/carlosframework/platform/internal/doorkey	0.010s
ok  	github.com/carlosframework/platform/internal/economics	0.004s
ok  	github.com/carlosframework/platform/internal/edge	27.711s
?   	github.com/carlosframework/platform/internal/edgeproof	[no test files]
ok  	github.com/carlosframework/platform/internal/edgesfile	0.009s
ok  	github.com/carlosframework/platform/internal/fleetapi	0.148s
ok  	github.com/carlosframework/platform/internal/gate	1.665s
ok  	github.com/carlosframework/platform/internal/genselect	0.025s
ok  	github.com/carlosframework/platform/internal/geo	0.020s
ok  	github.com/carlosframework/platform/internal/geoip	0.032s
ok  	github.com/carlosframework/platform/internal/host	137.146s
ok  	github.com/carlosframework/platform/internal/hostactors	0.614s
ok  	github.com/carlosframework/platform/internal/hostbox	3.436s
ok  	github.com/carlosframework/platform/internal/hostclaim	1.081s
ok  	github.com/carlosframework/platform/internal/hostevidence	0.008s
ok  	github.com/carlosframework/platform/internal/hostexec	9.341s
ok  	github.com/carlosframework/platform/internal/hostfence	0.239s
ok  	github.com/carlosframework/platform/internal/hostfiles	11.181s
ok  	github.com/carlosframework/platform/internal/hostfloor	0.025s
ok  	github.com/carlosframework/platform/internal/hostguard	1.028s
ok  	github.com/carlosframework/platform/internal/hostops	3.044s
?   	github.com/carlosframework/platform/internal/hostops/fencerelease	[no test files]
ok  	github.com/carlosframework/platform/internal/hostops/internal/fencerelease	0.002s
ok  	github.com/carlosframework/platform/internal/hostquarantine	0.004s
ok  	github.com/carlosframework/platform/internal/hostrelocate	0.937s
ok  	github.com/carlosframework/platform/internal/hostresolve	0.192s
ok  	github.com/carlosframework/platform/internal/hostwrite	0.002s
ok  	github.com/carlosframework/platform/internal/infraview	0.003s
ok  	github.com/carlosframework/platform/internal/instancectl	2.963s
ok  	github.com/carlosframework/platform/internal/instanceexec	3.048s
ok  	github.com/carlosframework/platform/internal/instancefs	0.010s
ok  	github.com/carlosframework/platform/internal/instancekey	0.002s
ok  	github.com/carlosframework/platform/internal/instanceupdates	0.016s
ok  	github.com/carlosframework/platform/internal/layout	2.272s
ok  	github.com/carlosframework/platform/internal/lease	10.233s
ok  	github.com/carlosframework/platform/internal/lease/leasetest	0.006s
ok  	github.com/carlosframework/platform/internal/ledger	0.019s
ok  	github.com/carlosframework/platform/internal/mail	0.318s
ok  	github.com/carlosframework/platform/internal/maintenance	0.089s
ok  	github.com/carlosframework/platform/internal/maintenanceexec	6.037s
ok  	github.com/carlosframework/platform/internal/maintenanceguard	0.153s
ok  	github.com/carlosframework/platform/internal/metrics	0.012s
ok  	github.com/carlosframework/platform/internal/moves	24.596s
ok  	github.com/carlosframework/platform/internal/moves/archive	1.566s
ok  	github.com/carlosframework/platform/internal/objstore	0.357s
ok  	github.com/carlosframework/platform/internal/ops	0.232s
ok  	github.com/carlosframework/platform/internal/park	0.380s
ok  	github.com/carlosframework/platform/internal/privatefile	0.005s
2026/10/14 15:41:19 provision: listing apps/bab/blog/instances/: list refused — its records are unseen this pass
2026/10/14 15:41:19 provision: listing apps/bab/: listdirs refused — its records are unseen this pass
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: listing apps/bac/tito/instances/: list refused — its records are unseen this pass
2026/10/14 15:41:19 provision: listing apps/bac/tito/instances/: list refused — its records are unseen this pass
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:19 provision: remove retired instance route shop.example: provision: claim admission unavailable
2026/10/14 15:41:19 provision: remove retired instance route shop.example: provision: claim admission unavailable
2026/10/14 15:41:19 provision: remove retired sidecar route worker.sidecar.internal: provision: claim admission unavailable
2026/10/14 15:41:19 provision: remove retired sidecar route worker.sidecar.internal: provision: claim admission unavailable
2026/10/14 15:41:19 provision: claim install acme.go.tito.io: provision: claim admission unavailable
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/14 15:41:19 provision: claim install bot.eleven.bac.sidecar.internal: provision: claim admission unavailable
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/14 15:41:19 provision: claim install bot.eleven.bac.sidecar.internal: registry: claim row ownership changed or unknown
2026/10/14 15:41:19 provision: refusing to mint route acme.go.tito.io (app "tito" acct "bac"): this box declares CARLOS_INBOUND=none (no-inbound) and cannot serve routed instance traffic
2026/10/14 15:41:19 provision: acme.go.tito.io: not minting this pass: the box's layout intent could not be read: no sealed config
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: REFUSING to mint sidecar bot.eleven.bac.sidecar.internal: bot.eleven.bac.sidecar.internal-sidecar.env is staged on this box — the legacy file co-spawn and a native sidecar row are two mechanisms for one host; remove the file to migrate this host onto sidecar records
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/14 15:41:19 provision: refusing to mint route acme.go.tito.io (app "tito" acct "bac"): this box declares CARLOS_INBOUND=none (no-inbound) and cannot serve routed instance traffic
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: REFUSING to mint sidecar bot.eleven.bac.sidecar.internal: bot.eleven.bac.sidecar.internal-sidecar.env is staged on this box — the legacy file co-spawn and a native sidecar row are two mechanisms for one host; remove the file to migrate this host onto sidecar records
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/14 15:41:19 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/14 15:41:19 provision: bot.eleven.bac.sidecar.internal exists but is not a sidecar row this pass owns (kind "sidecar" provisioned false app "eleven" acct "bac") — leaving it alone
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/14 15:41:19 provision: claim install bot.eleven.bac.sidecar.internal: registry: claim row ownership changed or unknown
2026/10/14 15:41:19 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:19 provision: bot.eleven.bac.sidecar.internal exists but is not a sidecar row this pass owns (kind "sidecar" provisioned false app "eleven" acct "bac") — leaving it alone
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:19 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:19 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/14 15:41:19 provision: skipping record apps/bac/tito/instances/new.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/14 15:41:19 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:19 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/14 15:41:19 provision: skipping record apps/bac/tito/instances/new.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/14 15:41:20 provision: minted instance route rk.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route ra.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rb.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rc.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rd.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route re.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rf.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rj.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rl.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rg.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rh.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route ri.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route ra.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rb.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rc.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route rd.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: skipping record apps/bac/tito/instances/rb.go.tito.io.json: read failed: read refused
2026/10/14 15:41:20 provision: skipping record apps/bac/tito/instances/rb.go.tito.io.json: read failed: read refused
2026/10/14 15:41:20 provision: minted instance route re.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appj.example (app "appj" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appa.example (app "appa" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appb.example (app "appb" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appc.example (app "appc" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appd.example (app "appd" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appe.example (app "appe" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appg.example (app "appg" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.apph.example (app "apph" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appi.example (app "appi" acct "bac")
2026/10/14 15:41:20 provision: minted instance route x.appf.example (app "appf" acct "bac")
2026/10/14 15:41:20 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:20 provision: minted instance route r0042.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0081.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0088.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0090.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0116.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0119.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0127.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0010.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0027.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0056.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0011.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0062.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0022.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0061.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0084.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0089.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0096.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0002.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0032.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0033.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0097.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0100.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0107.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0045.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0076.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0091.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0098.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0115.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0004.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0038.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0104.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0055.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0000.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0008.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0024.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0043.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0072.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0074.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0129.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0026.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0041.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0068.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0078.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0080.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0122.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0018.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0039.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0013.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0079.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0105.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0017.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0086.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0112.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0005.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0020.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0063.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0121.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0001.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0053.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0085.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0092.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0118.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0060.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0093.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0114.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0012.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0077.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0034.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0073.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0128.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0025.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0058.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0064.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0069.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0083.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0030.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0044.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0050.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0067.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0099.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0003.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0094.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0103.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0113.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0021.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0023.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0057.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0087.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0111.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0009.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0016.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0019.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0028.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0065.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0075.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0082.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0117.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0031.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0123.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0124.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0125.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0006.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0007.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0040.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0066.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0110.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0037.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0059.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0015.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0047.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0051.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0106.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0108.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0029.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0036.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0049.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0071.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0126.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0046.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0052.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0014.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0070.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0095.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0101.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0109.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0035.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0048.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0054.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0102.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:20 provision: minted instance route r0120.go.tito.io (app "tito" acct "bac")
--- FAIL: TestPlan14RootReadCensus (17.48s)
    plan14_root_reads_test.go:680: root read census: 23 discrepancies
        changed root read internal/activator/activator.go:Service.BeginSidecarRequest; review class, task, sites and digest
        changed root read internal/activator/activator.go:Service.begin; review class, task, sites and digest
        changed root read internal/activator/activator.go:Service.doWake; review class, task, sites and digest
        changed root read internal/activator/activator.go:Service.sweepOnce; review class, task, sites and digest
        changed root read internal/activator/activator.go:Service.wake; review class, task, sites and digest
        changed root read internal/activator/backend_exec.go:ExecBackend.spawnUnitFrom; review class, task, sites and digest
        changed root read internal/activator/maintenance.go:Service.cleanupFailedWake; review class, task, sites and digest
        changed root read internal/activator/opset.go:Service.reapUnprovenWake; review class, task, sites and digest
        changed root read internal/instancectl/server.go:type Server; review class, task, sites and digest
        changed root source envelope internal/activator
        changed root source envelope internal/instancectl
        changed root source envelope internal/lease
        unclassified root read internal/activator/backend_exec.go:ExecBackend.LegacyRunGone registry:Host@174,registry:Host@225,registry:Host@268,registry:Host@623
        unclassified root read internal/activator/backend_unit.go:SplitBackend.LegacyRunGone file:Exec@240,registry:Backing@89,registry:Host@200,registry:Host@305,whole:Route@364
        unclassified root read internal/activator/containment.go:Service.legacyRunGone whole:Route@358
        changed legacy declaration internal/activator/activator.go:Service.BeginSidecarRequest
        changed legacy declaration internal/activator/activator.go:Service.begin
        changed legacy declaration internal/activator/activator.go:Service.doWake
        changed legacy declaration internal/activator/activator.go:Service.sweepOnce
        changed legacy declaration internal/activator/activator.go:Service.wake
        changed legacy declaration internal/activator/backend_exec.go:ExecBackend.spawnUnitFrom
        changed legacy declaration internal/activator/maintenance.go:Service.cleanupFailedWake
        changed legacy declaration internal/activator/opset.go:Service.reapUnprovenWake
2026/10/14 15:41:38 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:38 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:38 provision: refusing to mint route acme.go.tito.io (app "tito" acct "bac"): this box declares CARLOS_INBOUND=none (no-inbound) and cannot serve routed instance traffic
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route whole.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route console.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route ha.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route svc.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route shared.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: converged acme.go.tito.io channel edge -> canary/rehearsal
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: empty channel
2026/10/14 15:41:39 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io environment "" -> "staging"
2026/10/14 15:41:39 provision: converged acme.go.tito.io environment "staging" -> ""
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io steering "" -> "latency"
2026/10/14 15:41:39 provision: converged acme.go.tito.io steering "latency" -> ""
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io hibernate false -> true
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io hibernate true -> false (replication "daily" cleared: only a hibernating route's rung is read)
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged acme.go.tito.io status-named false -> true
2026/10/14 15:41:39 provision: converged acme.go.tito.io status-named true -> false
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route ha.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged ha.go.tito.io upstreams addr "" -> "", addrs "127.0.0.1:7001,127.0.0.1:7002" -> "127.0.0.1:7001,127.0.0.1:7003" (probe "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}" -> "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}")
2026/10/14 15:41:39 provision: converged ha.go.tito.io upstreams addr "" -> "", addrs "127.0.0.1:7001,127.0.0.1:7003" -> "127.0.0.1:7003,127.0.0.1:7001" (probe "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}" -> "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}")
2026/10/14 15:41:39 provision: converged ha.go.tito.io upstreams addr "" -> "", addrs "127.0.0.1:7003,127.0.0.1:7001" -> "127.0.0.1:7003,127.0.0.1:7001" (probe "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}" -> "{\"path\":\"/healthz\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}")
2026/10/14 15:41:39 provision: minted service route whole.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: converged whole.go.tito.io upstreams addr "127.0.0.1:9443" -> "", addrs "" -> "127.0.0.1:9443,127.0.0.1:9444" (probe "" -> "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}")
2026/10/14 15:41:39 provision: converged whole.go.tito.io upstreams addr "" -> "", addrs "127.0.0.1:9443,127.0.0.1:9444" -> "" (probe "{\"path\":\"/\",\"status\":200,\"interval_ms\":2000,\"fail_after\":3,\"rise_after\":2}" -> "")
2026/10/14 15:41:39 provision: whole.go.tito.io: record describes a different route SHAPE than the row (kind "instance"/"service" unit ""/"" socket "/run/carlos/whole.go.tito.io.sock"/"" db "/data/whole.go.tito.io.db"/"") — not converged in place; `carlos remove whole.go.tito.io` purges this route's capability grants (registry.Delete's contract, not a bug) before the next pass re-mints it, so treat that as a last resort, not a routine fix
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route whole.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping accounts/bac/account.json: malformed account manifest: invalid character 'o' in literal null (expecting 'u')
2026/10/14 15:41:39 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: manifest bac/tito: read failed: provision: manifest bac/tito: invalid character 'o' in literal null (expecting 'u')
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: disagrees with its own path (host="wrong-host.go.tito.io" account="bac" app="tito")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/acme$evil.go.tito.io.json: host "acme$evil.go.tito.io" is not a hostname
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/acme$evil.go.tito.io.json: host "acme$evil.go.tito.io" is not a hostname
2026/10/14 15:41:39 provision: not removing acme$evil.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/bad-service.go.tito.io.json: invalid shape: kind service with no addr: the platform only proxies to a service, so the record must name the upstream it proxies to
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/bad-service.go.tito.io.json: invalid shape: kind service with no addr: the platform only proxies to a service, so the record must name the upstream it proxies to
2026/10/14 15:41:39 provision: not removing bad-service.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/no-channel.go.tito.io.json: empty channel
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/no-channel.go.tito.io.json: empty channel
2026/10/14 15:41:39 provision: not removing no-channel.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/14 15:41:39 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/14 15:41:39 provision: removed retired instance route ghost.go.tito.io (record gone)
2026/10/14 15:41:39 provision: duplicate host dup.go.tito.io: keeping apps/bac/tito/instances/dup.go.tito.io.json, skipping apps/bad/tito/instances/dup.go.tito.io.json
2026/10/14 15:41:39 provision: minted instance route dup.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:39 provision: removed retired instance route acme.go.tito.io (app in the trash)
2026/10/14 15:41:39 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:39 provision: removed retired static route site.go.tito.io (app in the trash)
2026/10/14 15:41:39 provision: trash marker for bac/tito unreadable: release: malformed trash marker for bac/tito: invalid character 'n' looking for beginning of object key string — not minting for this app
2026/10/14 15:41:39 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:39 provision: removed retired instance route acme.go.tito.io (app in the trash)
2026/10/14 15:41:39 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/14 15:41:39 provision: trash marker for bac/tito unreadable: release: malformed trash marker for bac/tito: invalid character 'n' looking for beginning of object key string — not minting for this app
2026/10/14 15:41:39 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:39 provision: converged acme.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:39 provision: converged acme.go.tito.io channel canary/rehearsal -> edge
2026/10/14 15:41:39 provision: converged acme.go.tito.io environment "staging" -> ""
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (backing "unit" (box-scoped, not expressible in a record)) — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (tunnel "pi-fleet" (box-scoped, not expressible in a record)) — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (caps "port:25" (box-scoped, not expressible in a record)) — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (platform (owned by the domains reconcile pass)) — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (canary (owned by the domains reconcile pass)) — leaving it alone
2026/10/14 15:41:39 provision: acme.go.tito.io exists but is not the route this record describes (db "/data/other.db"/"/data/acme.go.tito.io.db") — leaving it alone
2026/10/14 15:41:39 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:39 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/14 15:41:39 provision: dry-run: would mint instance route acme.go.tito.io (app "tito" acct "bac" channel "stable")
2026/10/14 15:41:39 provision: dry-run: would adopt existing route adopt.go.tito.io (app "tito" acct "bac") — this record would own its channel and environment
2026/10/14 15:41:39 provision: dry-run: would converge adopt.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: dry-run: would converge adopt.go.tito.io environment "" -> "staging"
2026/10/14 15:41:39 provision: dry-run: would converge owned.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: dry-run: would converge owned.go.tito.io environment "" -> "staging"
2026/10/14 15:41:39 provision: dry-run: would converge owned.go.tito.io hibernate false -> true
2026/10/14 15:41:39 provision: dry-run: would converge owned.go.tito.io seed
2026/10/14 15:41:39 provision: dry-run: would remove retired instance route gone.go.tito.io (record gone)
2026/10/14 15:41:39 provision: converged owned.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: converged owned.go.tito.io environment "" -> "staging"
2026/10/14 15:41:39 provision: converged owned.go.tito.io hibernate false -> true
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: adopted existing route adopt.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:39 provision: converged adopt.go.tito.io channel stable -> edge
2026/10/14 15:41:39 provision: converged adopt.go.tito.io environment "" -> "staging"
2026/10/14 15:41:39 provision: removed retired instance route gone.go.tito.io (record gone)
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: adopted existing route story.carlosframework.com (app "story" acct "bad") — this record now owns its channel and environment
2026/10/14 15:41:39 provision: story.carlosframework.com exists but is not the route this record describes (kind "instance"/"static") — leaving it alone
2026/10/14 15:41:39 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route pubs.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route pub.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route exec.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route loop.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route named.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted service route priv.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route unit.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted static route pisite.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: removed retired static route site.go.tito.io (record gone)
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:39 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme-uk.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: converged acme.go.tito.io replicas "ie,uk" -> "uk"
2026/10/14 15:41:40 provision: converged acme.go.tito.io replicas "uk" -> ""
2026/10/14 15:41:40 provision: minted instance route acme-uk.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: converged acme-uk.go.tito.io replica mark true -> false
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: acme.go.tito.io: row is on the nested layout (db "/data/instances/acme.go.tito.io/acme.go.tito.io.db" socket "/run/carlos/instances/acme.go.tito.io/app.sock"); the record's shared paths are not drift
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: acme.go.tito.io: not minting this pass: the box's layout intent could not be read: store down
2026/10/14 15:41:40 provision: router.go.tito.io: not minting this pass: the box's layout intent could not be read: store down
2026/10/14 15:41:40 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/14 15:41:40 provision: converged acme.go.tito.io channel stable -> edge
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
2026/10/14 15:41:40 provision: not removing acme.go.tito.io (record gone): participant of a running operation
2026/10/14 15:41:40 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
2026/10/14 15:41:40 provision: refusing to mint held route acme.go.tito.io (app "tito" acct "bac"): this box declares CARLOS_INBOUND=none (no-inbound) and cannot serve routed instance traffic
2026/10/14 15:41:40 provision: held acme.go.tito.io landing by mv_acme (was ready)
2026/10/14 15:41:40 provision: acme.go.tito.io: held restoring by rb_other, not by mv_acme; leaving it
2026/10/14 15:41:40 provision: acme.go.tito.io: the row is not this pass's (app "other" acct ""); not holding it for mv_acme
2026/10/14 15:41:40 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/14 15:41:40 provision: dry-run: would mint instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac" channel "stable")
2026/10/14 15:41:40 provision: acme.go.tito.io: not held landing by mv_acme: the row's hold changed under this pass; the next pass judges it afresh
2026/10/14 15:41:40 provision: held acme.go.tito.io landing by mv_acme (was ready)
2026/10/14 15:41:40 provision: removed retired sidecar route gone.eleven.bac.sidecar.internal (record gone)
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: converged sidecar bot.eleven.bac.sidecar.internal args ["sidecar","run"] -> ["worker","run"]
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: converged sidecar bot.eleven.bac.sidecar.internal ceilings 300/3600 -> 60/120
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: converged sidecar bot.eleven.bac.sidecar.internal channel stable -> canary/eleven
2026/10/14 15:41:40 provision: converged sidecar bot.eleven.bac.sidecar.internal environment "other" -> "relay"
2026/10/14 15:41:40 provision: converged sidecar bot.eleven.bac.sidecar.internal hibernate true -> false
2026/10/14 15:41:40 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: read failed: failStore: reads disabled under apps/bac/eleven/sidecars/
2026/10/14 15:41:40 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: malformed: invalid character 'n' looking for beginning of object key string
2026/10/14 15:41:40 provision: not removing sidecar bot.eleven.bac.sidecar.internal: its record exists but could not be read cleanly this pass
2026/10/14 15:41:40 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: empty channel
2026/10/14 15:41:40 provision: skipping sidecar record apps/bac/eleven/sidecars/held.json: empty channel
2026/10/14 15:41:40 provision: not removing sidecar held.eleven.bac.sidecar.internal: its record exists but could not be read cleanly this pass
2026/10/14 15:41:40 provision: removed retired sidecar route old.eleven.bac.sidecar.internal (record gone)
2026/10/14 15:41:40 provision: bac/eleven has sidecar records but no sidecars manifest — not minting
2026/10/14 15:41:40 provision: bac/eleven is in the trash — not minting sidecar routes for it
2026/10/14 15:41:40 provision: sidecar bot.eleven.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: sidecar hub.relay.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: minted sidecar route hub.relay.bac.sidecar.internal (app "relay" acct "bac" args ["relay"])
2026/10/14 15:41:40 provision: sidecar bot.eleven.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: sidecar bot.eleven.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: sidecar bot.eleven.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: removed retired sidecar route bot.eleven.bac.sidecar.internal (record gone)
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: sidecar bot.eleven.bac.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/14 15:41:40 provision: skipping sidecar record apps/bac/relay/sidecars/hub.json: read failed: failStore: reads disabled under apps/bac/relay/sidecars/
2026/10/14 15:41:40 provision: REFUSING to mint sidecar bot.eleven.bac.sidecar.internal: bot.eleven.bac.sidecar.internal-sidecar.env is staged on this box — the legacy file co-spawn and a native sidecar row are two mechanisms for one host; remove the file to migrate this host onto sidecar records
2026/10/14 15:41:40 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/14 15:41:40 provision: dry-run: would mint sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" channel "stable" args ["sidecar","run"])
2026/10/14 15:41:40 provision: dry-run: would remove retired sidecar route gone.eleven.bac.sidecar.internal (record gone)
2026/10/14 15:41:40 provision: bot.eleven.bac.sidecar.internal exists but is not a sidecar row this pass owns (kind "sidecar" provisioned false app "eleven" acct "bac") — leaving it alone
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: converged acme.go.tito.io update settings "{\"updates\":\"manual\",\"channel\":\"stable\"}" -> ""
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/14 15:41:40 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/14 15:41:40 provision: acme.go.tito.io: not minted this pass: the app's update policy could not be read
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/14 15:41:40 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/14 15:41:40 provision: acme.go.tito.io: not minted this pass: the app's update policy could not be read
2026/10/14 15:41:40 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
FAIL
FAIL	github.com/carlosframework/platform/internal/provision	21.820s
ok  	github.com/carlosframework/platform/internal/publicrelease	0.013s
?   	github.com/carlosframework/platform/internal/regionname	[no test files]
ok  	github.com/carlosframework/platform/internal/registry	5.044s
ok  	github.com/carlosframework/platform/internal/relay	7.362s
ok  	github.com/carlosframework/platform/internal/release	24.815s
ok  	github.com/carlosframework/platform/internal/rollout	5.195s
ok  	github.com/carlosframework/platform/internal/rolloutwords	0.004s
ok  	github.com/carlosframework/platform/internal/rootaws	0.010s
ok  	github.com/carlosframework/platform/internal/rootparticipation	0.010s
ok  	github.com/carlosframework/platform/internal/rootstate	0.029s
ok  	github.com/carlosframework/platform/internal/s3compat	0.010s
ok  	github.com/carlosframework/platform/internal/safefile	0.005s
ok  	github.com/carlosframework/platform/internal/schedule	3.150s
ok  	github.com/carlosframework/platform/internal/sim/hostlife	23.916s
ok  	github.com/carlosframework/platform/internal/sim/litestreamfacts	3.645s
ok  	github.com/carlosframework/platform/internal/status	0.038s
ok  	github.com/carlosframework/platform/internal/steering	0.009s
ok  	github.com/carlosframework/platform/internal/stopevidence	0.292s
ok  	github.com/carlosframework/platform/internal/svcrole	0.002s
ok  	github.com/carlosframework/platform/internal/telemetry	0.005s
ok  	github.com/carlosframework/platform/internal/termfence	0.046s
ok  	github.com/carlosframework/platform/internal/tunnelclient	0.006s
ok  	github.com/carlosframework/platform/internal/unixdial	0.003s
ok  	github.com/carlosframework/platform/internal/updatewords	0.006s
ok  	github.com/carlosframework/platform/internal/usage	0.016s
ok  	github.com/carlosframework/platform/internal/version	0.003s
ok  	github.com/carlosframework/platform/internal/vet	1.863s
FAIL
make: *** [Makefile:18: test] Error 1

amadan: step gate failed: exit status 2

amadan: job failed at step gate — its output is above, not at the tail of this log
diff --git a/internal/activator/activator.go b/internal/activator/activator.go
index ec5721a16..a3f7b1b31 100644
--- a/internal/activator/activator.go
+++ b/internal/activator/activator.go
@@ -75,6 +75,7 @@ import (
"github.com/carlosframework/platform/internal/hostclaim"
"github.com/carlosframework/platform/internal/hostwrite"
"github.com/carlosframework/platform/internal/instancectl"
+ "github.com/carlosframework/platform/internal/lease"
"github.com/carlosframework/platform/internal/registry"
"github.com/carlosframework/platform/internal/release"
)
@@ -319,10 +320,14 @@ func (a *Service) retryOwedRelease(o *owedRelease) {
ctx, cancel := context.WithTimeout(context.Background(), leaseReleaseBudget)
err := o.lease.RetryRelease(ctx)
cancel()
+ // A record past its own expiry is retired even though the delete still
+ // fails (lease.ErrReleaseLapsed): the lease is free to any acquirer by
+ // then, and a persistent refusal must not keep obligations forever.
+ lapsed := errors.Is(err, lease.ErrReleaseLapsed)
a.mu.Lock()
o.busy = false
- logIt := err == nil || time.Since(o.lastLog) >= 30*time.Second
- if err == nil {
+ logIt := err == nil || lapsed || time.Since(o.lastLog) >= 30*time.Second
+ if err == nil || lapsed {
delete(a.owedReleases, o)
} else if logIt {
o.lastLog = time.Now()
@@ -331,6 +336,8 @@ func (a *Service) retryOwedRelease(o *owedRelease) {
switch {
case err == nil:
log.Printf("activator: %s: lease given back on retry", o.host)
+ case lapsed:
+ log.Printf("activator: %s: lease release retired, never deleted: %v", o.host, err)
case logIt:
log.Printf("activator: %s: retrying the lease's release: %v", o.host, err)
}
@@ -1151,6 +1158,9 @@ type Service struct {
// off (#292): once it is set nothing wakes, and an exited child is
// Shutdown's to stop, never recycled as an unexpected exit.
shuttingDown bool
+ // shutdownCtx is Shutdown's budget, set with shuttingDown: a legacy
+ // proof runs under the sooner of its own budget and this (#292).
+ shutdownCtx context.Context
// convergeBudget is how many build-convergence cycles this sweep may
// still start: reset to maxConvergeCyclesPerSweep at the top of every
@@ -4980,6 +4990,9 @@ func (a *Service) Shutdown(ctx context.Context) {
// below cover the rest.)
a.mu.Lock()
a.shuttingDown = true
+ // Proofs that start or run from here end with this budget too
+ // (legacyRunGone, #292): none may outlive Shutdown.
+ a.shutdownCtx = ctx
sweepStop, sweepDone := a.sweepStop, a.sweepDone
a.mu.Unlock()
// …and cancel the service lifetime, which TEARS DOWN any worker spawn
diff --git a/internal/activator/activator_test.go b/internal/activator/activator_test.go
index c6b218703..dbadf7e90 100644
--- a/internal/activator/activator_test.go
+++ b/internal/activator/activator_test.go
@@ -34,6 +34,7 @@ import (
"github.com/carlosframework/platform/internal/cgroup"
"github.com/carlosframework/platform/internal/edge"
+ "github.com/carlosframework/platform/internal/lease"
"github.com/carlosframework/platform/internal/provision"
"github.com/carlosframework/platform/internal/registry"
@@ -303,6 +304,10 @@ func (l *fakeLease) RetryRelease(context.Context) error {
if len(l.b.retryErrs) > 0 {
err := l.b.retryErrs[0]
l.b.retryErrs = l.b.retryErrs[1:]
+ if l.b.leaseLapsed {
+ l.owed = false
+ return fmt.Errorf("%w: %w", lease.ErrReleaseLapsed, err)
+ }
return err
}
l.owed = false
@@ -313,10 +318,20 @@ func (l *fakeLease) RetryRelease(context.Context) error {
// LegacyRunGone is ExecBackend's: the legacy run unit's stop, which
// replaces a queued start job, and its proof.
-func (b *fakeBackend) LegacyRunGone(context.Context, registry.Route) error {
+func (b *fakeBackend) LegacyRunGone(ctx context.Context, _ registry.Route) error {
b.mu.Lock()
- defer b.mu.Unlock()
b.legacyStops++
+ block := b.legacyBlock
+ b.mu.Unlock()
+ if block {
+ <-ctx.Done()
+ b.mu.Lock()
+ b.legacyEnded++
+ b.mu.Unlock()
+ return ctx.Err()
+ }
+ b.mu.Lock()
+ defer b.mu.Unlock()
if b.legacyStopErr != nil {
return b.legacyStopErr
}
@@ -364,6 +379,13 @@ type fakeBackend struct {
// answer (an unproven stop) while set.
legacyStops int
legacyStopErr error
+ // legacyBlock holds every LegacyRunGone until its context ends (a
+ // stop that never proves); legacyEnded counts those that returned.
+ legacyBlock bool
+ legacyEnded int
+ // leaseLapsed: the owed records have passed their expiry, so a retry
+ // that fails again answers lease.ErrReleaseLapsed, as lease.Held does.
+ leaseLapsed bool
// queuedAtRelease is queuedJobs at each lease release that landed: a
// release over a still-queued job is the single-writer violation.
queuedAtRelease []int
diff --git a/internal/activator/containment.go b/internal/activator/containment.go
index 5ba74d117..da3a2a6e7 100644
--- a/internal/activator/containment.go
+++ b/internal/activator/containment.go
@@ -77,13 +77,22 @@ var errNoLegacyProof = errors.New("activator: this backend cannot prove a run un
// context is often why the start was aborted).
const legacyStopBudget = instancectl.DeadlineControl
-// legacyRunGone runs the backend's proof for rt under legacyStopBudget.
+// legacyRunGone runs the backend's proof for rt under legacyStopBudget or,
+// once Shutdown has begun, whichever ends first of that and Shutdown's own
+// budget (Astra, round 2): no proof outlives Shutdown, and one cut short is
+// unproven, so the lease is kept.
func (a *Service) legacyRunGone(rt registry.Route) error {
p, ok := a.backend.(legacyRunProver)
if !ok {
return errNoLegacyProof
}
- ctx, cancel := context.WithTimeout(context.Background(), legacyStopBudget)
+ parent := context.Background()
+ a.mu.Lock()
+ if a.shutdownCtx != nil {
+ parent = a.shutdownCtx
+ }
+ a.mu.Unlock()
+ ctx, cancel := context.WithTimeout(parent, legacyStopBudget)
defer cancel()
return p.LegacyRunGone(ctx, rt)
}
diff --git a/internal/activator/shutdown_lease_test.go b/internal/activator/shutdown_lease_test.go
index 2bf35fd86..6bb46e6fe 100644
--- a/internal/activator/shutdown_lease_test.go
+++ b/internal/activator/shutdown_lease_test.go
@@ -370,3 +370,69 @@ func TestAnExitAfterShutdownBeganIsNotUnexpected(t *testing.T) {
t.Fatalf("lease releases = %d, want 1", got)
}
}
+
+// Round 2 P2: release obligations expire. Under a persistent DELETE refusal
+// with acquisition still allowed, every failed wake adds one; once their
+// records pass their own expiry the retries retire them (logged) instead
+// of running forever.
+func TestOwedReleasesAreRetiredOnceTheirRecordsExpire(t *testing.T) {
+ logs := lockedLog(t)
+ a, b, _, _ := testActivator(t, time.Hour)
+ b.startErr = errors.New("start failed")
+ hosts := []string{"one.example.com", "two.example.com", "three.example.com"}
+ for range hosts {
+ b.releaseErrs = append(b.releaseErrs, errors.New("delete lease: AccessDenied"))
+ }
+ for i := 0; i < 1000; i++ {
+ b.retryErrs = append(b.retryErrs, errors.New("delete lease: AccessDenied"))
+ }
+ for _, h := range hosts {
+ if _, err := a.beginRequest(context.Background(), testRoute(h)); err == nil {
+ t.Fatalf("%s: the wake succeeded", h)
+ }
+ }
+ owed := func() int {
+ a.mu.Lock()
+ defer a.mu.Unlock()
+ a.finishPendingStops()
+ return len(a.owedReleases)
+ }
+ time.Sleep(50 * time.Millisecond)
+ if n := owed(); n != len(hosts) {
+ t.Fatalf("owed releases = %d before expiry, want %d", n, len(hosts))
+ }
+ b.mu.Lock()
+ b.leaseLapsed = true
+ b.mu.Unlock()
+ waitFor(t, "the expired obligations to be retired", func() bool { return owed() == 0 })
+ out := logs.String()
+ if !strings.Contains(out, "retired") {
+ t.Fatalf("no retirement line; log:\n%s", out)
+ }
+ if strings.Contains(out, "given back on retry") || b.releaseCount() != 0 {
+ t.Fatalf("an expired, never-deleted lease was reported as given back; log:\n%s", out)
+ }
+}
+
+// Astra, lower priority: the legacy proof is bounded by Shutdown's budget
+// as well as its own 30 s, whichever ends first, so no proof outlives
+// Shutdown. Unproven, the lease is still kept.
+func TestTheLegacyProofEndsWithShutdownsBudget(t *testing.T) {
+ a, b, _ := arrangeQueuedRewake(t, "slowproof.example.com")
+ b.mu.Lock()
+ b.legacyBlock = true
+ b.mu.Unlock()
+
+ ctx, cancel := context.WithTimeout(context.Background(), 300*time.Millisecond)
+ defer cancel()
+ a.Shutdown(ctx)
+ waitFor(t, "the proof to end with Shutdown's budget", func() bool {
+ b.mu.Lock()
+ defer b.mu.Unlock()
+ return b.legacyEnded > 0
+ })
+ acq, _, _ := b.counts()
+ if got := b.releaseCount(); got != acq-1 {
+ t.Fatalf("lease releases = %d, want %d: an unproven start keeps its lease", got, acq-1)
+ }
+}
diff --git a/internal/instancectl/legacystart.go b/internal/instancectl/legacystart.go
new file mode 100644
index 000000000..abc64f542
--- /dev/null
+++ b/internal/instancectl/legacystart.go
@@ -0,0 +1,144 @@
+package instancectl
+
+import (
+ "context"
+ "errors"
+ "fmt"
+ "net"
+ "time"
+)
+
+// Legacy run start attempts (#292, Astra round 2 P1, the owner's ruling).
+//
+// The agent proves an aborted start's unit stopped through /stop before it
+// gives the lease back. Cancelling its /start does not join this side's
+// handler, which could still submit the systemd start after that /stop had
+// answered, if it had not yet seen the disconnect; systemd's replacement of
+// a queued start by a stop only covers jobs that already exist. So, for the
+// original run unit (carlos-instance@, generation 0) only, start and stop
+// are ordered per host here:
+//
+// - every /start registers an attempt with a context /stop can cancel,
+// and checks that context immediately before it submits the start;
+// - a /stop fences the host: new starts are refused while it runs, every
+// attempt in flight is cancelled and joined (bounded), and only then is
+// the unit stopped, which replaces any job a joined attempt submitted;
+// - a start whose request was accepted before a stop of the host (the
+// connection's accept order, connSeq) is an earlier request, and is
+// refused once that stop has fenced the host, however late its handler
+// runs.
+//
+// Once /stop has answered, no start from an earlier request is in flight or
+// can be submitted afterwards. Generation units, seeds, sidecars and the
+// claim verbs are untouched.
+
+// legacyJoinBudget bounds how long a /stop waits for the start attempts it
+// cancelled to return. One that is still running then may yet submit, so
+// the stop answers an error and the agent keeps the lease.
+const legacyJoinBudget = 10 * time.Second
+
+// legacyAttempt is one in-flight legacy run start.
+type legacyAttempt struct {
+ cancel context.CancelFunc
+ done chan struct{}
+}
+
+// connSeqKey carries a connection's accept order in its request contexts.
+type connSeqKey struct{}
+
+// nextConnSeq hands out the next accept-order number (from 1).
+func (s *Server) nextConnSeq() uint64 { return s.connSeq.Add(1) }
+
+// connContext is Serve's ConnContext: the claim verbs' connection value,
+// and the connection's accept order. ConnContext runs on the accept loop,
+// once per connection, in accept order.
+func (s *Server) connContext(ctx context.Context, c net.Conn) context.Context {
+ return context.WithValue(requestConnContext(ctx, c), connSeqKey{}, s.nextConnSeq())
+}
+
+// requestSeq is a request's accept order; 0 when its connection was not
+// stamped (a handler called outside Serve), which no fence refuses.
+func requestSeq(ctx context.Context) uint64 {
+ n, _ := ctx.Value(connSeqKey{}).(uint64)
+ return n
+}
+
+// errLegacyFenced refuses a start while a stop of its host runs, or one
+// whose request came before a stop of its host.
+var errLegacyFenced = errors.New("a stop of this host's run unit has run since this start was asked for")
+
+// beginLegacyStart registers a legacy run start of host for a request of
+// accept order seq. Its context is parent's, cancellable by a /stop of the
+// host; finish must be called when the handler returns.
+func (s *Server) beginLegacyStart(parent context.Context, host string, seq uint64) (context.Context, func(), error) {
+ s.legacyMu.Lock()
+ defer s.legacyMu.Unlock()
+ if s.legacyStopping[host] > 0 || (seq != 0 && seq <= s.legacyBarrier[host]) {
+ return nil, nil, errLegacyFenced
+ }
+ ctx, cancel := context.WithCancel(parent)
+ a := &legacyAttempt{cancel: cancel, done: make(chan struct{})}
+ if s.legacyStarts == nil {
+ s.legacyStarts = make(map[string]map[*legacyAttempt]struct{})
+ }
+ if s.legacyStarts[host] == nil {
+ s.legacyStarts[host] = make(map[*legacyAttempt]struct{})
+ }
+ s.legacyStarts[host][a] = struct{}{}
+ finish := func() {
+ s.legacyMu.Lock()
+ delete(s.legacyStarts[host], a)
+ if len(s.legacyStarts[host]) == 0 {
+ delete(s.legacyStarts, host)
+ }
+ s.legacyMu.Unlock()
+ cancel()
+ close(a.done)
+ }
+ return ctx, finish, nil
+}
+
+// fenceLegacyStarts is a /stop's first step for host, its request of accept
+// order seq: refuse new starts and every earlier request's, cancel the
+// attempts in flight and join them, bounded by legacyJoinBudget and ctx.
+// release lifts the refusal of new starts once the stop is done; the
+// earlier requests stay refused. An error means an attempt did not return
+// in time and may still submit.
+func (s *Server) fenceLegacyStarts(ctx context.Context, host string, seq uint64) (func(), error) {
+ s.legacyMu.Lock()
+ if s.legacyStopping == nil {
+ s.legacyStopping = make(map[string]int)
+ }
+ if s.legacyBarrier == nil {
+ s.legacyBarrier = make(map[string]uint64)
+ }
+ s.legacyStopping[host]++
+ if seq > s.legacyBarrier[host] {
+ s.legacyBarrier[host] = seq
+ }
+ var inFlight []*legacyAttempt
+ for a := range s.legacyStarts[host] {
+ inFlight = append(inFlight, a)
+ }
+ s.legacyMu.Unlock()
+ release := func() {
+ s.legacyMu.Lock()
+ if s.legacyStopping[host]--; s.legacyStopping[host] <= 0 {
+ delete(s.legacyStopping, host)
+ }
+ s.legacyMu.Unlock()
+ }
+ timer := time.NewTimer(legacyJoinBudget)
+ defer timer.Stop()
+ for _, a := range inFlight {
+ a.cancel()
+ select {
+ case <-a.done:
+ case <-timer.C:
+ return release, fmt.Errorf("a start of %s is still in flight after %s", host, legacyJoinBudget)
+ case <-ctx.Done():
+ return release, fmt.Errorf("a start of %s is still in flight: %w", host, ctx.Err())
+ }
+ }
+ return release, nil
+}
diff --git a/internal/instancectl/legacystart_test.go b/internal/instancectl/legacystart_test.go
new file mode 100644
index 000000000..785b57c5d
--- /dev/null
+++ b/internal/instancectl/legacystart_test.go
@@ -0,0 +1,114 @@
+package instancectl
+
+import (
+ "context"
+ "net/http"
+ "strings"
+ "testing"
+ "time"
+)
+
+// #292, Astra round 2 P1: cancelling the agent's /start does not join
+// root's start handler, which can still submit its systemd start after a
+// /stop for the same host has answered, if it has not yet seen the
+// disconnect. The agent then proves the unit stopped, gives the lease
+// back, and the late job launches a writer no lease covers. Here the
+// handler is held before its submit, past the client's cancellation, and
+// does not see that cancellation (unseenCancel): no start may be submitted
+// once the /stop has returned.
+func TestALegacyStartDelayedPastItsCancellationNeverSubmitsAfterAStop(t *testing.T) {
+ host := "late.example.com"
+ unit := UnitName(RoleRun, host)
+ entered, gate := make(chan struct{}), make(chan struct{})
+ ctl := &fakeCtl{
+ answers: map[string]string{"show -p InvocationID --value": "inv1\n"},
+ unseenCancel: true,
+ before: map[string]func(){"set-property": func() {
+ close(entered)
+ <-gate
+ }},
+ }
+ _, c := newServer(t, ctl)
+
+ startCtx, cancelStart := context.WithCancel(context.Background())
+ startDone := make(chan struct{})
+ go func() {
+ defer close(startDone)
+ req, _ := http.NewRequestWithContext(startCtx, http.MethodPost, "http://unix/start?host="+host+"&role=run&memory_max=536870912", nil)
+ if resp, err := c.Do(req); err == nil {
+ resp.Body.Close()
+ }
+ }()
+ select {
+ case <-entered:
+ case <-time.After(5 * time.Second):
+ t.Fatal("the start handler never reached its tier step")
+ }
+ cancelStart() // the client gives up; the handler has not noticed
+ <-startDone
+
+ stopped := make(chan int, 1)
+ go func() {
+ resp := post(t, c, "/stop?host="+host+"&role=run")
+ resp.Body.Close()
+ stopped <- resp.StatusCode
+ }()
+ // The held handler goes on past the cancellation it has not seen.
+ time.Sleep(100 * time.Millisecond)
+ close(gate)
+ var status int
+ select {
+ case status = <-stopped:
+ case <-time.After(15 * time.Second):
+ t.Fatal("/stop never returned")
+ }
+ if status != http.StatusNoContent {
+ t.Fatalf("/stop status %d, want 204", status)
+ }
+ stopAt := len(strings.Split(ctl.joined(), "\n"))
+
+ // Give the held handler every chance to submit late.
+ deadline := time.Now().Add(time.Second)
+ for time.Now().Before(deadline) {
+ calls := strings.Split(ctl.joined(), "\n")
+ for _, line := range calls[stopAt:] {
+ if line == "start "+unit {
+ t.Fatalf("a start was submitted after /stop returned; calls:\n%s", ctl.joined())
+ }
+ }
+ time.Sleep(20 * time.Millisecond)
+ }
+ calls := ctl.joined()
+ stopIdx := strings.Index(calls, "stop "+unit)
+ if stopIdx < 0 {
+ t.Fatalf("the unit was never stopped; calls:\n%s", calls)
+ }
+ if i := strings.LastIndex(calls, "start "+unit); i > stopIdx {
+ t.Fatalf("a start was submitted after the stop; calls:\n%s", calls)
+ }
+}
+
+// A start whose own request was accepted before a /stop for the host is an
+// earlier request: refused once that stop has run, even if its handler only
+// gets going afterwards.
+func TestALegacyStartFromBeforeAStopIsRefused(t *testing.T) {
+ host := "early.example.com"
+ ctl := &fakeCtl{answers: map[string]string{"show -p InvocationID --value": "inv1\n"}}
+ s, _ := newServer(t, ctl)
+ // Stamp two connections in accept order: the start's first.
+ startSeq := s.nextConnSeq()
+ stopSeq := s.nextConnSeq()
+ release, err := s.fenceLegacyStarts(context.Background(), host, stopSeq)
+ if err != nil {
+ t.Fatalf("fence: %v", err)
+ }
+ release()
+ if _, _, err := s.beginLegacyStart(context.Background(), host, startSeq); err == nil {
+ t.Fatal("a start accepted before the stop was admitted after it")
+ }
+ if _, finish, err := s.beginLegacyStart(context.Background(), host, s.nextConnSeq()); err != nil {
+ t.Fatalf("a start accepted after the stop was refused: %v", err)
+ } else {
+ finish()
+ }
+}
diff --git a/internal/instancectl/server.go b/internal/instancectl/server.go
index 5df53ae72..ed023fb29 100644
--- a/internal/instancectl/server.go
+++ b/internal/instancectl/server.go
@@ -17,6 +17,7 @@ import (
"strconv"
"strings"
"sync"
+ "sync/atomic"
"time"
"github.com/carlosframework/platform/internal/cgroup"
@@ -116,6 +117,16 @@ type Server struct {
genMu sync.Mutex
genStarting map[string]bool
+ // Legacy run start attempts per host (legacystart.go, #292): the
+ // starts in flight, the stops in progress, and each host's barrier,
+ // the accept order of the latest stop's request. connSeq numbers
+ // connections in accept order.
+ legacyMu sync.Mutex
+ legacyStarts map[string]map[*legacyAttempt]struct{}
+ legacyStopping map[string]int
+ legacyBarrier map[string]uint64
+ connSeq atomic.Uint64
+
mu sync.Mutex
report ProbeReport
probed bool
@@ -203,7 +214,7 @@ func runWithClaim(args []string, claim, heldRelease http.Handler, hostApp func(s
// yields vetted connections.
func (s *Server) Serve(ctx context.Context, ln net.Listener) error {
vetted := &vettedListener{Listener: ln, ok: s.peerOK, logf: s.logf}
- srv := &http.Server{Handler: s.Handler(), ReadHeaderTimeout: 5 * time.Second, ConnContext: requestConnContext}
+ srv := &http.Server{Handler: s.Handler(), ReadHeaderTimeout: 5 * time.Second, ConnContext: s.connContext}
go func() {
<-ctx.Done()
srv.Close()
@@ -436,6 +447,17 @@ func (s *Server) handleStart(w http.ResponseWriter, r *http.Request) {
return
}
ctx := r.Context()
+ if req.role == RoleRun {
+ // An attempt a /stop of this host can cancel and join, and that a
+ // stop which has already run refuses (legacystart.go, #292).
+ attempt, finish, err := s.beginLegacyStart(ctx, req.host, requestSeq(ctx))
+ if err != nil {
+ http.Error(w, "start: "+err.Error(), http.StatusConflict)
+ return
+ }
+ defer finish()
+ ctx = attempt
+ }
unit := UnitName(req.role, req.host)
// A sidecar naming its generation's staged build, or a run unit naming
// the build its cold wake recorded, is validated before anything is
@@ -470,6 +492,12 @@ func (s *Server) handleStart(w http.ResponseWriter, r *http.Request) {
http.Error(w, "set-property: "+err.Error(), http.StatusBadGateway)
return
}
+ // Never submitted once cancelled (#292): a /stop of this host cancels
+ // the attempt before it joins it, and the client may have gone.
+ if err := ctx.Err(); err != nil {
+ http.Error(w, "start: cancelled before it was submitted: "+err.Error(), http.StatusConflict)
+ return
+ }
if out, err := s.Systemctl(ctx, "start", unit); err != nil {
http.Error(w, "start: "+strings.TrimSpace(out+" "+err.Error()), http.StatusBadGateway)
return
@@ -617,6 +645,21 @@ func (s *Server) handleStop(w http.ResponseWriter, r *http.Request) {
s.stopGen(w, r, req)
return
}
+ if req.role == RoleRun {
+ // Every start of this host's run unit in flight is cancelled and
+ // joined first, and earlier requests' starts are refused from here
+ // on (legacystart.go, #292): once this answers, no start from an
+ // earlier request can still be submitted, and the stop below
+ // replaces any job a joined start had submitted.
+ release, err := s.fenceLegacyStarts(r.Context(), req.host, requestSeq(r.Context()))
+ defer release()
+ if err != nil {
+ // Stopped anyway, but not proven final: a start may follow.
+ _, _ = s.Systemctl(r.Context(), "stop", UnitName(req.role, req.host))
+ http.Error(w, "stop: "+err.Error(), http.StatusBadGateway)
+ return
+ }
+ }
if out, err := s.Systemctl(r.Context(), "stop", UnitName(req.role, req.host)); err != nil {
http.Error(w, "stop: "+strings.TrimSpace(out+" "+err.Error()), http.StatusBadGateway)
return
diff --git a/internal/instancectl/server_test.go b/internal/instancectl/server_test.go
index 5ef76bc3c..d9ec6f9eb 100644
--- a/internal/instancectl/server_test.go
+++ b/internal/instancectl/server_test.go
@@ -28,9 +28,26 @@ type fakeCtl struct {
// simulate a client that disconnects the instant systemctl start
// answers (fix round 1, item 4).
onStart func()
+ // before, keyed by a verb (args[0]), runs once, synchronously, before
+ // that verb's call is recorded: a test holds a handler there.
+ before map[string]func()
+ // unseenCancel models a handler that has not yet seen its client go
+ // (#292): its systemctl calls run although the request's context is
+ // done, the race exec.CommandContext cannot close on its own.
+ unseenCancel bool
}
func (f *fakeCtl) run(ctx context.Context, args ...string) (string, error) {
+ f.mu.Lock()
+ var pre func()
+ if len(args) > 0 && f.before[args[0]] != nil {
+ pre = f.before[args[0]]
+ delete(f.before, args[0])
+ }
+ f.mu.Unlock()
+ if pre != nil {
+ pre()
+ }
f.mu.Lock()
line := strings.Join(args, " ")
f.calls = append(f.calls, line)
@@ -38,6 +55,7 @@ func (f *fakeCtl) run(ctx context.Context, args ...string) (string, error) {
if len(args) > 0 && args[0] == "start" && f.onStart != nil {
hook, f.onStart = f.onStart, nil
}
+ unseen := f.unseenCancel
f.mu.Unlock()
if hook != nil {
hook()
@@ -47,7 +65,7 @@ func (f *fakeCtl) run(ctx context.Context, args ...string) (string, error) {
// must behave the same way, or a test cannot tell a handler that used
// the request's context apart from one that used a detached one (fix
// round 1, item 4).
- if ctx.Err() != nil {
+ if ctx.Err() != nil && !unseen {
return "", ctx.Err()
}
f.mu.Lock()
diff --git a/internal/lease/lease.go b/internal/lease/lease.go
index e221468d8..3da80af54 100644
--- a/internal/lease/lease.go
+++ b/internal/lease/lease.go
@@ -307,11 +307,20 @@ func (h *Held) ReleaseOwed() bool {
return h.owed != nil
}
+// ErrReleaseLapsed is RetryRelease's answer when the delete failed again
+// but the owed record has passed its own expiry: the lease is free to any
+// acquirer by then, so the obligation is retired rather than retried
+// forever (#292). It wraps the delete's own error.
+var ErrReleaseLapsed = errors.New("lease release retired: the lease record has passed its expiry")
+
// RetryRelease discharges what a failed Release left owed (#292): the same
// conditional delete (If-Match on the lease's ETag), so it can never delete
// a lease someone else has taken since. nil once nothing is owed, including
-// when the record is already gone or is no longer ours. Callers do not run
-// it concurrently with itself.
+// when the record is already gone or is no longer ours. A delete that fails
+// again once the record has passed its own expiry retires the obligation
+// with ErrReleaseLapsed: under a persistent refusal (AccessDenied, say)
+// obligations would otherwise pile up and be retried forever. Callers do
+// not run it concurrently with itself.
func (h *Held) RetryRelease(ctx context.Context) error {
h.mu.Lock()
lease := h.owed
@@ -320,7 +329,15 @@ func (h *Held) RetryRelease(ctx context.Context) error {
return nil
}
if err := h.leaser.ReleaseLease(ctx, lease); err != nil && !releaseSettled(err) {
- return err
+ if lease.ExpiresAt.IsZero() || time.Now().Before(lease.ExpiresAt) {
+ return err
+ }
+ h.mu.Lock()
+ if h.owed == lease {
+ h.owed = nil
+ }
+ h.mu.Unlock()
+ return fmt.Errorf("%w (expired %s): %w", ErrReleaseLapsed, lease.ExpiresAt.UTC().Format(time.RFC3339), err)
}
h.mu.Lock()
if h.owed == lease {
diff --git a/internal/lease/release_retry_test.go b/internal/lease/release_retry_test.go
index e4f5696d7..235628cc9 100644
--- a/internal/lease/release_retry_test.go
+++ b/internal/lease/release_retry_test.go
@@ -2,6 +2,8 @@ package lease
import (
"context"
+ "errors"
+ "fmt"
"net/http"
"net/http/httptest"
"sync"
@@ -138,3 +140,54 @@ func TestASuccessfulReleaseOwesNothing(t *testing.T) {
t.Fatal("a successful release left an obligation")
}
}
+
+// Round 2 P2: under a persistent DELETE failure with acquisition still
+// allowed, obligations must not pile up forever. Each failed release stays
+// owed until its own record's expiry; past it, a retry that still fails
+// retires the obligation (ErrReleaseLapsed) rather than retrying forever.
+// Two acquisitions in a row, both failing to release, across that expiry.
+func TestAnOwedReleaseIsRetiredOnceItsRecordHasExpired(t *testing.T) {
+ stub := &deleteStub{statuses: []int{
+ http.StatusForbidden, http.StatusForbidden, http.StatusForbidden, http.StatusForbidden,
+ http.StatusForbidden, http.StatusForbidden, http.StatusForbidden, http.StatusForbidden,
+ }}
+ srv := httptest.NewServer(stub)
+ defer srv.Close()
+ ctx := context.Background()
+ expires := time.Now().Add(300 * time.Millisecond)
+ var held []*Held
+ for i := 0; i < 2; i++ {
+ h := heldExpiring(t, srv, fmt.Sprintf(`"e%d"`, i), expires)
+ if err := h.Release(ctx); err == nil {
+ t.Fatal("Release succeeded against a refusing store")
+ }
+ held = append(held, h)
+ }
+ for _, h := range held {
+ if err := h.RetryRelease(ctx); err == nil || errors.Is(err, ErrReleaseLapsed) {
+ t.Fatalf("a retry before the record's expiry = %v, want the store's refusal", err)
+ }
+ if !h.ReleaseOwed() {
+ t.Fatal("an unexpired record stopped being owed")
+ }
+ }
+ time.Sleep(time.Until(expires) + 50*time.Millisecond)
+ for _, h := range held {
+ if err := h.RetryRelease(ctx); !errors.Is(err, ErrReleaseLapsed) {
+ t.Fatalf("a failed retry past the record's expiry = %v, want ErrReleaseLapsed", err)
+ }
+ if h.ReleaseOwed() {
+ t.Fatal("an expired record is still owed")
+ }
+ }
+}
+
+// heldExpiring is heldAgainst with the record's own expiry set.
+func heldExpiring(t *testing.T, srv *httptest.Server, etag string, expires time.Time) *Held {
+ t.Helper()
+ h := heldAgainst(t, srv, etag)
+ h.rn.mu.Lock()
+ h.rn.lease.ExpiresAt = expires
+ h.rn.mu.Unlock()
+ return h
+}