amadan
edge: pressure-gated fair share and backstop per instance, observe by default (#358)
The edge judges every instance request at the last point before the activator or the proxy: after the meter, the password gate and the cache check, so a cache hit is never limited and a refusal never wakes an instance. An admitted request holds a slot until the instance starts its answer (slotWriter), including while it waits on a wake. Upgrades are judged at the handshake and hold no slot, keeping the raw writer. The limiter keys on the route host, so an alias spends its primary's buckets, and on clientIP, so a verified hop is keyed by the client it carries. Door callers and requests that arrived over a fleet tunnel are never limited; the hub, which has the row and the real client, limits. CARLOS_RATE_LIMIT is off, observe (default) or enforce. Observe counts and logs what it would refuse. usage.EdgeRow gains rate_shed and rate_ceiling, summed in AddDeltas. A rate_limit column the edge cannot use runs at the defaults and is logged. The agent arms the plan ceiling hook beside the usage meter. Census digests (plan9 B8, plan14 root reads) are not re-pinned here, per the controller's ruling.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
7 files changed,
+1076
−2
internal/edge/edge.go+41 −2internal/edge/ratelimit.go+244 −0internal/edge/ratelimit_test.go+719 −0internal/edge/usagemeter.go+22 −0internal/host/agent.go+4 −0internal/usage/edge.go+11 −0internal/usage/edge_ratelimit_test.go+35 −0
CI failed — run details
CI log
=== gate ===
.amadan/test-gate.sh
=== launchctx (0 s)
ok amadan.net/carlos/platform.git/launchctx 0.012s
? amadan.net/carlos/platform.git/launchctx/controlname [no test files]
? amadan.net/carlos/platform.git/launchctx/wireid [no test files]
=== vet (18 s)
=== gofmt (0 s)
gofmt -l .: clean
=== rest (173 s)
? github.com/carlosframework/platform/cmd/changelog [no test files]
ok github.com/carlosframework/platform/cmd/console 3.739s
ok github.com/carlosframework/platform/cmd/moveprobe 12.018s
ok github.com/carlosframework/platform/cmd/zddprobe 0.731s
ok github.com/carlosframework/platform/internal/activator 58.220s
ok github.com/carlosframework/platform/internal/agentsock 0.030s
ok github.com/carlosframework/platform/internal/alerting 0.006s
ok github.com/carlosframework/platform/internal/analytics 0.034s
ok github.com/carlosframework/platform/internal/appconfig 3.053s
ok github.com/carlosframework/platform/internal/apperr 0.167s
ok github.com/carlosframework/platform/internal/applog 0.321s
ok github.com/carlosframework/platform/internal/awsinv 0.016s
ok github.com/carlosframework/platform/internal/boxchoice 0.008s
ok github.com/carlosframework/platform/internal/boxid 0.946s
? 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.016s
ok github.com/carlosframework/platform/internal/caps 0.015s
ok github.com/carlosframework/platform/internal/certwarm 0.004s
ok github.com/carlosframework/platform/internal/cgroup 0.825s
ok github.com/carlosframework/platform/internal/changelog 0.590s
ok github.com/carlosframework/platform/internal/claimactivation 1.399s
ok github.com/carlosframework/platform/internal/clamd 0.067s
? github.com/carlosframework/platform/internal/cliflag [no test files]
? 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 7.778s
ok github.com/carlosframework/platform/internal/dbdoor/dbdoortest 0.011s
ok github.com/carlosframework/platform/internal/dbquery 0.017s
ok github.com/carlosframework/platform/internal/dbreads 2.212s
? github.com/carlosframework/platform/internal/dbreads/dbreadstest [no test files]
ok github.com/carlosframework/platform/internal/dbverify 0.006s
ok github.com/carlosframework/platform/internal/dnsrec 0.006s
ok github.com/carlosframework/platform/internal/docsite 0.024s
ok github.com/carlosframework/platform/internal/domains 3.019s
ok github.com/carlosframework/platform/internal/doorkey 0.015s
ok github.com/carlosframework/platform/internal/economics 0.010s
ok github.com/carlosframework/platform/internal/edge 45.940s
? github.com/carlosframework/platform/internal/edgeproof [no test files]
ok github.com/carlosframework/platform/internal/edgesfile 0.008s
ok github.com/carlosframework/platform/internal/fleetapi 0.134s
ok github.com/carlosframework/platform/internal/gate 1.655s
ok github.com/carlosframework/platform/internal/genselect 0.017s
ok github.com/carlosframework/platform/internal/geo 0.017s
ok github.com/carlosframework/platform/internal/geoip 0.029s
ok github.com/carlosframework/platform/internal/historyreadback 0.161s
ok github.com/carlosframework/platform/internal/host 144.050s
ok github.com/carlosframework/platform/internal/hostactors 6.176s
ok github.com/carlosframework/platform/internal/hostactors/awsmembership 0.004s
ok github.com/carlosframework/platform/internal/hostbox 2.957s
ok github.com/carlosframework/platform/internal/hostclaim 0.720s
ok github.com/carlosframework/platform/internal/hostenv 0.007s
ok github.com/carlosframework/platform/internal/hostevidence 0.006s
ok github.com/carlosframework/platform/internal/hostexec 5.334s
ok github.com/carlosframework/platform/internal/hostfence 0.085s
ok github.com/carlosframework/platform/internal/hostfiles 10.395s
ok github.com/carlosframework/platform/internal/hostfloor 0.029s
ok github.com/carlosframework/platform/internal/hostguard 1.083s
ok github.com/carlosframework/platform/internal/hostops 1.965s
? github.com/carlosframework/platform/internal/hostops/fencerelease [no test files]
ok github.com/carlosframework/platform/internal/hostops/internal/fencerelease 0.004s
ok github.com/carlosframework/platform/internal/hostquarantine 0.005s
ok github.com/carlosframework/platform/internal/hostrelocate 0.632s
ok github.com/carlosframework/platform/internal/hostresolve 0.193s
ok github.com/carlosframework/platform/internal/hostwrite 0.002s
ok github.com/carlosframework/platform/internal/infraview 0.006s
ok github.com/carlosframework/platform/internal/instancectl 5.236s
ok github.com/carlosframework/platform/internal/instanceexec 2.809s
ok github.com/carlosframework/platform/internal/instancefs 0.005s
ok github.com/carlosframework/platform/internal/instancekey 0.003s
ok github.com/carlosframework/platform/internal/instanceupdates 0.009s
ok github.com/carlosframework/platform/internal/layout 1.808s
ok github.com/carlosframework/platform/internal/lbhealth 0.005s
ok github.com/carlosframework/platform/internal/lease 10.169s
ok github.com/carlosframework/platform/internal/lease/leasetest 0.551s
ok github.com/carlosframework/platform/internal/ledger 0.020s
ok github.com/carlosframework/platform/internal/mail 0.262s
ok github.com/carlosframework/platform/internal/maintenance 0.101s
ok github.com/carlosframework/platform/internal/maintenanceexec 5.609s
ok github.com/carlosframework/platform/internal/maintenanceguard 0.098s
ok github.com/carlosframework/platform/internal/metrics 0.006s
ok github.com/carlosframework/platform/internal/moves 22.594s
ok github.com/carlosframework/platform/internal/moves/archive 1.045s
ok github.com/carlosframework/platform/internal/objstore 0.270s
ok github.com/carlosframework/platform/internal/ops 0.217s
ok github.com/carlosframework/platform/internal/park 0.303s
ok github.com/carlosframework/platform/internal/plans 0.009s
ok github.com/carlosframework/platform/internal/privatefile 0.008s
2026/10/24 21:29:41 provision: listing apps/bab/blog/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:41 provision: listing apps/bab/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: listing apps/bac/tito/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:41 provision: listing apps/bac/tito/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:41 provision: skipping record apps/bac/tito/instances/one.example.com.json: unreadable: read refused
2026/10/24 21:29:41 provision: listing apps/bac/tito/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:41 provision: an app's records could not be listed: they are skipped
2026/10/24 21:29:41 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:41 provision: remove retired instance route shop.example: provision: claim admission unavailable
2026/10/24 21:29:41 provision: remove retired instance route shop.example: provision: claim admission unavailable
2026/10/24 21:29:41 provision: remove retired sidecar route worker.sidecar.internal: provision: claim admission unavailable
2026/10/24 21:29:41 provision: remove retired sidecar route worker.sidecar.internal: provision: claim admission unavailable
2026/10/24 21:29:41 provision: claim install acme.go.tito.io: provision: claim admission unavailable
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/24 21:29:41 provision: claim install bot.eleven.bac.sidecar.internal: provision: claim admission unavailable
2026/10/24 21:29:41 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/24 21:29:41 provision: claim install bot.eleven.bac.sidecar.internal: registry: claim row ownership changed or unknown
2026/10/24 21:29:41 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/24 21:29:41 provision: acme.go.tito.io: not minting this pass: the box's layout intent could not be read: no sealed config
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 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/24 21:29:41 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/24 21:29:41 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/24 21:29:41 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/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 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/24 21:29:41 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/24 21:29:41 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/24 21:29:41 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:41 provision: claim install acme.go.tito.io: registry: claim row ownership changed or unknown
2026/10/24 21:29:41 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/24 21:29:42 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["run"])
2026/10/24 21:29:42 provision: claim install bot.eleven.bac.sidecar.internal: registry: claim row ownership changed or unknown
2026/10/24 21:29:42 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/24 21:29:42 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:42 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/24 21:29:42 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:42 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/new.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:42 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/new.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:42 provision: minted instance route rc.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rd.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route re.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rh.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route ri.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rj.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route ra.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rb.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rf.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rg.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rk.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rl.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rc.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rd.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route ra.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route rb.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/rb.go.tito.io.json: read failed: read refused
2026/10/24 21:29:42 provision: skipping record apps/bac/tito/instances/rb.go.tito.io.json: read failed: read refused
2026/10/24 21:29:42 provision: minted instance route re.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appa.example (app "appa" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appb.example (app "appb" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appc.example (app "appc" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appd.example (app "appd" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appe.example (app "appe" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appg.example (app "appg" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.apph.example (app "apph" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appj.example (app "appj" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appf.example (app "appf" acct "bac")
2026/10/24 21:29:42 provision: minted instance route x.appi.example (app "appi" acct "bac")
2026/10/24 21:29:42 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:42 provision: minted instance route r0021.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0038.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0051.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0056.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0057.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0088.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0059.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0108.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0005.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0037.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0049.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0050.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0071.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0101.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0102.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0040.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0114.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0068.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0112.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0001.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0073.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0090.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0103.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0002.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0042.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0096.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0125.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0009.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0061.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0091.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0100.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0035.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0036.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0077.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0032.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0043.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0084.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0086.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0127.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0006.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0072.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0122.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0010.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0064.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0069.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0087.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0111.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0119.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0126.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0024.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0053.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0054.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0063.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0013.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0079.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0097.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0107.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0008.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0074.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0095.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0003.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0004.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0039.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0048.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0094.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0115.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0116.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0023.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0031.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0047.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0098.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0000.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0018.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0034.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0046.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0060.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0076.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0011.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0025.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0029.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0099.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0117.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0129.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0007.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0026.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0044.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0092.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0105.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0120.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0070.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0078.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0080.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0083.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0106.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0033.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0113.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0028.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0067.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0082.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0089.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0124.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0016.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0022.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0052.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0065.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0075.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0118.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0121.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0017.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0019.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0012.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0027.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0045.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0058.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0085.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0104.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0066.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0093.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0110.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0014.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0015.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0030.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0041.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0062.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0123.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0128.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0020.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0055.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0081.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:42 provision: minted instance route r0109.go.tito.io (app "tito" acct "bac")
--- FAIL: TestPlan9B8RecordWriteCensus (0.74s)
plan9_b8_census_test.go:372: record-write census rejected 1 site(s); update the explicit inventory only after reviewing the source:
changed site internal/provision/reconcile.go:Reconcile: source differs from the reviewed digest
2026/10/24 21:29:43 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:43 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:43 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/24 21:29:43 provision: minted instance route shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:43 provision: minted instance route shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:43 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route whole.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route console.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route ha.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route svc.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route shared.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: converged acme.go.tito.io channel edge -> canary/rehearsal
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: empty channel
2026/10/24 21:29:44 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io environment "" -> "staging"
2026/10/24 21:29:44 provision: converged acme.go.tito.io environment "staging" -> ""
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io steering "" -> "latency"
2026/10/24 21:29:44 provision: converged acme.go.tito.io steering "latency" -> ""
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io hibernate false -> true
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io hibernate true -> false (replication "daily" cleared: only a hibernating route's rung is read)
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: converged acme.go.tito.io status-named false -> true
2026/10/24 21:29:44 provision: converged acme.go.tito.io status-named true -> false
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route ha.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 provision: minted service route whole.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route whole.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: skipping accounts/bac/account.json: malformed account manifest: invalid character 'o' in literal null (expecting 'u')
2026/10/24 21:29:44 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: manifest bac/tito: read failed: provision: manifest bac/tito: invalid character 'o' in literal null (expecting 'u')
2026/10/24 21:29:44 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/24 21:29:44 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/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 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/24 21:29:44 provision: not removing acme$evil.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:44 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/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 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/24 21:29:44 provision: not removing bad-service.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:44 provision: skipping record apps/bac/tito/instances/no-channel.go.tito.io.json: empty channel
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: skipping record apps/bac/tito/instances/no-channel.go.tito.io.json: empty channel
2026/10/24 21:29:44 provision: not removing no-channel.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: skipping record apps/bac/tito/instances/acme.go.tito.io.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:44 provision: not removing acme.go.tito.io: its record exists but could not be read cleanly this pass
2026/10/24 21:29:44 provision: removed retired instance route ghost.go.tito.io (record gone)
2026/10/24 21:29:44 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/24 21:29:44 provision: minted instance route dup.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:44 provision: removed retired instance route acme.go.tito.io (app in the trash)
2026/10/24 21:29:44 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:44 provision: removed retired static route site.go.tito.io (app in the trash)
2026/10/24 21:29:44 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/24 21:29:44 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:44 provision: removed retired instance route acme.go.tito.io (app in the trash)
2026/10/24 21:29:44 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:44 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/24 21:29:44 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:44 provision: converged acme.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:44 provision: converged acme.go.tito.io channel canary/rehearsal -> edge
2026/10/24 21:29:44 provision: converged acme.go.tito.io environment "staging" -> ""
2026/10/24 21:29:44 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 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/24 21:29:44 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:44 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/24 21:29:44 provision: dry-run: would mint instance route acme.go.tito.io (app "tito" acct "bac" channel "stable")
2026/10/24 21:29:44 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/24 21:29:44 provision: dry-run: would converge adopt.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: dry-run: would converge adopt.go.tito.io environment "" -> "staging"
2026/10/24 21:29:44 provision: dry-run: would converge owned.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: dry-run: would converge owned.go.tito.io environment "" -> "staging"
2026/10/24 21:29:44 provision: dry-run: would converge owned.go.tito.io hibernate false -> true
2026/10/24 21:29:44 provision: dry-run: would converge owned.go.tito.io seed
2026/10/24 21:29:44 provision: dry-run: would remove retired instance route gone.go.tito.io (record gone)
2026/10/24 21:29:44 provision: converged owned.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: converged owned.go.tito.io environment "" -> "staging"
2026/10/24 21:29:44 provision: converged owned.go.tito.io hibernate false -> true
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: adopted existing route adopt.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:44 provision: converged adopt.go.tito.io channel stable -> edge
2026/10/24 21:29:44 provision: converged adopt.go.tito.io environment "" -> "staging"
2026/10/24 21:29:44 provision: removed retired instance route gone.go.tito.io (record gone)
2026/10/24 21:29:44 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: adopted existing route story.carlosframework.com (app "story" acct "bad") — this record now owns its channel and environment
2026/10/24 21:29:44 provision: story.carlosframework.com exists but is not the route this record describes (kind "instance"/"static") — leaving it alone
2026/10/24 21:29:44 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route pubs.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route pub.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route loop.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route named.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted service route priv.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route unit.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted instance route exec.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted static route pisite.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: minted static route site.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:44 provision: removed retired static route site.go.tito.io (record gone)
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme-uk.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: converged acme.go.tito.io replicas "ie,uk" -> "uk"
2026/10/24 21:29:45 provision: converged acme.go.tito.io replicas "uk" -> ""
2026/10/24 21:29:45 provision: minted instance route acme-uk.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: converged acme-uk.go.tito.io replica mark true -> false
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 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/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route router.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:45 provision: acme.go.tito.io: not minting this pass: the box's layout intent could not be read: store down
2026/10/24 21:29:45 provision: router.go.tito.io: not minting this pass: the box's layout intent could not be read: store down
2026/10/24 21:29:45 provision: adopted existing route acme.go.tito.io (app "tito" acct "bac") — this record now owns its channel and environment
2026/10/24 21:29:45 provision: converged acme.go.tito.io channel stable -> edge
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
2026/10/24 21:29:45 provision: not removing acme.go.tito.io (record gone): participant of a running operation
2026/10/24 21:29:45 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/24 21:29:45 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
2026/10/24 21:29:45 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/24 21:29:45 provision: held acme.go.tito.io landing by mv_acme (was ready)
2026/10/24 21:29:45 provision: acme.go.tito.io: held restoring by rb_other, not by mv_acme; leaving it
2026/10/24 21:29:45 provision: acme.go.tito.io: the row is not this pass's (app "other" acct ""); not holding it for mv_acme
2026/10/24 21:29:45 provision: acme.go.tito.io exists but is not the route this record describes (app "other"/"tito") — leaving it alone
2026/10/24 21:29:45 provision: dry-run: would mint instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac" channel "stable")
2026/10/24 21:29:45 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/24 21:29:45 provision: held acme.go.tito.io landing by mv_acme (was ready)
2026/10/24 21:29:45 provision: minted instance route acme.example.com (app "shop" acct "bac")
2026/10/24 21:29:45 provision: minted instance route plain.example.com (app "shop" acct "bac")
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/garbled.shop.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/liar.shop.example.com.json: disagrees with its own path (host="other.shop.example.com" account="bac" app="shop")
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/garbled.shop.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/liar.shop.example.com.json: disagrees with its own path (host="other.shop.example.com" account="bac" app="shop")
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/garbled.shop.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/liar.shop.example.com.json: disagrees with its own path (host="other.shop.example.com" account="bac" app="shop")
2026/10/24 21:29:45 provision: skipping record apps/bac/shop/instances/garbled.shop.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:45 provision: listing apps/bac/shop/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:46 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:46 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:46 provision: removed retired instance route acme.go.tito.io (record gone)
2026/10/24 21:29:46 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:46 provision: bac/tito is in the trash — not minting instance routes for it
2026/10/24 21:29:46 provision: minted sidecar route bot.shop.bac.sidecar.internal (app "shop" acct "bac" args ["run"])
2026/10/24 21:29:46 provision: removed retired sidecar route bot.shop.bac.sidecar.internal (record gone)
2026/10/24 21:29:46 provision: minted sidecar route bot.shop.bum.sidecar.internal (app "shop" acct "bum" args ["run"])
2026/10/24 21:29:46 provision: minted sidecar route bot.shop.bum.sidecar.internal (app "shop" acct "bum" args ["run"])
2026/10/24 21:29:46 provision: sidecar bot.shop.bum.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/24 21:29:46 provision: sidecar bot.shop.bum.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/24 21:29:46 provision: sidecar bot.shop.bum.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/24 21:29:46 provision: removed retired sidecar route bot.shop.bum.sidecar.internal (record gone)
2026/10/24 21:29:46 provision: sidecar bot.shop.bum.sidecar.internal is not placeable here: it asks for "no-inbound" placement and this box accepts inbound work (CARLOS_INBOUND="")
2026/10/24 21:29:46 provision: removed retired sidecar route bot.shop.bum.sidecar.internal (record gone)
2026/10/24 21:29:46 provision: a.shop.example.com: swapped for import sd_maw3c5pwmzkdo2jwsltdnnghsi (the original route is journaled)
2026/10/24 21:29:46 provision: a.shop.example.com: import sd_maw3c5pwmzkdo2jwsltdnnghsi committed: its gate is cleared and its journal row dropped
2026/10/24 21:29:46 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_ni3zw6m6xqkm6trhc26carsed4 rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_ni3zw6m6xqkm6trhc26carsed4: the host's replica is left alone: the record apps/bac/shop/instances/a.shop.example.com.json holds the host
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_ni3zw6m6xqkm6trhc26carsed4 is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2ay5krl4wmqbv7j2ao2kqntv2a rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2ay5krl4wmqbv7j2ao2kqntv2a: the host's replica is left alone: the record apps/bac/shop/instances/a.shop.example.com.json holds the host
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2ay5krl4wmqbv7j2ao2kqntv2a is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: dry-run: would redo a.shop.example.com's swap record CAS for import sd_qq4fzpwitv34sibx6srenuioli
2026/10/24 21:29:47 provision: dry-run: would clear a.shop.example.com's import gate
2026/10/24 21:29:47 provision: dry-run: would converge a.shop.example.com seed source
2026/10/24 21:29:47 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:47 provision: a.shop.example.com: the import's record apps/bac/shop/instances/a.shop.example.com.json is not one this pass can use (connection reset)
2026/10/24 21:29:47 provision: a.shop.example.com: the import's record apps/bac/shop/instances/a.shop.example.com.json is not one this pass can use (provision: invalid maintenance projection or protected fields)
2026/10/24 21:29:47 provision: a.shop.example.com: the import's record apps/bac/shop/instances/a.shop.example.com.json is not one this pass can use (the record under apps/bac/shop/instances/a.shop.example.com.json is apps/bac/shop/instances/b.shop.example.com.json's)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_q7toqatlhplvmhkzxjsr4ypr2i cannot roll back on this box: the activator is not wired; it stays journaled and gated
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_lltogrqy4bt6mjxxi4woexkij4 cannot roll back on this box: the activator is not wired; it stays journaled and gated
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_zkyujh45lu74sfejyx26kgpoqe is journaled, but this box cannot act on imports; its row is left alone
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_nk5uqujn5ytyiue7soqkodb2qe is journaled, but this box cannot act on imports; its row is left alone
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_4iqwa7uxhvniz7i77nsyre6iuy is journaled, but this box cannot act on imports; its row is left alone
2026/10/24 21:29:47 provision: the import journal could not be read: registry: import journal a.shop.example.com: original row: unexpected end of JSON input (no import is acted on and no route is removed this pass)
2026/10/24 21:29:47 provision: b.shop.example.com: import sd_6vs6bjfgvmg2s2rpyl3g3da53q left alone this pass: the import journal could not be read
2026/10/24 21:29:47 provision: c.shop.example.com: import sd_vksl6gkdwxxgtzizu2san6qoeq left alone this pass: the import journal could not be read
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_4rrkn5rxhiyrljjz7p25mtxxqm committed: its gate is cleared and its journal row dropped
2026/10/24 21:29:47 provision: a.shop.example.com: not converging import sd_omvte2gnqfkmuxkqm4t34duh5e: it is swapped but not committed, and the row on this box has no import gate
2026/10/24 21:29:47 provision: a.shop.example.com: not converging import sd_53hdvgyddwmpewxyfcsx5yy2ku: it is swapped but not committed, and the row on this box has no import gate
2026/10/24 21:29:47 provision: a.shop.example.com: not converging import sd_mxhau4rvgedivayheunajms3ea: it is placed but not committed, and the row on this box has no import gate
2026/10/24 21:29:47 provision: a.shop.example.com: not converging import sd_vjgfcwgso77zxo2uq4rfmaid5i: it is placed but not committed, and the row on this box has no import gate
2026/10/24 21:29:47 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:47 provision: converge seed source on a.shop.example.com: constraint failed: seed_source is read-only here (1811)
2026/10/24 21:29:47 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_m6doowo7yj2vqzisxbwpw2inaa committed: its gate is cleared and its journal row dropped
2026/10/24 21:29:47 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:47 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:47 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/24 21:29:47 provision: acme.go.tito.io: not minting a seeded instance: this box does not mint nested (<nil>)
2026/10/24 21:29:47 provision: acme.go.tito.io: not minting a seeded instance: claim control is on for this box
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_hcs4aytdunyztcsna2c72qadou: this box cannot read seed markers, and places no seed; nothing local is removed
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_hcs4aytdunyztcsna2c72qadou rolled back (no box had swapped it)
2026/10/24 21:29:47 provision: acme.go.tito.io: not minting a seeded instance: its record does not describe a hibernating instance
2026/10/24 21:29:47 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:47 provision: removed instance route acme.go.tito.io (its seed sd_d66pjzwypvynonqzwiwi5panme was aborted); the next pass rolls it back
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_d66pjzwypvynonqzwiwi5panme: this box cannot read seed markers, and places no seed; nothing local is removed
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_d66pjzwypvynonqzwiwi5panme rolled back (no box had swapped it)
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_2xabqzzdmlv3o4eqjconlqwmam has a row this pass may not remove; leaving the seed aborted
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_f3aqictoc7s3elgsnr24rvm5bu rolled back (no box had swapped it)
2026/10/24 21:29:47 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:47 provision: removed instance route acme.go.tito.io (its seed sd_xckdj75jltimhnl4bscpk6sxdy was aborted); the next pass rolls it back
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_xckdj75jltimhnl4bscpk6sxdy has no route on this box: its local data is removed
2026/10/24 21:29:47 provision: acme.go.tito.io: aborted seed sd_xckdj75jltimhnl4bscpk6sxdy rolled back (no box had swapped it)
2026/10/24 21:29:47 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_d4v5ycd742uqgm4nqoonnuiaom (the original route is journaled)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_d4v5ycd742uqgm4nqoonnuiaom rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_d4v5ycd742uqgm4nqoonnuiaom is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_z36k7bzkxdg4eyphipg4ohekzu (the original route is journaled)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_z36k7bzkxdg4eyphipg4ohekzu rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_z36k7bzkxdg4eyphipg4ohekzu is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_utrtaqkitoi5i3sduoljtc5dwy (the original route is journaled)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_utrtaqkitoi5i3sduoljtc5dwy rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_utrtaqkitoi5i3sduoljtc5dwy: the host's replica is left alone: its record no longer names this seed
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_utrtaqkitoi5i3sduoljtc5dwy is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_2dkm535ttwkocmolofhgvywvfu (the original route is journaled)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2dkm535ttwkocmolofhgvywvfu rollback deferred: the host is not fenced and stopped yet (<nil>)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2dkm535ttwkocmolofhgvywvfu rolled back to its original route
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_2dkm535ttwkocmolofhgvywvfu is cleaned up and its journal row retired
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_6kwjho6v3bl67qgezfyc7ylxb4 (the original route is journaled)
2026/10/24 21:29:47 provision: a.shop.example.com: import sd_6kwjho6v3bl67qgezfyc7ylxb4 rollback deferred: the host is not fenced and stopped yet (stop unproven)
2026/10/24 21:29:47 provision: a.shop.example.com: swapped for import sd_wspkpd652ls3izqybqzvsu3o2e (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_wspkpd652ls3izqybqzvsu3o2e is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_foospydv34jwqujos5k5g7gqv4 (the original route is journaled)
2026/10/24 21:29:48 provision: skipping record apps/bac/shop/instances/a.shop.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_foospydv34jwqujos5k5g7gqv4 left alone this pass: its record could not be read
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_63tq4tvug4mkmwpam74n4647di (the original route is journaled)
2026/10/24 21:29:48 provision: skipping record apps/bac/shop/instances/a.shop.example.com.json: read failed: connection reset
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_63tq4tvug4mkmwpam74n4647di left alone this pass: its record could not be read
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_lpbw7i2fhoyr2ahv5ahxdvjhby (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_lpbw7i2fhoyr2ahv5ahxdvjhby: close the import gate: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_lpbw7i2fhoyr2ahv5ahxdvjhby rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_lpbw7i2fhoyr2ahv5ahxdvjhby is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_hkyolyijvrpgcddb6bgvqdpesi (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_hkyolyijvrpgcddb6bgvqdpesi: close the import gate: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_hkyolyijvrpgcddb6bgvqdpesi rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_hkyolyijvrpgcddb6bgvqdpesi is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_cwqjnyr4hofdxt6mzublti6s5i (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_cwqjnyr4hofdxt6mzublti6s5i rollback deferred: the host is not fenced and stopped yet (injected failure at fence)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_cwqjnyr4hofdxt6mzublti6s5i rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_cwqjnyr4hofdxt6mzublti6s5i is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_2626edobkr2j43ah3qo6udjizq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_2626edobkr2j43ah3qo6udjizq rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_2626edobkr2j43ah3qo6udjizq is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_65aamjx7v6heuf54nqeym5ovfi (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_65aamjx7v6heuf54nqeym5ovfi: retire its instance key: injected failure at retire-key
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_65aamjx7v6heuf54nqeym5ovfi rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_65aamjx7v6heuf54nqeym5ovfi is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_fowckejvyhxbnmprv5ownuvhqa (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_fowckejvyhxbnmprv5ownuvhqa rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_fowckejvyhxbnmprv5ownuvhqa is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_g3pkphimhzoo4ljquibxpujdpu (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_g3pkphimhzoo4ljquibxpujdpu: remove its local data: injected failure at remove-local
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_g3pkphimhzoo4ljquibxpujdpu rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_g3pkphimhzoo4ljquibxpujdpu is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_ezeedvi5otnyyilh46qscddv4y (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_ezeedvi5otnyyilh46qscddv4y rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_ezeedvi5otnyyilh46qscddv4y is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_4dzpkljxlvckd3zt3zvrmbisky (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_4dzpkljxlvckd3zt3zvrmbisky: remove its local data: injected failure at remove-local-done
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_4dzpkljxlvckd3zt3zvrmbisky rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_4dzpkljxlvckd3zt3zvrmbisky is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_kkzdzzcwmlstyo56lmtf7zikp4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_kkzdzzcwmlstyo56lmtf7zikp4 rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_kkzdzzcwmlstyo56lmtf7zikp4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_n53zcf7ktaahwi2r5r6pk6wpvy (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n53zcf7ktaahwi2r5r6pk6wpvy: restore the original route: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n53zcf7ktaahwi2r5r6pk6wpvy rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n53zcf7ktaahwi2r5r6pk6wpvy is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_jczncrfxjw3vgodzi44kfotusa (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_jczncrfxjw3vgodzi44kfotusa: restore the original route: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_jczncrfxjw3vgodzi44kfotusa rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_jczncrfxjw3vgodzi44kfotusa is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_ia54uo5cix7tbrthj3cjcthxp4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_ia54uo5cix7tbrthj3cjcthxp4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_vbkethryvyhq57uimpu5ksppwm (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vbkethryvyhq57uimpu5ksppwm rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vbkethryvyhq57uimpu5ksppwm: delete its snapshot: injected failure at delete-snapshot
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vbkethryvyhq57uimpu5ksppwm is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_gms5dfw4vflysnrnleovfe4dk4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_gms5dfw4vflysnrnleovfe4dk4 rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_gms5dfw4vflysnrnleovfe4dk4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_bd6ryiws6svsujmxzc3k2ushju (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_bd6ryiws6svsujmxzc3k2ushju rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_bd6ryiws6svsujmxzc3k2ushju: delete the host's replica: injected failure at delete-replica
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_bd6ryiws6svsujmxzc3k2ushju is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_nfwu7unrxoekfywck4442grbci (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_nfwu7unrxoekfywck4442grbci rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_nfwu7unrxoekfywck4442grbci is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_kkkiy7jgfpxc6an2ckymk4agae (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_kkkiy7jgfpxc6an2ckymk4agae rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_kkkiy7jgfpxc6an2ckymk4agae: retire its journal row: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_kkkiy7jgfpxc6an2ckymk4agae is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_vdg2z63nmoel5com5fwygj72zm (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vdg2z63nmoel5com5fwygj72zm rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vdg2z63nmoel5com5fwygj72zm: retire its journal row: constraint failed: injected (1811)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_vdg2z63nmoel5com5fwygj72zm is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_n7ko4tmhpjsygzysktx74nqnsu (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n7ko4tmhpjsygzysktx74nqnsu rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n7ko4tmhpjsygzysktx74nqnsu is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: mark import sd_n7ko4tmhpjsygzysktx74nqnsu rolled back: injected failure at cas
2026/10/24 21:29:48 provision: a.shop.example.com: aborted seed sd_n7ko4tmhpjsygzysktx74nqnsu rolled back (no box had swapped it)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_xbom45dk2aajwyumubl4a2cijy (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_xbom45dk2aajwyumubl4a2cijy rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_xbom45dk2aajwyumubl4a2cijy is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: aborted seed sd_xbom45dk2aajwyumubl4a2cijy rolled back (no box had swapped it)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_syrzckys7cmyda5scjw5xfebxq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_syrzckys7cmyda5scjw5xfebxq rollback deferred: the host is not fenced and stopped yet (<nil>)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_syrzckys7cmyda5scjw5xfebxq rollback deferred: the host is not fenced and stopped yet (<nil>)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_syrzckys7cmyda5scjw5xfebxq rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_syrzckys7cmyda5scjw5xfebxq is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_gtxryybci32ota6lwwkd4uoja4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_gtxryybci32ota6lwwkd4uoja4 rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_gtxryybci32ota6lwwkd4uoja4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_4twh6hq35yubzu2negshoacin4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_4twh6hq35yubzu2negshoacin4 rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_4twh6hq35yubzu2negshoacin4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_hzqmamgdjkfnralz5k2j4tlgbm (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_hzqmamgdjkfnralz5k2j4tlgbm rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_hzqmamgdjkfnralz5k2j4tlgbm is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_bvlyaqnsbkwj3nhvozadoyfyse (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_bvlyaqnsbkwj3nhvozadoyfyse rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_bvlyaqnsbkwj3nhvozadoyfyse is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_m3v4yo25xgqf6npdw6fraaf2f4 (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_m3v4yo25xgqf6npdw6fraaf2f4 rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_m3v4yo25xgqf6npdw6fraaf2f4 is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "other" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_n3yeydicda6l6csy7dii7aogbq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n3yeydicda6l6csy7dii7aogbq rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_n3yeydicda6l6csy7dii7aogbq is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "other" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_s6rk6i2uw232vz267nc2y56vfi (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_s6rk6i2uw232vz267nc2y56vfi rolled back to its original route
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_s6rk6i2uw232vz267nc2y56vfi is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "other" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_dxlwc6sgwmmmgpxqcxnzphmvua (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_dxlwc6sgwmmmgpxqcxnzphmvua has no route on this box: its local data is removed and no route is put back
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_dxlwc6sgwmmmgpxqcxnzphmvua is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_d4vw5m4iqmfbsdbpvr44z6p7ce (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_z4brqintkv6p6rakx5l7ucz4fq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_mj2p3ozzmmiuod6edzgsxr5ehu (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_mj2p3ozzmmiuod6edzgsxr5ehu cannot roll back on this box: the activator is not wired; it stays journaled and gated
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_jf4enzkdxyutjoe3txupyg4leq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_jf4enzkdxyutjoe3txupyg4leq is not rolled back: the route changed under the fence, so nothing there is touched
2026/10/24 21:29:48 provision: a.shop.example.com: import "../not-a-seed" names no snapshot and no replica; only its journal row is cleaned up
2026/10/24 21:29:48 provision: a.shop.example.com: import ../not-a-seed is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_fzk7m27x6z253vwe3rss3wz5lu (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_3mkpe5o7clzh6p4d62i2bz6v3y (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_plfq4krs2vawfyulphgidld7we (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_wkcjqn3pps4vz7nwo4cmn2imby (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_3sylpgrqxk2ho7rdzmfnfq2r6q (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_3sylpgrqxk2ho7rdzmfnfq2r6q rollback deferred: the host is not fenced and stopped yet (stop evidence unreadable)
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_xymcgw667ar6tnihjxk44zfqdq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_xymcgw667ar6tnihjxk44zfqdq has no route on this box: its local data is removed and no route is put back
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_xymcgw667ar6tnihjxk44zfqdq is cleaned up and its journal row retired
2026/10/24 21:29:48 provision: minted instance route a.shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_7tmndrqy55sob2wwue3u35leaq (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_7tmndrqy55sob2wwue3u35leaq: remove its local data: injected failure at remove-local
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_7tmndrqy55sob2wwue3u35leaq is not rolled back: the route at the host is not the import's, so nothing there is touched
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_5z4lb2zempkl6ignpjc4irv2ri (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_5z4lb2zempkl6ignpjc4irv2ri: a route appeared at the host, so its local database is left and the rollback waits
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_ihueak75k3axirvofqpvlgfnvm (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_ihueak75k3axirvofqpvlgfnvm rollback deferred: no fence generation: registry busy
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_fizjyn6i36tawj7fhx4d33pktm (the original route is journaled)
2026/10/24 21:29:48 provision: a.shop.example.com: import sd_fizjyn6i36tawj7fhx4d33pktm rollback deferred: no fence generation: the generation source answered 0
2026/10/24 21:29:48 provision: a.shop.example.com: swapped for import sd_mcdtw3d54ypz2gfi4nlevzeksq (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_pbfiz3itdeqkd4g4h4hq2brjaa (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_6nn74ksexypmiqdqeua2hvpnra (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: this box cannot read the instance's env file
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: the instance's env file could not be read: a symlink
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_5sfdq2mjkfyixuyoimjyhp6xu4 (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_5sfdq2mjkfyixuyoimjyhp6xu4 rolled back to its original route
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_5sfdq2mjkfyixuyoimjyhp6xu4 is cleaned up and its journal row retired
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_6unffwq5ggssmrx5xmkzwlhikm (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_6unffwq5ggssmrx5xmkzwlhikm rolled back to its original route
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_6unffwq5ggssmrx5xmkzwlhikm is cleaned up and its journal row retired
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_scn6vbzvjhv6uy4entyvagqnau (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_scn6vbzvjhv6uy4entyvagqnau rolled back to its original route
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_scn6vbzvjhv6uy4entyvagqnau is cleaned up and its journal row retired
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_pkzogwhwbkxymqendghq4yiahu (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_pkzogwhwbkxymqendghq4yiahu: retire its instance key: the env file is a symlink
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_pkzogwhwbkxymqendghq4yiahu rolled back to its original route
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_pkzogwhwbkxymqendghq4yiahu is cleaned up and its journal row retired
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_u2v3ofbusw5fmdz2sixizvcuxm (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: row is on the nested layout (db "/data/instances/a.shop.example.com/a.shop.example.com.db" socket "/run/carlos/instances/a.shop.example.com/app.sock"); the record's shared paths are not drift
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_dorrt75yyyy3zxfvx4rcd5fmym (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_t3rvhbnxbb3uzdzxukigas2sjy refused: there is no route at a.shop.example.com to replace
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_apxnhzhjviogj2pm46uuazhbgm refused: the route's address is 127.0.0.1:9, not 127.0.0.1:8401
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_67ckxw76huwptx5pcvahle7bki refused: the route's address is 127.0.0.1:8401,127.0.0.1:8402, not 127.0.0.1:8401
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_f4lruyu7otckzn3jl6dnyzp6um refused: the route's address is 127.0.0.1:9, not 127.0.0.1:8401
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_algkxa43l2srbiz5zd2ojqvfma refused: the route belongs to app other
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_nznvwfo3t47yb6thw3ckxk2hzq refused: the route is filed under another account
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_jfxx5nu2ko4vv6lqfvwz5p2k6i refused: the route is filed under the operator account, and no assignment maps shop to this app
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_aiif4bj6lbvdknueluptsjeoa4 refused: the route is filed under the operator account, and no assignment maps shop to this app
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_lluuqfaezsu453xtdjxhbimweq refused: the route is filed under the operator account, and no assignment maps shop to this app
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_i5kw5mntageaj36zbty7czwhuq refused: the route is filed under the operator account, and no assignment maps shop to this app
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_rsmotkgcmrsd3qqxlcyuyyjc5q refused: the route is not an address route this import can take over (socket)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_p4uvvc3v5psvfpwsarw75x4izq refused: the route is not an address route this import can take over (no address)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_3xrez45ra4fskgru55zwzm6fei refused: the route is not an address route this import can take over (provisioned)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_uom5xdgq6tmjhpu2qjd4xkhodm refused: the route is not an address route this import can take over (kind static)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_qgneo4prmt7ljdvix5zrgkjcji refused: the route is not an address route this import can take over (backing)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_zjx4sdwv53tpwvawb4wssbjqtm refused: the route is not an address route this import can take over (tunnel)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_57zfdc2b5jqto5n5pz3dlwgxde refused: the route is not an address route this import can take over (caps)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_rnaeoodjy4ql6a2zet6s5tfu5q refused: the route is not an address route this import can take over (platform)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_lh3gaupcf2wdp4ckk2li5vlqnm refused: the route is not an address route this import can take over (canary)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_6a4eksknppamhge5bod6qp5q64 refused: the route is not an address route this import can take over (kind sidecar)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_nrgibfhtsj255zgmzi2egwa5ay refused: the route is not an address route this import can take over (region)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_rtfyemd53y4jr6shwxnmxoisu4 refused: the route is not an address route this import can take over (fleet_box)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_i6pok5rveagngnfosdkgc55hxi refused: the route is not an address route this import can take over (hibernate)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_xp3veypm5gxawq3dwx2agtzcei refused: the route is not an address route this import can take over (claim_owner)
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_3v7fqxu6nq2mie5xbtpnslvhpi refused: this box does not run instances nested
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_vldlg3blvdbpk3eoi5ztadgjvi refused: this box does not run instances nested
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_ufp4cxzai7mgxnojweuj4tc5oq refused: claim control is on for this box
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_ul3ur46f4u7xff5ds6hbl2irui (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_rxvtm2fxgpjxxmnrpswb3ltb64 (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: the legacy route assignments could not be read: store down
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: this box cannot read the legacy route assignments
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_px4u7l3qrl2mob6efcctrxotpa: its verify hash is not a sha256
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_silvqwwmz6vpjsjwzu5ss3judi: its verify hash is not a sha256
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_olbhholqrnyyrr6wrkeevhogxa: its verify hash is not a sha256
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_../../x: its host or seed id is malformed (seeds: not a seed id)
2026/10/24 21:29:49 provision: A.shop.example.com/..: not swapping for import sd_mbklv5twua2mmlswoancqw62e4: its host or seed id is malformed (seeds: not a host)
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_x4res2erbsyvpcnlvrxx2u5smm: its record does not describe a nested, hibernating instance
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_aayhflbyoqewoqi5dlbg6pye7u: its record does not describe a nested, hibernating instance
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_g45aqksl6uge2ov7r664223cg4: its record does not describe a nested, hibernating instance
2026/10/24 21:29:49 provision: a.shop.example.com: not swapping for import sd_np3lrizognmqu2fgdtduf324xe: its record does not describe a nested, hibernating instance
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: the box's layout intent could not be read: store down
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_fdqjojetotpczdxqn6yuu4awrq (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: the box's nested probe did not answer: ready probe timed out
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_hkwtvju45ndxewrspot7kznodi (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_2r7f73frzwkxu4tu4mloj74woe (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: import deferred: the route is held by operation op_1
2026/10/24 21:29:49 provision: dry-run: would consider swapping a.shop.example.com for import sd_lfbe6s5mxrnace66qakuakjxxm
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_c2ix32wso4sp4u55y7gt66zuhy rolled back to its original route
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_c2ix32wso4sp4u55y7gt66zuhy: the host's replica is left alone: the record apps/bac/shop/instances/a.shop.example.com.json holds the host
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_c2ix32wso4sp4u55y7gt66zuhy is cleaned up and its journal row retired
2026/10/24 21:29:49 provision: a.shop.example.com: import sd_qaf636s6o6eucmrhszs6syltte left alone: the import journal holds seed sd_xkailm3yfqk4azu5ukhaqbe45y at swapped
2026/10/24 21:29:49 provision: a.shop.example.com: not minting import sd_shvdwyywbc3qrbkmwuwte2gscq: it is swapped but not committed, and only its swap makes its row
2026/10/24 21:29:49 provision: a.shop.example.com: not minting import sd_drr7pdvggakxixtjkfz7qa6d5e: it is placed but not committed, and only its swap makes its row
2026/10/24 21:29:49 provision: a.shop.example.com: swapped for import sd_i7skhpdn7r7jnfduujrptrnefa (the original route is journaled)
2026/10/24 21:29:49 provision: a.shop.example.com: not minting import sd_i7skhpdn7r7jnfduujrptrnefa: it is swapped but not committed, and only its swap makes its row
2026/10/24 21:29:49 provision: a.shop.example.com: not minting import sd_i7skhpdn7r7jnfduujrptrnefa: it is placed but not committed, and only its swap makes its row
2026/10/24 21:29:49 provision: minted instance route a.shop.example.com (app "shop" acct "bac")
2026/10/24 21:29:50 provision: removed retired sidecar route gone.eleven.bac.sidecar.internal (record gone)
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: converged sidecar bot.eleven.bac.sidecar.internal args ["sidecar","run"] -> ["worker","run"]
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: converged sidecar bot.eleven.bac.sidecar.internal ceilings 300/3600 -> 60/120
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: converged sidecar bot.eleven.bac.sidecar.internal channel stable -> canary/eleven
2026/10/24 21:29:50 provision: converged sidecar bot.eleven.bac.sidecar.internal environment "other" -> "relay"
2026/10/24 21:29:50 provision: converged sidecar bot.eleven.bac.sidecar.internal hibernate true -> false
2026/10/24 21:29:50 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: read failed: failStore: reads disabled under apps/bac/eleven/sidecars/
2026/10/24 21:29:50 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: malformed: invalid character 'n' looking for beginning of object key string
2026/10/24 21:29:50 provision: not removing sidecar bot.eleven.bac.sidecar.internal: its record exists but could not be read cleanly this pass
2026/10/24 21:29:50 provision: skipping sidecar record apps/bac/eleven/sidecars/bot.json: empty channel
2026/10/24 21:29:50 provision: skipping sidecar record apps/bac/eleven/sidecars/held.json: empty channel
2026/10/24 21:29:50 provision: not removing sidecar held.eleven.bac.sidecar.internal: its record exists but could not be read cleanly this pass
2026/10/24 21:29:50 provision: removed retired sidecar route old.eleven.bac.sidecar.internal (record gone)
2026/10/24 21:29:50 provision: bac/eleven has sidecar records but no sidecars manifest — not minting
2026/10/24 21:29:50 provision: bac/eleven is in the trash — not minting sidecar routes for it
2026/10/24 21:29:50 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/24 21:29:50 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/24 21:29:50 provision: minted sidecar route hub.relay.bac.sidecar.internal (app "relay" acct "bac" args ["relay"])
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 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/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 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/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 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/24 21:29:50 provision: removed retired sidecar route bot.eleven.bac.sidecar.internal (record gone)
2026/10/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 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/24 21:29:50 provision: skipping sidecar record apps/bac/relay/sidecars/hub.json: read failed: failStore: reads disabled under apps/bac/relay/sidecars/
2026/10/24 21:29:50 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/24 21:29:50 provision: minted sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" args ["sidecar","run"])
2026/10/24 21:29:50 provision: dry-run: would mint sidecar route bot.eleven.bac.sidecar.internal (app "eleven" acct "bac" channel "stable" args ["sidecar","run"])
2026/10/24 21:29:50 provision: dry-run: would remove retired sidecar route gone.eleven.bac.sidecar.internal (record gone)
2026/10/24 21:29:50 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/24 21:29:50 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:50 provision: converged acme.go.tito.io update settings "{\"updates\":\"manual\",\"channel\":\"stable\"}" -> ""
2026/10/24 21:29:50 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:50 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:50 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/24 21:29:50 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/24 21:29:50 provision: acme.go.tito.io: not minted this pass: the app's update policy could not be read
2026/10/24 21:29:50 provision: minted instance route acme.go.tito.io (app "tito" acct "bac")
2026/10/24 21:29:50 provision: manifest bac/tito: read failed: provision: manifest bac/tito: unexpected end of JSON input
2026/10/24 21:29:50 provision: acme.go.tito.io: not minted this pass: the app's update policy could not be read
2026/10/24 21:29:50 provision: minted instance route acme.go.tito.io held landing by mv_acme (app "tito" acct "bac")
2026/10/24 21:29:50 provision: record view: change index unusable (release: change index unreadable: store has no conditional read: unsupported operation): the walk records no generations
2026/10/24 21:29:50 provision: listing apps/bqd/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:50 provision: listing apps/bqd/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:50 provision: listing apps/bqd/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:50 provision: listing apps/bqd/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: listing apps/bqd/: listdirs refused — its records are unseen this pass
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: record view: re-reading apps/bqc/shop failed: retrying on the next refresh
2026/10/24 21:29:50 provision: listing apps/bqc/shop/instances/: context canceled — its records are unseen this pass
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: record view: re-reading apps/bqc/shop failed: retrying on the next refresh
2026/10/24 21:29:50 provision: listing apps/bqc/shop/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:50 provision: listing apps/bqc/shop/instances/: list refused — its records are unseen this pass
2026/10/24 21:29:50 provision: an app's records could not be listed: they are skipped
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: record view: change index unusable (get refused): walking
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: record view: change index unusable (release: change index malformed: invalid character 'n' looking for beginning of object key string): walking
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping accounts/bqd/account.json: malformed account manifest: invalid character 'n' looking for beginning of object key string
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping accounts/bqd/account.json: malformed account manifest: invalid character 'n' looking for beginning of object key string
2026/10/24 21:29:50 provision: skipping accounts/bqd/account.json: malformed account manifest: invalid character 'n' looking for beginning of object key string
2026/10/24 21:29:50 provision: record view: re-reading accounts/bqd failed: retrying on the next refresh
2026/10/24 21:29:50 provision: skipping accounts/bqd/account.json: read failed: list refused
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: minted instance route one.example.com (app "shop" acct "bum")
2026/10/24 21:29:50 provision: minted instance route one.example.com (app "shop" acct "bum")
2026/10/24 21:29:50 provision: minted instance route one.example.com (app "shop" acct "bum")
2026/10/24 21:29:50 provision: removed retired instance route one.example.com (record gone)
2026/10/24 21:29:50 provision: removed retired instance route one.example.com (record gone)
2026/10/24 21:29:50 provision: skipping record apps/bum/shop/instances/one.example.com.json: empty channel
2026/10/24 21:29:50 provision: not removing one.example.com: its record exists but could not be read cleanly this pass
2026/10/24 21:29:50 provision: skipping record apps/bum/shop/instances/one.example.com.json: empty channel
2026/10/24 21:29:50 provision: not removing one.example.com: its record exists but could not be read cleanly this pass
2026/10/24 21:29:50 provision: record view: change index unusable (context deadline exceeded): walking
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
2026/10/24 21:29:50 provision: record view: change index unusable (context deadline exceeded): the walk records no generations
2026/10/24 21:29:50 provision: skipping record apps/bqe/store/instances/bad.store.example.com.json: malformed: provision: invalid maintenance projection or protected fields
--- FAIL: TestPlan14RootReadCensus (15.32s)
plan14_root_reads_test.go:600: root read census: 33 discrepancies
changed registry schema
changed root read internal/edge/edge.go:Edge.Reload; review class, task, sites and digest
changed root read internal/edge/edge.go:Edge.ServeHTTP; review class, task, sites and digest
changed root read internal/host/agent.go:runAgent; review class, task, sites and digest
changed root read internal/provision/reconcile.go:Reconcile; review class, task, sites and digest
changed root read internal/provision/reconcile.go:RouteFor; review class, task, sites and digest
changed root read internal/registry/registry.go:Registry.Fingerprint; review class, task, sites and digest
changed root read internal/registry/registry.go:Registry.Upsert; review class, task, sites and digest
changed root read internal/registry/registry.go:Registry.migrate; review class, task, sites and digest
changed root read internal/registry/registry.go:routeArgs; review class, task, sites and digest
changed root read internal/registry/registry.go:scanRoute; review class, task, sites and digest
changed root read internal/registry/remote_dispatch.go:Registry.dispatchRemote; review class, task, sites and digest
changed root source envelope internal/edge
changed root source envelope internal/host
changed root source envelope internal/plans
changed root source envelope internal/provision
changed root source envelope internal/ratelimit
changed root source envelope internal/registry
changed root source envelope internal/usage
unclassified root read internal/edge/ratelimit.go:Edge.noteRateLimited registry:Host@505,registry:Host@597,whole:Route@166
unclassified root read internal/edge/ratelimit.go:Edge.parseRateSettings registry:Host@271,registry:Host@367,registry:RateLimit@158,registry:RateLimit@77
unclassified root read internal/edge/ratelimit.go:Edge.rateAdmit registry:Host@806,registry:Kind@150,whole:Route@153,whole:Route@533,whole:Route@809,whole:Route@915
unclassified root read internal/edge/usagemeter.go:UsageMeter.RecordRateLimited registry:App@206,registry:Host@146,registry:Host@294,whole:Route@191
unclassified root read internal/host/plans_pass.go:planRateCeilingFor whole:Route@108
unclassified root read internal/registry/registry.go:Registry.SetRateLimit file:Exec@225,registry:remote@68,registry:remote@98,registry:sql@225,whole:remoteClient@100,whole:remoteClient@70
changed legacy declaration internal/edge/edge.go:Edge.Reload
changed legacy declaration internal/edge/edge.go:Edge.ServeHTTP
changed legacy declaration internal/provision/reconcile.go:Reconcile
changed legacy declaration internal/registry/registry.go:Registry.Fingerprint
changed legacy declaration internal/registry/registry.go:Registry.migrate
changed legacy declaration internal/registry/registry.go:scanRoute
changed reclassified declaration internal/registry/registry.go:Registry.Upsert
changed reclassified declaration internal/registry/remote_dispatch.go:Registry.dispatchRemote
make census-card shows what changed; make census-propose NAME=<branch> CLAIMS=<file> writes the overlay and its approval card (AGENTS.md, The census)
FAIL
FAIL github.com/carlosframework/platform/internal/provision 24.236s
ok github.com/carlosframework/platform/internal/publicrelease 0.012s
ok github.com/carlosframework/platform/internal/ratelimit 0.124s
? github.com/carlosframework/platform/internal/regionname [no test files]
ok github.com/carlosframework/platform/internal/registry 5.760s
ok github.com/carlosframework/platform/internal/relay 7.241s
ok github.com/carlosframework/platform/internal/release 25.918s
ok github.com/carlosframework/platform/internal/rollout 3.822s
ok github.com/carlosframework/platform/internal/rolloutwords 0.004s
ok github.com/carlosframework/platform/internal/rootaws 0.011s
ok github.com/carlosframework/platform/internal/rootparticipation 0.062s
ok github.com/carlosframework/platform/internal/rootstate 0.027s
ok github.com/carlosframework/platform/internal/runs 0.624s
ok github.com/carlosframework/platform/internal/s3compat 0.013s
ok github.com/carlosframework/platform/internal/safefile 0.004s
ok github.com/carlosframework/platform/internal/schedule 2.657s
ok github.com/carlosframework/platform/internal/seeds 0.014s
ok github.com/carlosframework/platform/internal/sim/engines 2.597s
ok github.com/carlosframework/platform/internal/sim/hostlife 10.850s
ok github.com/carlosframework/platform/internal/sim/litestreamfacts 3.605s
ok github.com/carlosframework/platform/internal/status 0.067s
ok github.com/carlosframework/platform/internal/steering 0.006s
ok github.com/carlosframework/platform/internal/stopevidence 0.303s
ok github.com/carlosframework/platform/internal/svcrole 0.003s
ok github.com/carlosframework/platform/internal/telemetry 0.004s
ok github.com/carlosframework/platform/internal/termfence 0.004s
ok github.com/carlosframework/platform/internal/tunnelclient 0.006s
ok github.com/carlosframework/platform/internal/unixdial 0.005s
ok github.com/carlosframework/platform/internal/updatewords 0.005s
ok github.com/carlosframework/platform/internal/usage 0.010s
ok github.com/carlosframework/platform/internal/version 0.002s
ok github.com/carlosframework/platform/internal/vet 1.680s
FAIL
=== internal_console@0 (87 s)
ok github.com/carlosframework/platform/internal/console 85.192s
=== internal_console@1 (44 s)
ok github.com/carlosframework/platform/internal/console 42.247s
=== internal_console@2 (42 s)
ok github.com/carlosframework/platform/internal/console 40.190s
=== internal_console@3 (42 s)
ok github.com/carlosframework/platform/internal/console 40.695s
=== internal_console@4 (43 s)
ok github.com/carlosframework/platform/internal/console 41.487s
=== internal_console@5 (41 s)
ok github.com/carlosframework/platform/internal/console 40.039s
=== internal_console@6 (38 s)
ok github.com/carlosframework/platform/internal/console 36.941s
=== internal_console@7 (47 s)
ok github.com/carlosframework/platform/internal/console 45.408s
=== root@0 (110 s)
ok github.com/carlosframework/platform 108.523s
=== root@1 (84 s)
ok github.com/carlosframework/platform 82.925s
=== root@2 (92 s)
ok github.com/carlosframework/platform 90.467s
FAILED: rest
make: *** [Makefile:19: 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/edge/edge.go b/internal/edge/edge.go| index a23121947..1fee007b2 100644 |
| --- a/internal/edge/edge.go |
| +++ b/internal/edge/edge.go |
| @@ -58,6 +58,7 @@ import ( |
| "github.com/carlosframework/platform/internal/geoip" |
| "github.com/carlosframework/platform/internal/lbhealth" |
| "github.com/carlosframework/platform/internal/provision" |
| + "github.com/carlosframework/platform/internal/ratelimit" |
| "github.com/carlosframework/platform/internal/registry" |
| "github.com/carlosframework/platform/internal/release" |
| ) |
| @@ -299,6 +300,15 @@ type Edge struct { |
| // routes get unixProxy(t.Socket) and the row's version, as before. |
| gens GenSource |
| genPools *GenPools |
| + // The per-instance rate limit (ratelimit.go, #358). rateMode is |
| + // CARLOS_RATE_LIMIT, read once in New. rateLimiter holds every |
| + // instance's buckets and in-flight slots, keyed by route host, in memory |
| + // only: a restart refills them, which both do within seconds anyway. |
| + // rateCeiling is the plan ceiling hook (SetRateCeilingFor), atomic |
| + // because the agent arms it after construction; nil is no ceiling. |
| + rateMode RateMode |
| + rateLimiter *ratelimit.Limiter |
| + rateCeiling atomic.Pointer[func(registry.Route) ratelimit.Ceiling] |
| } |
| // RunOption configures the Edge that Run/RunWithActivator* builds, before it |
| @@ -389,13 +399,17 @@ type upstream struct { |
| // appSocketProxy (generations on). Its cacheable responses are stored |
| // only when tagged with the generation that served them (cache.go). |
| genManaged bool |
| + // rate is the instance owner's rate-limit settings from the row's |
| + // rate_limit column, parsed once per reload (parseRateSettings). An alias |
| + // copies it with the rest of the primary's entry. |
| + rate ratelimit.Settings |
| } |
| // New builds an Edge over reg and performs the startup reload. act may be nil |
| // (no hibernation). |
| func New(reg *registry.Registry, act Activator) (*Edge, error) { |
| e := &Edge{reg: reg, act: act, gate: gate.New(), probers: newProberSet(), gzipOn: gzipEnabled(), steeringHost: steeringProbeHostFromEnv(), appsDomain: appsDomainFromEnv(), |
| - lbHealth: lbHealthFromEnv(os.Getenv, act)} |
| + lbHealth: lbHealthFromEnv(os.Getenv, act), rateMode: rateModeFromEnv(), rateLimiter: ratelimit.NewLimiter(time.Now, 100_000)} |
| e.geo = geo.NewSwappable() |
| e.geoLookup = e.geo.Lookup |
| // Generations (zero-downtime spec §7.2), before the startup Reload so |
| @@ -903,7 +917,8 @@ func (e *Edge) Reload() error { |
| "route %s is a hibernating instance but this box has no activator, so nothing here will create %s or start its process. If this box runs `carlos agent`, set CARLOS_HIBERNATE_BUCKET in /etc/carlos/host.env and restart carlos-edge; `carlos edge` on its own never runs instances.", |
| t.Host, t.Socket)) |
| } |
| - m[t.Host] = upstream{proxy: proxy, route: t, hibernating: hib, viaTunnel: viaTunnel, genManaged: genManaged} |
| + m[t.Host] = upstream{proxy: proxy, route: t, hibernating: hib, viaTunnel: viaTunnel, genManaged: genManaged, |
| + rate: e.parseRateSettings(t)} |
| } |
| // Path routes, folded BEFORE aliases so an alias of a prefix-routed |
| // hostname inherits its map along with everything else it copies — an |
| @@ -1719,6 +1734,13 @@ func (e *Edge) ServeHTTP(w http.ResponseWriter, r *http.Request) { |
| // identical to pre-cache behavior, rather than relying on |
| // recordingResponseWriter's Hijack forwarding below. |
| if isUpgradeRequest(r) { |
| + // The rate limit judges the handshake and holds no slot: an open |
| + // WebSocket is not work the instance is doing for the busy count. A |
| + // refusal is written to the raw writer; an admission leaves it |
| + // untouched. |
| + if _, ok := e.rateAdmit(w, r, up, false); !ok { |
| + return |
| + } |
| if up.hibernating { |
| if e.act.ServeHTTP(w, r, up.route, up.proxy) { |
| return |
| @@ -1781,6 +1803,23 @@ func (e *Edge) ServeHTTP(w http.ResponseWriter, r *http.Request) { |
| } |
| } |
| + // The rate limit (ratelimit.go): after the cache, so a hit is never |
| + // limited, and before the activator and the proxy, so a refusal never |
| + // wakes an instance. The 429 is written here, beneath no recorder, so it |
| + // is never stored. An admitted request holds a slot until the instance |
| + // starts its answer (slotWriter), including while it waits on a wake; |
| + // the defer covers an answer that never wrote anything. A request that |
| + // holds no slot (off, exempt, not an instance) keeps its writer as it |
| + // was. |
| + release, admitted := e.rateAdmit(w, r, up, true) |
| + if !admitted { |
| + return |
| + } |
| + if release != nil { |
| + defer release() |
| + w = &slotWriter{ResponseWriter: w, release: release} |
| + } |
| + |
| if up.hibernating { |
| // Wake (or join an in-progress wake) before proxying; the activator |
| // also stamps this request's activity for the idle clock. Note a bare |
diff --git a/internal/edge/ratelimit.go b/internal/edge/ratelimit.go| new file mode 100644 |
| index 000000000..e57fab738 |
| --- /dev/null |
| +++ b/internal/edge/ratelimit.go |
| @@ -0,0 +1,244 @@ |
| +package edge |
| + |
| +// The per-instance rate limit (#358) on the request path: fair share of an |
| +// instance's in-flight slots while it is busy, and a per-client backstop |
| +// bucket always. The decisions are internal/ratelimit's; this file decides |
| +// which requests are judged, keys them, and answers the refusals. |
| +// |
| +// ServeHTTP calls rateAdmit at the last point before a request would reach |
| +// the activator or the proxy: after the meter (a refusal is counted and |
| +// observed like any answer), after the password gate, and, on the ordinary |
| +// path, after the cache check (a hit costs the instance nothing). A refused |
| +// request therefore never wakes a sleeping instance. |
| + |
| +import ( |
| + "bufio" |
| + "fmt" |
| + "io" |
| + "log" |
| + "net" |
| + "net/http" |
| + "os" |
| + "strconv" |
| + "time" |
| + |
| + "github.com/carlosframework/platform/internal/ratelimit" |
| + "github.com/carlosframework/platform/internal/registry" |
| +) |
| + |
| +// rateLimitBody is the whole body of a rate-limit refusal. Plain text, |
| +// because callers may be scripts. |
| +const rateLimitBody = "Too many requests. Try again in a moment." |
| + |
| +// RateMode is the box-wide switch for the limiter, CARLOS_RATE_LIMIT. It is |
| +// a kill switch and a rollout mode, not where the numbers live: those are on |
| +// each instance's record. |
| +type RateMode int |
| + |
| +const ( |
| + // RateOff never consults the limiter. |
| + RateOff RateMode = iota |
| + // RateObserve judges every request and counts and logs what it would |
| + // refuse, but refuses nothing. The default, so a release can ship the |
| + // limiter and its counts can be read before anything is refused. |
| + RateObserve |
| + // RateEnforce refuses. |
| + RateEnforce |
| +) |
| + |
| +func (m RateMode) String() string { |
| + switch m { |
| + case RateOff: |
| + return "off" |
| + case RateObserve: |
| + return "observe" |
| + case RateEnforce: |
| + return "enforce" |
| + } |
| + return "RateMode(?)" |
| +} |
| + |
| +// rateModeFromEnv reads CARLOS_RATE_LIMIT: off, observe or enforce. Unset is |
| +// observe, and so is anything else, with a log line: a typo must not turn the |
| +// limiter off, and must not start refusing either. |
| +func rateModeFromEnv() RateMode { |
| + switch v := os.Getenv("CARLOS_RATE_LIMIT"); v { |
| + case "off": |
| + return RateOff |
| + case "", "observe": |
| + return RateObserve |
| + case "enforce": |
| + return RateEnforce |
| + default: |
| + log.Printf("edge: CARLOS_RATE_LIMIT=%q is not off, observe or enforce; observing", v) |
| + return RateObserve |
| + } |
| +} |
| + |
| +// SetRateCeilingFor installs the plan ceiling hook: the most a route's plan |
| +// lets its owner set (internal/host's planRateCeilingFor). It is consulted |
| +// per request, so a plan change applies on the next request without a |
| +// reload. nil, the default and every box without a plan catalog, is no |
| +// ceiling. Safe to call while serving. |
| +func (e *Edge) SetRateCeilingFor(f func(registry.Route) ratelimit.Ceiling) { |
| + if f == nil { |
| + e.rateCeiling.Store(nil) |
| + return |
| + } |
| + e.rateCeiling.Store(&f) |
| +} |
| + |
| +// parseRateSettings is Reload's reading of a route's rate_limit column. A |
| +// column the edge cannot use, unparseable or out of range, costs the |
| +// instance its own settings and never its service: it runs at the defaults, |
| +// and the edge says so, throttled, since the row repeats on every reload. |
| +func (e *Edge) parseRateSettings(rt registry.Route) ratelimit.Settings { |
| + if rt.RateLimit == "" { |
| + return ratelimit.Settings{} |
| + } |
| + s, err := ratelimit.Parse(rt.RateLimit) |
| + if err == nil { |
| + err = s.Validate() |
| + } |
| + if err != nil { |
| + e.logThrottled("ratelimit-bad-column "+rt.Host, fmt.Sprintf( |
| + "route %s: unusable rate_limit column (%v); limiting at the defaults", rt.Host, err)) |
| + return ratelimit.Settings{} |
| + } |
| + return s |
| +} |
| + |
| +// rateAdmit judges r for up. holdSlot is false for an upgrade, which is |
| +// judged when its handshake arrives and never holds a slot. When ok is |
| +// false the 429 has been written and the caller returns. Otherwise release |
| +// is nil when the request holds no slot (not judged, or judged without one), |
| +// and when it is not, the caller must call it once the request is done; it |
| +// gives the slot back if the slot writer has not already. |
| +// |
| +// Not judged: anything but an instance, a door caller (the box itself), and |
| +// a request that arrived over a fleet tunnel. On the fleet side of a tunnel |
| +// every request comes from the hub, so keying on it would put every client |
| +// in one bucket; the hub has the route row and the real client, and limits |
| +// there (its route is viaTunnel). |
| +func (e *Edge) rateAdmit(w http.ResponseWriter, r *http.Request, up upstream, holdSlot bool) (release func(), ok bool) { |
| + if e.rateMode == RateOff || up.route.Kind != "instance" { |
| + return nil, true |
| + } |
| + if _, door := doorCallerFrom(r.Context()); door || fromTunnel(r.Context()) { |
| + return nil, true |
| + } |
| + client, ok := ratelimit.ClientKey(clientIP(r)) |
| + if !ok { |
| + // No address to key on, so nothing to be fair between. |
| + return nil, true |
| + } |
| + var ceiling ratelimit.Ceiling |
| + if f := e.rateCeiling.Load(); f != nil { |
| + ceiling = (*f)(up.route) |
| + } |
| + eff := ratelimit.Resolve(up.rate, ceiling) |
| + observe := e.rateMode == RateObserve |
| + // Keyed on the route's host, never the request's: an alias, a wildcard |
| + // name and the primary are one instance with one set of buckets. |
| + t, d, retryAfter := e.rateLimiter.Admit(up.route.Host, eff, client, r.URL.Path, holdSlot, observe) |
| + if d != ratelimit.Allow { |
| + e.noteRateLimited(up.route, d, client.String(), observe) |
| + if !observe { |
| + writeRateLimited(w, retryAfter) |
| + return nil, false |
| + } |
| + } |
| + if !holdSlot { |
| + return nil, true |
| + } |
| + return t.Release, true |
| +} |
| + |
| +// noteRateLimited counts one refusal (or, observing, one that would have |
| +// been) and logs it, throttled per host and reason. |
| +func (e *Edge) noteRateLimited(rt registry.Route, d ratelimit.Decision, client string, observe bool) { |
| + if m := e.usageMeter.Load(); m != nil { |
| + m.RecordRateLimited(rt, d) |
| + } |
| + reason := "backstop" |
| + if d == ratelimit.Shed { |
| + reason = "fair-share" |
| + } |
| + verb := "refused" |
| + if observe { |
| + verb = "would refuse" |
| + } |
| + // The key is the host and the reason, both the box's own values; the |
| + // client is only in the message, so a stream of addresses cannot grow |
| + // the throttle map. |
| + e.logThrottled("ratelimit "+rt.Host+" "+reason, fmt.Sprintf( |
| + "rate limit: %s a request for %s (%s), client %s", verb, rt.Host, reason, client)) |
| +} |
| + |
| +// writeRateLimited answers a refusal: 429, Retry-After in whole seconds (at |
| +// least one), never stored by anyone, and the plain-text body. |
| +func writeRateLimited(w http.ResponseWriter, retryAfter time.Duration) { |
| + h := w.Header() |
| + h.Set("Content-Type", "text/plain; charset=utf-8") |
| + h.Set("X-Content-Type-Options", "nosniff") |
| + h.Set("Cache-Control", "no-store") |
| + h.Set("Retry-After", strconv.FormatInt(max(int64(retryAfter/time.Second), 1), 10)) |
| + w.WriteHeader(http.StatusTooManyRequests) |
| + io.WriteString(w, rateLimitBody) |
| +} |
| + |
| +// slotWriter gives a request's slot back when the instance starts its |
| +// answer: the first final WriteHeader, Write or Flush. The busy count |
| +// measures work the instance is doing, not how fast a client downloads, so a |
| +// long body or an event stream stops counting once its headers are out. An |
| +// informational (1xx) header is not the answer and keeps the slot. |
| +// |
| +// It wraps the writer handed to the activator too, so a request waiting on a |
| +// wake holds its slot until the woken instance answers or the activator |
| +// answers for it. |
| +type slotWriter struct { |
| + http.ResponseWriter |
| + release func() |
| + done bool |
| +} |
| + |
| +func (s *slotWriter) free() { |
| + if !s.done { |
| + s.done = true |
| + s.release() |
| + } |
| +} |
| + |
| +func (s *slotWriter) WriteHeader(code int) { |
| + if code >= 200 { |
| + s.free() |
| + } |
| + s.ResponseWriter.WriteHeader(code) |
| +} |
| + |
| +func (s *slotWriter) Write(p []byte) (int, error) { |
| + s.free() |
| + return s.ResponseWriter.Write(p) |
| +} |
| + |
| +func (s *slotWriter) Flush() { |
| + s.free() |
| + if f, ok := s.ResponseWriter.(http.Flusher); ok { |
| + f.Flush() |
| + } |
| +} |
| + |
| +// Hijack forwards like countingWriter's, so the writer stack below a |
| +// recordingResponseWriter keeps the shape it had. Nothing on the path this |
| +// writer serves upgrades; upgrades never get one. |
| +func (s *slotWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) { |
| + hj, ok := s.ResponseWriter.(http.Hijacker) |
| + if !ok { |
| + return nil, nil, fmt.Errorf("edge: underlying ResponseWriter does not support http.Hijacker") |
| + } |
| + s.free() |
| + return hj.Hijack() |
| +} |
| + |
| +// Unwrap lets http.ResponseController reach the writers below. |
| +func (s *slotWriter) Unwrap() http.ResponseWriter { return s.ResponseWriter } |
diff --git a/internal/edge/ratelimit_test.go b/internal/edge/ratelimit_test.go| new file mode 100644 |
| index 000000000..3866307e0 |
| --- /dev/null |
| +++ b/internal/edge/ratelimit_test.go |
| @@ -0,0 +1,719 @@ |
| +package edge |
| + |
| +// The per-instance rate limit (#358) on the edge's request path. Every |
| +// request here goes through Edge.ServeHTTP (or serveDoor, which hands it to |
| +// ServeHTTP) against a real upstream; nothing calls rateAdmit directly. |
| + |
| +import ( |
| + "context" |
| + "fmt" |
| + "io" |
| + "net" |
| + "net/http" |
| + "net/http/httptest" |
| + "net/url" |
| + "strings" |
| + "sync" |
| + "sync/atomic" |
| + "testing" |
| + "time" |
| + |
| + "github.com/carlosframework/platform/internal/doorkey" |
| + "github.com/carlosframework/platform/internal/ratelimit" |
| + "github.com/carlosframework/platform/internal/registry" |
| +) |
| + |
| +const ( |
| + rlHost = "shop.example.com" |
| + rlAlias = "www.shop.example" |
| + // rlPeerHeader is how a test names the client address. The front server |
| + // below turns it into RemoteAddr and deletes it, so the edge sees an |
| + // ordinary connection from that address. |
| + rlPeerHeader = "X-Rate-Test-Peer" |
| +) |
| + |
| +// rlClient bounds every request, so a limiter that lets through what it |
| +// should refuse fails the test instead of hanging it on a blocked upstream. |
| +var rlClient = &http.Client{Timeout: 10 * time.Second} |
| + |
| +// rateScene is an edge serving rlHost, behind a front server that sets each |
| +// request's peer address from rlPeerHeader. |
| +type rateScene struct { |
| + e *Edge |
| + front *httptest.Server |
| +} |
| + |
| +// newRateScene builds the edge in mode ("" leaves CARLOS_RATE_LIMIT empty, |
| +// which is observe). The mode is read in New, so it is set first. |
| +func newRateScene(t *testing.T, mode string, act Activator, routes ...registry.Route) *rateScene { |
| + t.Helper() |
| + t.Setenv("CARLOS_RATE_LIMIT", mode) |
| + reg := openReg(t) |
| + for _, rt := range routes { |
| + if err := reg.Upsert(rt); err != nil { |
| + t.Fatalf("upsert %s: %v", rt.Host, err) |
| + } |
| + } |
| + e, err := New(reg, act) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + t.Cleanup(e.probers.Stop) |
| + front := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| + if p := r.Header.Get(rlPeerHeader); p != "" { |
| + r.Header.Del(rlPeerHeader) |
| + r.RemoteAddr = net.JoinHostPort(p, "40000") |
| + } |
| + e.ServeHTTP(w, r) |
| + })) |
| + t.Cleanup(front.Close) |
| + return &rateScene{e: e, front: front} |
| +} |
| + |
| +func rlRoute(addr, rateLimit string) registry.Route { |
| + return registry.Route{Host: rlHost, Kind: "instance", Addr: addr, Status: "ready", App: "web", RateLimit: rateLimit} |
| +} |
| + |
| +type rlResult struct { |
| + status int |
| + header http.Header |
| + body string |
| + err error |
| +} |
| + |
| +// do sends one request from peer and reads the whole answer. Accept-Encoding |
| +// is pinned to identity so the edge's compressor never holds a streamed |
| +// response back. |
| +func (s *rateScene) do(peer, host, path string) rlResult { |
| + req, err := http.NewRequest(http.MethodGet, s.front.URL+path, nil) |
| + if err != nil { |
| + return rlResult{err: err} |
| + } |
| + req.Host = host |
| + req.Header.Set(rlPeerHeader, peer) |
| + req.Header.Set("Accept-Encoding", "identity") |
| + resp, err := rlClient.Do(req) |
| + if err != nil { |
| + return rlResult{err: err} |
| + } |
| + defer resp.Body.Close() |
| + b, err := io.ReadAll(resp.Body) |
| + return rlResult{status: resp.StatusCode, header: resp.Header, body: string(b), err: err} |
| +} |
| + |
| +func (s *rateScene) get(t *testing.T, peer, host, path string) rlResult { |
| + t.Helper() |
| + res := s.do(peer, host, path) |
| + if res.err != nil { |
| + t.Fatalf("GET %s%s from %s: %v", host, path, peer, res.err) |
| + } |
| + return res |
| +} |
| + |
| +// goGet sends a request in the background; the answer arrives on the channel. |
| +func (s *rateScene) goGet(peer, host, path string) <-chan rlResult { |
| + ch := make(chan rlResult, 1) |
| + go func() { ch <- s.do(peer, host, path) }() |
| + return ch |
| +} |
| + |
| +func wantOK(t *testing.T, res rlResult, what string) { |
| + t.Helper() |
| + if res.status != http.StatusOK { |
| + t.Fatalf("%s: status %d %q, want 200", what, res.status, res.body) |
| + } |
| +} |
| + |
| +// want429 checks the whole refusal: status, Retry-After, no-store and the body. |
| +func want429(t *testing.T, res rlResult, retryAfter, what string) { |
| + t.Helper() |
| + if res.status != http.StatusTooManyRequests { |
| + t.Fatalf("%s: status %d %q, want 429", what, res.status, res.body) |
| + } |
| + if got := res.header.Get("Retry-After"); got != retryAfter { |
| + t.Fatalf("%s: Retry-After %q, want %q", what, got, retryAfter) |
| + } |
| + if got := res.header.Get("Cache-Control"); got != "no-store" { |
| + t.Fatalf("%s: Cache-Control %q, want no-store", what, got) |
| + } |
| + if res.body != rateLimitBody { |
| + t.Fatalf("%s: body %q, want %q", what, res.body, rateLimitBody) |
| + } |
| +} |
| + |
| +func waitResult(t *testing.T, ch <-chan rlResult, what string) rlResult { |
| + t.Helper() |
| + select { |
| + case res := <-ch: |
| + if res.err != nil { |
| + t.Fatalf("%s: %v", what, res.err) |
| + } |
| + return res |
| + case <-time.After(10 * time.Second): |
| + t.Fatalf("%s: no answer", what) |
| + } |
| + return rlResult{} |
| +} |
| + |
| +// blockingUpstream answers every request only once release is closed, and |
| +// says on arrived each time one reaches it. |
| +type blockingUpstream struct { |
| + srv *httptest.Server |
| + arrived chan struct{} |
| + release chan struct{} |
| + hits atomic.Int64 |
| + once sync.Once |
| +} |
| + |
| +func newBlockingUpstream(t *testing.T) *blockingUpstream { |
| + t.Helper() |
| + b := &blockingUpstream{arrived: make(chan struct{}, 64), release: make(chan struct{})} |
| + b.srv = httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| + b.hits.Add(1) |
| + b.arrived <- struct{}{} |
| + <-b.release |
| + io.WriteString(w, "done") |
| + })) |
| + // Open the gate before closing the server, whatever the test did. |
| + t.Cleanup(b.srv.Close) |
| + t.Cleanup(b.open) |
| + return b |
| +} |
| + |
| +func (b *blockingUpstream) open() { b.once.Do(func() { close(b.release) }) } |
| + |
| +func (b *blockingUpstream) addr() string { return b.srv.Listener.Addr().String() } |
| + |
| +func (b *blockingUpstream) waitArrived(t *testing.T, what string) { |
| + t.Helper() |
| + select { |
| + case <-b.arrived: |
| + case <-time.After(10 * time.Second): |
| + t.Fatalf("%s never reached the upstream", what) |
| + } |
| +} |
| + |
| +// countingUpstream answers at once with body, counting hits. |
| +func countingUpstream(t *testing.T, body string, hdr map[string]string) (*httptest.Server, *atomic.Int64) { |
| + t.Helper() |
| + n := new(atomic.Int64) |
| + ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| + n.Add(1) |
| + for k, v := range hdr { |
| + w.Header().Set(k, v) |
| + } |
| + io.WriteString(w, body) |
| + })) |
| + t.Cleanup(ts.Close) |
| + return ts, n |
| +} |
| + |
| +// ---- fair share ------------------------------------------------------------- |
| + |
| +// Two clients fill busy_at; the one already holding its share is refused, |
| +// and the refusal never reaches the upstream. A third client, holding |
| +// nothing, still gets through: only the heaviest are shed. |
| +func TestRateEnforceShedsWhenBusy(t *testing.T) { |
| + up := newBlockingUpstream(t) |
| + s := newRateScene(t, "enforce", nil, rlRoute(up.addr(), `{"busy_at":2,"client_share":1}`)) |
| + t.Cleanup(up.open) // before the front server closes on a failure |
| + |
| + a := s.goGet("203.0.113.1", rlHost, "/a") |
| + up.waitArrived(t, "A's first request") |
| + b := s.goGet("203.0.113.2", rlHost, "/b") |
| + up.waitArrived(t, "B's request") |
| + if n := s.e.rateLimiter.InFlight(rlHost); n != 2 { |
| + t.Fatalf("InFlight = %d, want 2 while both wait on the upstream", n) |
| + } |
| + |
| + want429(t, s.get(t, "203.0.113.1", rlHost, "/a2"), "1", "A's second request while busy") |
| + if n := up.hits.Load(); n != 2 { |
| + t.Fatalf("upstream hits = %d, want 2: a shed request must never reach the upstream", n) |
| + } |
| + |
| + c := s.goGet("203.0.113.3", rlHost, "/c") |
| + up.waitArrived(t, "C's request (holding no slots)") |
| + |
| + up.open() |
| + for name, ch := range map[string]<-chan rlResult{"A": a, "B": b, "C": c} { |
| + wantOK(t, waitResult(t, ch, name), name) |
| + } |
| + if n := s.e.rateLimiter.InFlight(rlHost); n != 0 { |
| + t.Fatalf("InFlight = %d after every request was answered, want 0", n) |
| + } |
| +} |
| + |
| +// A quiet instance at the defaults never refuses an ordinary client. |
| +func TestRateQuietNeverRefuses(t *testing.T) { |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), "")) |
| + for i := range 200 { |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, fmt.Sprintf("/page/%d", i)), fmt.Sprintf("request %d", i)) |
| + } |
| +} |
| + |
| +// ---- backstop and the wake path --------------------------------------------- |
| + |
| +// sleepyActivator is an instance that sleeps until a request wakes it. A wake |
| +// waits on wakeDone, so a test can hold one open. |
| +type sleepyActivator struct { |
| + mu sync.Mutex |
| + awake bool |
| + wakes int |
| + wakeDone chan struct{} |
| +} |
| + |
| +func (a *sleepyActivator) ServeHTTP(w http.ResponseWriter, r *http.Request, rt registry.Route, proxy http.Handler) bool { |
| + a.mu.Lock() |
| + if !a.awake { |
| + a.wakes++ |
| + a.mu.Unlock() |
| + <-a.wakeDone |
| + a.mu.Lock() |
| + a.awake = true |
| + } |
| + a.mu.Unlock() |
| + proxy.ServeHTTP(w, r) |
| + return true |
| +} |
| + |
| +func (a *sleepyActivator) RetireExcept(map[string]bool) {} |
| + |
| +func (a *sleepyActivator) wakeCount() int { |
| + a.mu.Lock() |
| + defer a.mu.Unlock() |
| + return a.wakes |
| +} |
| + |
| +// Review Focus 2: a refused request never wakes the instance. The first |
| +// request wakes it and holds its slot while it waits; the second, over the |
| +// backstop, is refused without reaching the activator; and once the |
| +// instance is asleep again, a request with an empty bucket is refused |
| +// without a wake. |
| +func TestRateBackstopRefusesWithoutWake(t *testing.T) { |
| + ts, _ := countingUpstream(t, "awake", nil) |
| + act := &sleepyActivator{wakeDone: make(chan struct{})} |
| + rt := rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`) |
| + rt.Hibernate = true |
| + s := newRateScene(t, "enforce", act, rt) |
| + var wakeOnce sync.Once |
| + finishWake := func() { wakeOnce.Do(func() { close(act.wakeDone) }) } |
| + t.Cleanup(finishWake) // before the front server closes on a failure |
| + |
| + first := s.goGet("203.0.113.1", rlHost, "/") |
| + deadline := time.Now().Add(10 * time.Second) |
| + for act.wakeCount() == 0 { |
| + if time.Now().After(deadline) { |
| + t.Fatal("the first request never reached the activator") |
| + } |
| + time.Sleep(5 * time.Millisecond) |
| + } |
| + if n := s.e.rateLimiter.InFlight(rlHost); n != 1 { |
| + t.Fatalf("InFlight = %d during the wake, want 1: a request waiting on a wake holds its slot", n) |
| + } |
| + |
| + want429(t, s.get(t, "203.0.113.1", rlHost, "/"), "1", "second request during the wake") |
| + if n := act.wakeCount(); n != 1 { |
| + t.Fatalf("wakes = %d, want 1", n) |
| + } |
| + |
| + finishWake() |
| + wantOK(t, waitResult(t, first, "first request"), "first request") |
| + |
| + act.mu.Lock() |
| + act.awake = false // idled out |
| + act.mu.Unlock() |
| + want429(t, s.get(t, "203.0.113.1", rlHost, "/"), "1", "request to the sleeping instance with an empty bucket") |
| + if n := act.wakeCount(); n != 1 { |
| + t.Fatalf("wakes = %d after a refused request, want 1: a refusal must never wake", n) |
| + } |
| +} |
| + |
| +// The slot is held until the instance sends headers, not until the body is |
| +// done: while a long body streams, the same client is not counted as busy. |
| +func TestRateSlotReleasedAtHeaders(t *testing.T) { |
| + stop := make(chan struct{}) |
| + var stopOnce sync.Once |
| + stopStream := func() { stopOnce.Do(func() { close(stop) }) } |
| + ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| + if r.URL.Path != "/stream" { |
| + io.WriteString(w, "ok") |
| + return |
| + } |
| + w.Header().Set("Content-Type", "text/plain") |
| + w.WriteHeader(http.StatusOK) |
| + w.(http.Flusher).Flush() |
| + limit := time.After(2 * time.Second) |
| + for { |
| + select { |
| + case <-stop: |
| + return |
| + case <-limit: |
| + return |
| + case <-time.After(20 * time.Millisecond): |
| + io.WriteString(w, "tick\n") |
| + w.(http.Flusher).Flush() |
| + } |
| + } |
| + })) |
| + t.Cleanup(ts.Close) |
| + t.Cleanup(stopStream) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), `{"busy_at":1,"client_share":1}`)) |
| + |
| + req, _ := http.NewRequest(http.MethodGet, s.front.URL+"/stream", nil) |
| + req.Host = rlHost |
| + req.Header.Set(rlPeerHeader, "203.0.113.1") |
| + req.Header.Set("Accept-Encoding", "identity") |
| + resp, err := rlClient.Do(req) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + defer resp.Body.Close() |
| + if resp.StatusCode != http.StatusOK { |
| + t.Fatalf("stream status = %d", resp.StatusCode) |
| + } |
| + if _, err := resp.Body.Read(make([]byte, 1)); err != nil { |
| + t.Fatalf("stream body: %v", err) |
| + } |
| + |
| + if n := s.e.rateLimiter.InFlight(rlHost); n != 0 { |
| + t.Fatalf("InFlight = %d while the body streams, want 0: the slot goes back at headers", n) |
| + } |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/other"), "the streaming client's next request") |
| + wantOK(t, s.get(t, "203.0.113.2", rlHost, "/other"), "a second client during the stream") |
| + stopStream() |
| + io.Copy(io.Discard, resp.Body) |
| +} |
| + |
| +// An upgrade is judged when the handshake arrives and never holds a slot: |
| +// it keeps the raw, hijackable writer, and the open connection does not count |
| +// toward busy. Over the backstop it is refused before the activator. |
| +func TestRateUpgradeJudgedNotHeld(t *testing.T) { |
| + var calls atomic.Int64 |
| + var e *Edge |
| + var heldDuring atomic.Int64 |
| + act := activatorFunc(func(w http.ResponseWriter, r *http.Request, rt registry.Route, proxy http.Handler) bool { |
| + calls.Add(1) |
| + if _, ok := w.(http.Hijacker); !ok { |
| + t.Error("the activator got an upgrade writer that is not an http.Hijacker") |
| + } |
| + heldDuring.Add(int64(e.rateLimiter.InFlight(rlHost))) |
| + w.WriteHeader(http.StatusSwitchingProtocols) |
| + return true |
| + }) |
| + rt := rlRoute("127.0.0.1:1", `{"rate":1,"burst":10}`) |
| + rt.Hibernate = true |
| + e = newRateScene(t, "enforce", act, rt).e |
| + |
| + upgrade := func() *hijackableRecorder { |
| + req := httptest.NewRequest(http.MethodGet, "http://"+rlHost+"/socket", nil) |
| + req.RemoteAddr = "203.0.113.1:40000" |
| + req.Header.Set("Connection", "Upgrade") |
| + req.Header.Set("Upgrade", "websocket") |
| + rec := &hijackableRecorder{ResponseRecorder: httptest.NewRecorder()} |
| + e.ServeHTTP(rec, req) |
| + return rec |
| + } |
| + for i := range 10 { |
| + if rec := upgrade(); rec.Code != http.StatusSwitchingProtocols { |
| + t.Fatalf("upgrade %d: status %d, want 101", i, rec.Code) |
| + } |
| + } |
| + if n := heldDuring.Load(); n != 0 { |
| + t.Fatalf("slots held during admitted upgrades summed to %d, want 0", n) |
| + } |
| + if n := e.rateLimiter.InFlight(rlHost); n != 0 { |
| + t.Fatalf("InFlight = %d after ten upgrades, want 0", n) |
| + } |
| + rec := upgrade() |
| + res := rlResult{status: rec.Code, header: rec.Header(), body: rec.Body.String()} |
| + want429(t, res, "1", "the eleventh upgrade, over the backstop") |
| + if n := calls.Load(); n != 10 { |
| + t.Fatalf("activator calls = %d, want 10: a refused upgrade never reaches it", n) |
| + } |
| +} |
| + |
| +// Review Focus 1: an alias is the primary's instance, so it spends the |
| +// primary's bucket. |
| +func TestRateAliasUsesPrimaryHost(t *testing.T) { |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`)) |
| + upsertAlias(t, s.e.reg, rlAlias, rlHost) |
| + if err := s.e.Reload(); err != nil { |
| + t.Fatal(err) |
| + } |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/"), "primary") |
| + want429(t, s.get(t, "203.0.113.1", rlAlias, "/"), "1", "alias after the primary spent the bucket") |
| +} |
| + |
| +// ---- modes ------------------------------------------------------------------ |
| + |
| +// Observe serves what enforce would refuse, and counts and logs it. |
| +func TestRateObserveCountsButServes(t *testing.T) { |
| + logs := captureLog(t) |
| + ts, hits := countingUpstream(t, "ok", nil) |
| + s := newRateScene(t, "", nil, rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`)) |
| + m := NewUsageMeter() |
| + s.e.EnableUsage(m) |
| + |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/"), "first") |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/"), "second, over the backstop") |
| + if n := hits.Load(); n != 2 { |
| + t.Fatalf("upstream hits = %d, want 2", n) |
| + } |
| + row := m.Drain()[rlHost] |
| + if row.Requests != 2 || row.RateCeiling != 1 || row.RateShed != 0 { |
| + t.Fatalf("row = %+v, want 2 requests and rate_ceiling 1", row) |
| + } |
| + if out := logs.String(); !strings.Contains(out, "would refuse") || !strings.Contains(out, rlHost) || |
| + !strings.Contains(out, "203.0.113.1/32") { |
| + t.Fatalf("log = %q, want a would-refuse line naming the host and the client", out) |
| + } |
| +} |
| + |
| +// Off never touches the limiter: no slots, no buckets, no counts. |
| +func TestRateOffDoesNothing(t *testing.T) { |
| + up := newBlockingUpstream(t) |
| + s := newRateScene(t, "off", nil, rlRoute(up.addr(), `{"busy_at":1,"client_share":1,"rate":1,"burst":1}`)) |
| + t.Cleanup(up.open) |
| + m := NewUsageMeter() |
| + s.e.EnableUsage(m) |
| + |
| + var chans []<-chan rlResult |
| + for i := range 3 { |
| + chans = append(chans, s.goGet("203.0.113.1", rlHost, "/")) |
| + up.waitArrived(t, fmt.Sprintf("request %d", i)) |
| + if n := s.e.rateLimiter.InFlight(rlHost); n != 0 { |
| + t.Fatalf("InFlight = %d in off mode, want 0", n) |
| + } |
| + } |
| + up.open() |
| + for i, ch := range chans { |
| + wantOK(t, waitResult(t, ch, fmt.Sprint(i)), fmt.Sprintf("request %d", i)) |
| + } |
| + if row := m.Drain()[rlHost]; row.RateShed != 0 || row.RateCeiling != 0 { |
| + t.Fatalf("row = %+v, want no rate counts in off mode", row) |
| + } |
| +} |
| + |
| +func TestRateModeFromEnv(t *testing.T) { |
| + for in, want := range map[string]RateMode{"": RateObserve, "observe": RateObserve, "enforce": RateEnforce, "off": RateOff, "bogus": RateObserve} { |
| + t.Setenv("CARLOS_RATE_LIMIT", in) |
| + if got := rateModeFromEnv(); got != want { |
| + t.Errorf("CARLOS_RATE_LIMIT=%q: mode %v, want %v", in, got, want) |
| + } |
| + } |
| +} |
| + |
| +// ---- exemptions ------------------------------------------------------------- |
| + |
| +// A cache hit costs the instance nothing and is never limited. |
| +func TestRateCacheHitNeverLimited(t *testing.T) { |
| + ts, hits := countingUpstream(t, "cached page", map[string]string{"Cache-Control": "public, max-age=60"}) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`)) |
| + s.e.EnableCache(NewCache(DefaultCacheMaxEntries, DefaultCacheMaxBodyBytes)) |
| + |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/page"), "the miss that fills the cache") |
| + if res := s.get(t, "203.0.113.1", rlHost, "/page"); res.status != http.StatusOK || res.body != "cached page" { |
| + t.Fatalf("cache hit with an empty bucket: %d %q, want 200 from the cache", res.status, res.body) |
| + } |
| + if n := hits.Load(); n != 1 { |
| + t.Fatalf("upstream hits = %d, want 1", n) |
| + } |
| + // The bucket really is empty: a miss is refused, and the refusal is not |
| + // stored for the next caller. |
| + want429(t, s.get(t, "203.0.113.1", rlHost, "/other"), "1", "a miss with an empty bucket") |
| + if res := s.get(t, "203.0.113.2", rlHost, "/other"); res.status != http.StatusOK { |
| + t.Fatalf("another client's /other: %d, want 200 (a 429 must never be cached)", res.status) |
| + } |
| +} |
| + |
| +// A door caller is the box itself and is never limited, even when a public |
| +// client at the box's own address has emptied the bucket. |
| +func TestRateDoorCallerExempt(t *testing.T) { |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + rt := rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`) |
| + rt.Account = "bae" |
| + s := newRateScene(t, "enforce", nil, rt) |
| + fx := newDoorKeyFixture(t) |
| + store := meshTestStore(t) |
| + key, entry := fx.mint(t, "bae", "web") |
| + putJSON(t, store, doorkey.RecordKey("bae", "web"), string(fx.record(t, "bae", "web", 1, entry))) |
| + s.e.doorKeys = fx.mirror(store) |
| + refreshDoorKeys(t, s.e.doorKeys) |
| + s.e.doorAddr = doorTestAddr |
| + |
| + wantOK(t, s.get(t, doorTestAddr, rlHost, "/"), "public request from the box's address") |
| + want429(t, s.get(t, doorTestAddr, rlHost, "/"), "1", "second public request") |
| + for i := range 3 { |
| + req := httptest.NewRequest(http.MethodGet, "http://"+rlHost+"/", nil) |
| + req.RemoteAddr = "@" |
| + req.Header.Set(doorkey.Header, key) |
| + rec := httptest.NewRecorder() |
| + s.e.serveDoor(rec, req) |
| + if rec.Code != http.StatusOK { |
| + t.Fatalf("door request %d: %d %q, want 200", i, rec.Code, rec.Body.String()) |
| + } |
| + } |
| +} |
| + |
| +// A verified hop is keyed by the client it carries, not by the sending edge. |
| +func TestRateHopKeyedByClient(t *testing.T) { |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), `{"rate":1,"burst":1}`)) |
| + store := meshTestStore(t) |
| + if err := mintMeshKey(context.Background(), store); err != nil { |
| + t.Fatal(err) |
| + } |
| + m := newHomeMap(store, "annie") |
| + refreshHomeMap(t, m) |
| + s.e.homes.Store(m) |
| + key, _ := m.meshKeys() |
| + |
| + hop := func(xff string) rlResult { |
| + t.Helper() |
| + resp := hopRequest(t, s.e, rlHost, map[string]string{ |
| + hopHeader: "1", |
| + hopAuthHeader: signHop(key, rlHost, time.Now()), |
| + "X-Forwarded-For": xff, |
| + }) |
| + return rlResult{status: resp.StatusCode, header: resp.Header, body: readBody(t, resp)} |
| + } |
| + wantOK(t, hop("203.0.113.9"), "first client over the hop") |
| + wantOK(t, hop("198.51.100.7"), "second client over the same hop") |
| + want429(t, hop("203.0.113.9"), "1", "first client again") |
| +} |
| + |
| +// ---- settings --------------------------------------------------------------- |
| + |
| +// Review Focus 4: the plan ceiling is applied per request, over whatever the |
| +// owner set. |
| +func TestRateCeilingClampsAtApply(t *testing.T) { |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + s := newRateScene(t, "enforce", nil, rlRoute(ts.Listener.Addr().String(), `{"rate":1000,"burst":1000}`)) |
| + var seen atomic.Value |
| + s.e.SetRateCeilingFor(func(rt registry.Route) ratelimit.Ceiling { |
| + seen.Store(rt.Host) |
| + return ratelimit.Ceiling{Rate: 2, Burst: 2} |
| + }) |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/"), "first") |
| + wantOK(t, s.get(t, "203.0.113.1", rlHost, "/"), "second") |
| + want429(t, s.get(t, "203.0.113.1", rlHost, "/"), "1", "third within a second, over the ceiling") |
| + if got, _ := seen.Load().(string); got != rlHost { |
| + t.Fatalf("ceiling hook saw host %q, want %q", got, rlHost) |
| + } |
| + |
| + // No hook is no ceiling: the owner's 1000 applies again. |
| + s.e.SetRateCeilingFor(nil) |
| + for i := range 5 { |
| + wantOK(t, s.get(t, "203.0.113.2", rlHost, "/"), fmt.Sprintf("request %d without a ceiling", i)) |
| + } |
| +} |
| + |
| +// Review Focus 5: a column the edge cannot use costs the instance its own |
| +// settings, never its service: it runs at the defaults and the edge says so. |
| +func TestRateMalformedColumnUsesDefaults(t *testing.T) { |
| + logs := captureLog(t) |
| + ts, _ := countingUpstream(t, "ok", nil) |
| + bad := rlRoute(ts.Listener.Addr().String(), "{bad") |
| + invalid := rlRoute(ts.Listener.Addr().String(), `{"rate":-5}`) |
| + invalid.Host = "invalid.example.com" |
| + s := newRateScene(t, "enforce", nil, bad, invalid) |
| + |
| + for _, host := range []string{rlHost, invalid.Host} { |
| + for i := range 3 { |
| + wantOK(t, s.get(t, "203.0.113.1", host, "/"), fmt.Sprintf("%s request %d", host, i)) |
| + } |
| + if up := s.e.current()[host]; up.rate.BusyAt != 0 || up.rate.Rule != (ratelimit.Rule{}) || up.rate.Paths != nil { |
| + t.Fatalf("%s: settings %+v, want the zero Settings (defaults)", host, up.rate) |
| + } |
| + if out := logs.String(); !strings.Contains(out, host) || !strings.Contains(out, "rate") { |
| + t.Fatalf("log = %q, want a line naming %s", out, host) |
| + } |
| + } |
| +} |
| + |
| +// ---- tunnels ---------------------------------------------------------------- |
| + |
| +// The hub has the route row and the real client, so it limits. The fleet box |
| +// sees every tunnelled request as coming from the hub, so it never limits |
| +// what arrives over the tunnel; it still limits its own direct traffic. |
| +func TestRateTunnelSides(t *testing.T) { |
| + t.Setenv("CARLOS_RATE_LIMIT", "enforce") |
| + hubReg := tunnelRoute(t, registry.Route{Host: rlHost, Kind: "instance", Status: "ready", Tunnel: "pi-box", App: "web", |
| + RateLimit: `{"rate":1,"burst":2}`}) |
| + hub, err := New(hubReg, nil) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + t.Cleanup(hub.probers.Stop) |
| + hubMeter := NewUsageMeter() |
| + hub.EnableUsage(hubMeter) |
| + srv := httptest.NewServer(hub) |
| + t.Cleanup(srv.Close) |
| + u, _ := url.Parse(srv.URL) |
| + th := NewTunnelHub(u.Hostname(), map[string]string{"pi-box": "sekrit"}) |
| + hub.EnableTunnels(th) |
| + if err := hub.Reload(); err != nil { |
| + t.Fatal(err) |
| + } |
| + if !hub.current()[rlHost].viaTunnel { |
| + t.Fatal("precondition: the hub's route must be viaTunnel") |
| + } |
| + |
| + app, _ := countingUpstream(t, "fleet app", nil) |
| + remoteReg := openReg(t) |
| + if err := remoteReg.Upsert(rlRoute(app.Listener.Addr().String(), `{"rate":1,"burst":1}`)); err != nil { |
| + t.Fatal(err) |
| + } |
| + remote, err := New(remoteReg, nil) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + t.Cleanup(remote.probers.Stop) |
| + remoteMeter := NewUsageMeter() |
| + remote.EnableUsage(remoteMeter) |
| + stop := startFakeRemoteHost(t, srv.URL, "pi-box", "sekrit", remote) |
| + t.Cleanup(stop) |
| + waitForTunnelState(t, th, "pi-box", "connected", e2eReconnectBound) |
| + |
| + viaHub := func() rlResult { |
| + t.Helper() |
| + req, _ := http.NewRequest(http.MethodGet, srv.URL+"/", nil) |
| + req.Host = rlHost |
| + resp, err := rlClient.Do(req) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + defer resp.Body.Close() |
| + b, _ := io.ReadAll(resp.Body) |
| + return rlResult{status: resp.StatusCode, header: resp.Header, body: string(b)} |
| + } |
| + // The fleet box's own burst is 1; two tunnelled requests through means |
| + // it did not limit them. |
| + wantOK(t, viaHub(), "first request via the hub") |
| + wantOK(t, viaHub(), "second request via the hub") |
| + want429(t, viaHub(), "1", "third request: the hub's burst of 2 is spent") |
| + if row := hubMeter.Drain()[rlHost]; row.RateCeiling != 1 { |
| + t.Fatalf("hub row = %+v, want rate_ceiling 1", row) |
| + } |
| + if row := remoteMeter.Drain()[rlHost]; row.RateCeiling != 0 || row.RateShed != 0 || row.Requests != 2 { |
| + t.Fatalf("fleet row = %+v, want 2 requests and no rate counts", row) |
| + } |
| + |
| + // Control: the fleet box does enforce on a request that did not come |
| + // over the tunnel. |
| + direct := func() int { |
| + req := httptest.NewRequest(http.MethodGet, "http://"+rlHost+"/", nil) |
| + req.RemoteAddr = "198.51.100.7:40000" |
| + rec := httptest.NewRecorder() |
| + remote.ServeHTTP(rec, req) |
| + return rec.Code |
| + } |
| + if c := direct(); c != http.StatusOK { |
| + t.Fatalf("direct request to the fleet box: %d, want 200", c) |
| + } |
| + if c := direct(); c != http.StatusTooManyRequests { |
| + t.Fatalf("second direct request to the fleet box: %d, want 429", c) |
| + } |
| +} |
diff --git a/internal/edge/usagemeter.go b/internal/edge/usagemeter.go| index 6afb2fa38..d5e8a1a27 100644 |
| --- a/internal/edge/usagemeter.go |
| +++ b/internal/edge/usagemeter.go |
| @@ -7,6 +7,7 @@ import ( |
| "net/http" |
| "sync" |
| + "github.com/carlosframework/platform/internal/ratelimit" |
| "github.com/carlosframework/platform/internal/registry" |
| "github.com/carlosframework/platform/internal/release" |
| "github.com/carlosframework/platform/internal/usage" |
| @@ -48,6 +49,27 @@ func (u *UsageMeter) Record(rt registry.Route, requests, bytes int64, hopped boo |
| u.mu.Unlock() |
| } |
| +// RecordRateLimited counts one request the rate limit refused, or in |
| +// observe mode would have refused, against rt. The request itself is |
| +// counted by Record like any other answer; these counters say why it was |
| +// (or would have been) a 429. |
| +func (u *UsageMeter) RecordRateLimited(rt registry.Route, d ratelimit.Decision) { |
| + if d == ratelimit.Allow { |
| + return |
| + } |
| + u.mu.Lock() |
| + row := u.m[rt.Host] |
| + row.Account = release.RouteAccount(rt) |
| + row.App = rt.App |
| + if d == ratelimit.Shed { |
| + row.RateShed++ |
| + } else { |
| + row.RateCeiling++ |
| + } |
| + u.m[rt.Host] = row |
| + u.mu.Unlock() |
| +} |
| + |
| // Drain returns the accumulated rows and resets the meter. |
| func (u *UsageMeter) Drain() map[string]usage.EdgeRow { |
| u.mu.Lock() |
diff --git a/internal/host/agent.go b/internal/host/agent.go| index ef5e93ddf..15acc3eaa 100644 |
| --- a/internal/host/agent.go |
| +++ b/internal/host/agent.go |
| @@ -940,6 +940,10 @@ func runAgent(args []string, buildClaims ClaimFactory) { |
| layoutReload.Store(&reload) |
| m := edge.NewUsageMeter() |
| e.EnableUsage(m) |
| + // The plan rate ceiling (#358): the same plans snapshot the |
| + // activator's idle hook reads, so a box without a plan catalog gets |
| + // the zero Ceiling and no extra reads. |
| + e.SetRateCeilingFor(planRateCeilingFor) |
| // Same arming point as the meter: the edge observes an upstream 5xx |
| // on the serving path and files it here (spec 2026-09-07 §3.2), and |
| // errshipLoop above ships what this fills. Guarded, because a typed |
diff --git a/internal/usage/edge.go b/internal/usage/edge.go| index 04f7bef1f..484933bd6 100644 |
| --- a/internal/usage/edge.go |
| +++ b/internal/usage/edge.go |
| @@ -31,6 +31,15 @@ type EdgeRow struct { |
| // stay byte-identical to what it wrote yesterday. |
| HopRequests int64 `json:"hop_requests,omitempty"` |
| HopBytesOut int64 `json:"hop_bytes_out,omitempty"` |
| + // RateShed and RateCeiling count the requests the per-instance rate |
| + // limit refused (or, in observe mode, would have refused): RateShed by |
| + // fair share while the instance was busy, RateCeiling by the per-client |
| + // backstop. Two counters because they mean different things: shedding is |
| + // the limit working under load, while backstop refusals of a real |
| + // customer mean the defaults are wrong. Both are inside Requests, never |
| + // added to it. Additive and omitempty, for the hop counters' reason. |
| + RateShed int64 `json:"rate_shed,omitempty"` |
| + RateCeiling int64 `json:"rate_ceiling,omitempty"` |
| } |
| // EdgeDay is usage/edge/<box>/days/<date>.json — a box's edge traffic for |
| @@ -75,6 +84,8 @@ func (d *EdgeDay) AddDeltas(hour string, deltas map[string]EdgeRow) { |
| row.BytesOut += delta.BytesOut |
| row.HopRequests += delta.HopRequests |
| row.HopBytesOut += delta.HopBytesOut |
| + row.RateShed += delta.RateShed |
| + row.RateCeiling += delta.RateCeiling |
| rows[host] = row |
| } |
| } |
diff --git a/internal/usage/edge_ratelimit_test.go b/internal/usage/edge_ratelimit_test.go| new file mode 100644 |
| index 000000000..0e1a16995 |
| --- /dev/null |
| +++ b/internal/usage/edge_ratelimit_test.go |
| @@ -0,0 +1,35 @@ |
| +package usage |
| + |
| +import ( |
| + "encoding/json" |
| + "strings" |
| + "testing" |
| +) |
| + |
| +// The rate-limit counters ride the edge row like the hop counters: summed |
| +// across flushes, and absent from the JSON of a row that has none, so a box |
| +// that limits nothing writes the same day object it wrote before. |
| +func TestAddDeltasSumsRateCounters(t *testing.T) { |
| + var d EdgeDay |
| + d.AddDeltas("09", map[string]EdgeRow{"shop.example.com": {Requests: 3, RateShed: 2, RateCeiling: 1}}) |
| + d.AddDeltas("09", map[string]EdgeRow{"shop.example.com": {Requests: 1, RateShed: 1, RateCeiling: 4}}) |
| + row := d.Hours["09"]["shop.example.com"] |
| + if row.Requests != 4 || row.RateShed != 3 || row.RateCeiling != 5 { |
| + t.Fatalf("row = %+v, want requests 4, rate_shed 3, rate_ceiling 5", row) |
| + } |
| + |
| + b, err := json.Marshal(row) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + if !strings.Contains(string(b), `"rate_shed":3`) || !strings.Contains(string(b), `"rate_ceiling":5`) { |
| + t.Fatalf("json = %s, want rate_shed and rate_ceiling", b) |
| + } |
| + b, err = json.Marshal(EdgeRow{Requests: 1}) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + if strings.Contains(string(b), "rate_") { |
| + t.Fatalf("json = %s, want no rate fields on a row that has none", b) |
| + } |
| +} |