carlos / platform Public

Merge origin/main into design-plans-and-caps

run-lifecycle-logs-325's census overlay loads before this branch's; the
seal is recomputed. The closed-door walk counts the two plan doors.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
claude agent, operated by paul@keymail.dev 2a1ac8393df6daa981e1a0a44c1fe2c601406433 parent 63585d7parent f54aa2f
12 files changed, +491 −19
  • docs/site/cli.md +2 −0
  • internal/console/svcroutes_test.go +2 −2
  • internal/host/agent.go +1 −1
  • internal/host/runevents.go +88 −0
  • internal/host/runevents_linux_test.go +114 −0
  • internal/host/runevents_test.go +206 −0
  • internal/host/runexec.go +15 −5
  • internal/host/runs.go +36 −6
  • internal/provision/plan14_root_reads_test.go +16 −2
  • internal/provision/plan9_b8_census_test.go +4 −2
  • internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv +1 −1
  • internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv +6 −0

CI passed — run details

CI log
=== gate ===
cd launchctx && go vet ./... && go test ./... -count=1
ok  	amadan.net/carlos/platform.git/launchctx	0.011s
?   	amadan.net/carlos/platform.git/launchctx/controlname	[no test files]
?   	amadan.net/carlos/platform.git/launchctx/wireid	[no test files]
go vet ./...
gofmt -l .: clean
go test ./... -count=1 -timeout 30m
ok  	github.com/carlosframework/platform	330.821s
?   	github.com/carlosframework/platform/cmd/changelog	[no test files]
ok  	github.com/carlosframework/platform/cmd/console	2.889s
ok  	github.com/carlosframework/platform/cmd/moveprobe	92.261s
ok  	github.com/carlosframework/platform/cmd/zddprobe	0.705s
ok  	github.com/carlosframework/platform/internal/activator	250.751s
ok  	github.com/carlosframework/platform/internal/agentsock	0.016s
ok  	github.com/carlosframework/platform/internal/alerting	0.005s
ok  	github.com/carlosframework/platform/internal/analytics	0.019s
ok  	github.com/carlosframework/platform/internal/appconfig	2.497s
ok  	github.com/carlosframework/platform/internal/apperr	0.078s
ok  	github.com/carlosframework/platform/internal/applog	0.138s
ok  	github.com/carlosframework/platform/internal/awsinv	0.004s
ok  	github.com/carlosframework/platform/internal/boxchoice	0.004s
ok  	github.com/carlosframework/platform/internal/boxid	0.702s
?   	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.008s
ok  	github.com/carlosframework/platform/internal/caps	0.013s
ok  	github.com/carlosframework/platform/internal/certwarm	0.004s
ok  	github.com/carlosframework/platform/internal/cgroup	0.704s
ok  	github.com/carlosframework/platform/internal/changelog	0.343s
ok  	github.com/carlosframework/platform/internal/claimactivation	0.803s
ok  	github.com/carlosframework/platform/internal/clamd	0.055s
?   	github.com/carlosframework/platform/internal/cliflag	[no test files]
ok  	github.com/carlosframework/platform/internal/console	445.024s
?   	github.com/carlosframework/platform/internal/controlname	[no test files]
?   	github.com/carlosframework/platform/internal/controlsock	[no test files]
ok  	github.com/carlosframework/platform/internal/dbdoor	6.360s
ok  	github.com/carlosframework/platform/internal/dbdoor/dbdoortest	0.009s
ok  	github.com/carlosframework/platform/internal/dbverify	0.004s
ok  	github.com/carlosframework/platform/internal/dnsrec	0.003s
ok  	github.com/carlosframework/platform/internal/docsite	0.006s
ok  	github.com/carlosframework/platform/internal/domains	2.400s
ok  	github.com/carlosframework/platform/internal/doorkey	0.006s
ok  	github.com/carlosframework/platform/internal/economics	0.005s
ok  	github.com/carlosframework/platform/internal/edge	45.238s
?   	github.com/carlosframework/platform/internal/edgeproof	[no test files]
ok  	github.com/carlosframework/platform/internal/edgesfile	0.009s
ok  	github.com/carlosframework/platform/internal/fleetapi	0.158s
ok  	github.com/carlosframework/platform/internal/gate	1.655s
ok  	github.com/carlosframework/platform/internal/genselect	0.016s
ok  	github.com/carlosframework/platform/internal/geo	0.010s
ok  	github.com/carlosframework/platform/internal/geoip	0.030s
ok  	github.com/carlosframework/platform/internal/historyreadback	0.206s
ok  	github.com/carlosframework/platform/internal/host	191.030s
ok  	github.com/carlosframework/platform/internal/hostactors	6.660s
ok  	github.com/carlosframework/platform/internal/hostactors/awsmembership	0.005s
ok  	github.com/carlosframework/platform/internal/hostbox	2.706s
ok  	github.com/carlosframework/platform/internal/hostclaim	0.590s
ok  	github.com/carlosframework/platform/internal/hostenv	0.005s
ok  	github.com/carlosframework/platform/internal/hostevidence	0.008s
ok  	github.com/carlosframework/platform/internal/hostexec	4.876s
ok  	github.com/carlosframework/platform/internal/hostfence	0.041s
ok  	github.com/carlosframework/platform/internal/hostfiles	10.574s
ok  	github.com/carlosframework/platform/internal/hostfloor	0.019s
ok  	github.com/carlosframework/platform/internal/hostguard	0.998s
ok  	github.com/carlosframework/platform/internal/hostops	1.665s
?   	github.com/carlosframework/platform/internal/hostops/fencerelease	[no test files]
ok  	github.com/carlosframework/platform/internal/hostops/internal/fencerelease	0.005s
ok  	github.com/carlosframework/platform/internal/hostquarantine	0.005s
ok  	github.com/carlosframework/platform/internal/hostrelocate	0.481s
ok  	github.com/carlosframework/platform/internal/hostresolve	0.148s
ok  	github.com/carlosframework/platform/internal/hostwrite	0.005s
ok  	github.com/carlosframework/platform/internal/infraview	0.004s
ok  	github.com/carlosframework/platform/internal/instancectl	5.254s
ok  	github.com/carlosframework/platform/internal/instanceexec	2.748s
ok  	github.com/carlosframework/platform/internal/instancefs	0.009s
ok  	github.com/carlosframework/platform/internal/instancekey	0.005s
ok  	github.com/carlosframework/platform/internal/instanceupdates	0.008s
ok  	github.com/carlosframework/platform/internal/layout	1.586s
ok  	github.com/carlosframework/platform/internal/lbhealth	0.003s
ok  	github.com/carlosframework/platform/internal/lease	9.901s
ok  	github.com/carlosframework/platform/internal/lease/leasetest	0.390s
ok  	github.com/carlosframework/platform/internal/ledger	0.013s
ok  	github.com/carlosframework/platform/internal/mail	0.194s
ok  	github.com/carlosframework/platform/internal/maintenance	0.077s
ok  	github.com/carlosframework/platform/internal/maintenanceexec	5.577s
ok  	github.com/carlosframework/platform/internal/maintenanceguard	0.092s
ok  	github.com/carlosframework/platform/internal/metrics	0.005s
ok  	github.com/carlosframework/platform/internal/moves	21.213s
ok  	github.com/carlosframework/platform/internal/moves/archive	0.839s
ok  	github.com/carlosframework/platform/internal/objstore	0.224s
ok  	github.com/carlosframework/platform/internal/ops	0.173s
ok  	github.com/carlosframework/platform/internal/park	0.216s
ok  	github.com/carlosframework/platform/internal/plans	0.005s
ok  	github.com/carlosframework/platform/internal/privatefile	0.004s
ok  	github.com/carlosframework/platform/internal/provision	31.717s
ok  	github.com/carlosframework/platform/internal/publicrelease	0.009s
?   	github.com/carlosframework/platform/internal/regionname	[no test files]
ok  	github.com/carlosframework/platform/internal/registry	5.516s
ok  	github.com/carlosframework/platform/internal/relay	7.236s
ok  	github.com/carlosframework/platform/internal/release	24.625s
ok  	github.com/carlosframework/platform/internal/rollout	3.710s
ok  	github.com/carlosframework/platform/internal/rolloutwords	0.004s
ok  	github.com/carlosframework/platform/internal/rootaws	0.007s
ok  	github.com/carlosframework/platform/internal/rootparticipation	0.059s
ok  	github.com/carlosframework/platform/internal/rootstate	0.027s
ok  	github.com/carlosframework/platform/internal/runs	0.583s
ok  	github.com/carlosframework/platform/internal/s3compat	0.005s
ok  	github.com/carlosframework/platform/internal/safefile	0.004s
ok  	github.com/carlosframework/platform/internal/schedule	2.588s
ok  	github.com/carlosframework/platform/internal/seeds	0.012s
ok  	github.com/carlosframework/platform/internal/sim/hostlife	9.949s
ok  	github.com/carlosframework/platform/internal/sim/litestreamfacts	4.219s
ok  	github.com/carlosframework/platform/internal/status	0.069s
ok  	github.com/carlosframework/platform/internal/steering	0.006s
ok  	github.com/carlosframework/platform/internal/stopevidence	0.289s
ok  	github.com/carlosframework/platform/internal/svcrole	0.002s
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.004s
ok  	github.com/carlosframework/platform/internal/unixdial	0.003s
ok  	github.com/carlosframework/platform/internal/updatewords	0.004s
ok  	github.com/carlosframework/platform/internal/usage	0.005s
ok  	github.com/carlosframework/platform/internal/version	0.001s
ok  	github.com/carlosframework/platform/internal/vet	1.608s
=== cross ===
--- shard 0 of 5 ---
cross-compiling darwin/arm64
--- shard 1 of 5 ---
cross-compiling darwin/amd64
--- shard 2 of 5 ---
cross-compiling linux/arm64
linux/arm64 carlos binary: 49873058 bytes (ceiling 52000000)
--- shard 3 of 5 ---
cross-compiling windows/amd64
--- shard 4 of 5 ---
cross-compiling windows/arm64
=== minio-contract ===
minio contract: arm64, minio RELEASE.2025-09-07T16-13-09Z, mc RELEASE.2025-08-13T08-35-41Z
  minio: cached, digest verified
  mc: cached, digest verified
  minio healthy on 127.0.0.1:20999
Added `local` successfully.
Bucket created successfully `local/contract-bucket`.
Bucket created successfully `local/denied-bucket`.
Created policy `contract-only` successfully.
Added user `scopeduser` successfully.
Attached Policies: [contract-only]
To User: scopeduser
  buckets and scoped user ready
=== RUN   TestDeliveredContractMinio
=== RUN   TestDeliveredContractMinio/put
=== RUN   TestDeliveredContractMinio/get_round-trips_the_body
=== RUN   TestDeliveredContractMinio/list_shows_the_key
=== RUN   TestDeliveredContractMinio/head_and_list_agree_on_the_version
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_its_own_object
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_its_own_object/not_by_PutObjectTagging
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_its_own_object/and_not_by_x-amz-tagging_on_upload
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/not_by_CreateMultipartUpload
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/not_by_CopyObject_with_a_REPLACE_tagging_directive
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/but_multipart_itself_is_allowed
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/and_copy_itself_is_allowed
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/a_POST-policy_forged_tag_with_a_matching_version_is_still_not_a_verdict
=== RUN   TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/and_an_ordinary_tagged-with-something-else_upload_is_allowed
=== RUN   TestDeliveredContractMinio/delete_removes_it
=== RUN   TestDeliveredContractMinio/cross-bucket_denial
--- PASS: TestDeliveredContractMinio (0.02s)
    --- PASS: TestDeliveredContractMinio/put (0.00s)
    --- PASS: TestDeliveredContractMinio/get_round-trips_the_body (0.00s)
    --- PASS: TestDeliveredContractMinio/list_shows_the_key (0.00s)
    --- PASS: TestDeliveredContractMinio/head_and_list_agree_on_the_version (0.00s)
    --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_its_own_object (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_its_own_object/not_by_PutObjectTagging (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_its_own_object/and_not_by_x-amz-tagging_on_upload (0.00s)
    --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route (0.01s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/not_by_CreateMultipartUpload (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/not_by_CopyObject_with_a_REPLACE_tagging_directive (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/but_multipart_itself_is_allowed (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/and_copy_itself_is_allowed (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/a_POST-policy_forged_tag_with_a_matching_version_is_still_not_a_verdict (0.00s)
        --- PASS: TestDeliveredContractMinio/the_app_cannot_tag_by_any_other_route/and_an_ordinary_tagged-with-something-else_upload_is_allowed (0.00s)
    --- PASS: TestDeliveredContractMinio/delete_removes_it (0.00s)
    --- PASS: TestDeliveredContractMinio/cross-bucket_denial (0.00s)
PASS
ok  	github.com/carlosframework/platform/internal/objstore	0.025s
=== RUN   TestT4StorageProbeMinio
2026/10/21 12:52:10 moves: T4: STORE: list: operation error S3: ListObjectsV2, https response error StatusCode: 403, RequestID: 18E08C7F5515C02B, HostID: 7c420053e0fbcd7f41653fdd92ffa2802c903d05303b1aa15adc2e8bb65d183f, api error SignatureDoesNotMatch: The request signature we calculated does not match the signature you provided. Check your key and signing method.
--- PASS: TestT4StorageProbeMinio (0.01s)
PASS
ok  	github.com/carlosframework/platform/internal/host	0.025s
minio contract: PASS
diff --git a/docs/site/cli.md b/docs/site/cli.md
index d3e4874e5..918eb7768 100644
--- a/docs/site/cli.md
+++ b/docs/site/cli.md
@@ -559,6 +559,8 @@ A hibernating instance is woken first. A live one keeps serving, and the command
carlos run exits with the command's own status, 128 plus the signal number when a signal ended it, 124 when it timed out, 125 when it was interrupted or the instance let go of it without a result, 130 when you cancelled it, 3 when the box refused it or did not pick it up within 60 seconds, and 2 when the console refused it.
+carlos logs shows when each run started, who asked for it and how it ended. The command's output is not kept there.
+
Arguments are kept in the account's audit log, with who ran them. Never put a secret in an argument. Pass it in a --file, or keep it in the instance's environment.
### carlos schedule
diff --git a/internal/console/svcroutes_test.go b/internal/console/svcroutes_test.go
index 649ade7fd..804f1f078 100644
--- a/internal/console/svcroutes_test.go
+++ b/internal/console/svcroutes_test.go
@@ -1003,8 +1003,8 @@ func TestEveryClosedDoorRefusesAServiceCredential(t *testing.T) {
}
seen++
}
- if seen != len(closedDoors) || seen != 61 {
- t.Errorf("walked %d closed doors, want all %d (and 61 today: instance-token, three door-key doors, the routes door, instances-manifest, the app update policy, sidecars-manifest, the route-channel move, three instance update settings doors, two db replica doors, six fleets, four services, two email credentials, email pause, the build probe, the swap policy, the live tenancy read, the layout read, the activation-cancel door, nine system doors, three deployment-wide antivirus, three platform geoip doors, two pointer digest doors, the channel resign, two release authorize doors, four store-entitlement doors, and the five run doors)",
+ if seen != len(closedDoors) || seen != 63 {
+ t.Errorf("walked %d closed doors, want all %d (and 63 today: instance-token, three door-key doors, the routes door, instances-manifest, the app update policy, sidecars-manifest, the route-channel move, three instance update settings doors, two db replica doors, six fleets, four services, two email credentials, email pause, the build probe, the swap policy, the live tenancy read, the layout read, the activation-cancel door, nine system doors, three deployment-wide antivirus, three platform geoip doors, two pointer digest doors, the channel resign, two release authorize doors, four store-entitlement doors, two account plan doors, and the five run doors)",
seen, len(closedDoors))
}
}
diff --git a/internal/host/agent.go b/internal/host/agent.go
index 483700f2d..559c0a27c 100644
--- a/internal/host/agent.go
+++ b/internal/host/agent.go
@@ -605,7 +605,7 @@ func runAgent(args []string, buildClaims ClaimFactory) {
// latch: no run is picked up before the startup sweep has
// stopped a previous agent's leftover units, the cmd units
// among them.
- armRunsPass(svc, reg, dd)
+ armRunsPass(svc, reg, dd, rolloutSink)
},
Ready: func() {
close(started)
diff --git a/internal/host/runevents.go b/internal/host/runevents.go
new file mode 100644
index 000000000..338498311
--- /dev/null
+++ b/internal/host/runevents.go
@@ -0,0 +1,88 @@
+package host
+
+import (
+ "fmt"
+ "time"
+
+ "github.com/carlosframework/platform/internal/applog"
+ "github.com/carlosframework/platform/internal/provision"
+ "github.com/carlosframework/platform/internal/runs"
+)
+
+// A run's two lines in `carlos logs` (amadan #325): when it started and who
+// asked for it, then how it ended. The output stays in the run's chunks and
+// the argv in the audit log; neither is ever written here, since a log
+// reader is not necessarily someone the command's arguments were meant for.
+//
+// Both lines are info. The Errors and Availability views read the platform
+// stream at warn and above, and a command that failed says nothing about
+// whether the instance could serve.
+
+const runEventLevel = applog.LevelInfo
+
+// runStartedLine is the line for a run whose unit has started.
+func runStartedLine(req runs.Request) string {
+ return fmt.Sprintf("run %s started by %s", req.ID, req.By)
+}
+
+// runEndedLine is the line for a run's result, whatever ended it. started
+// says whether RunCmd handed back a running unit: a result written before
+// that (a refusal, a cancel or a timeout during the wake or the staging, a
+// stop that overlapped the launch) is a run that did not start, whatever
+// its fields say. A failed start is the exception: StartCmd can answer an
+// error for a unit the control service did start (a lost response), and
+// RunCmd then stops it and hands back nothing, so the line hedges as the
+// CLI's does rather than say it never ran. A cancel or a deadline that
+// lands during that same start is written as cancelled or timed out with
+// no handle, and its line says "before it started", as the CLI says of the
+// same result: the result does not record whether the start was reached,
+// and the line restates the result, never more.
+func runEndedLine(id string, res runs.Result, started bool) string {
+ took := res.Ended.Sub(res.Started).Round(time.Second)
+ switch {
+ case res.Refused != "":
+ return fmt.Sprintf("run %s did not start: %s", id, runRefusedWords(res))
+ case res.Interrupted != "" && !started && res.Interrupted != runs.InterruptedStartFailed:
+ return fmt.Sprintf("run %s did not start: %s", id, res.Interrupted)
+ case res.Cancelled && !started:
+ return fmt.Sprintf("run %s was cancelled before it started", id)
+ case res.Cancelled:
+ return fmt.Sprintf("run %s was cancelled after %s", id, took)
+ case res.TimedOut && !started:
+ return fmt.Sprintf("run %s timed out before it started", id)
+ case res.TimedOut:
+ return fmt.Sprintf("run %s timed out after %s", id, took)
+ case res.Interrupted != "":
+ return fmt.Sprintf("run %s was interrupted: %s. it may have done part of its work", id, res.Interrupted)
+ case res.Signal != "":
+ return fmt.Sprintf("run %s was ended by signal %s after %s", id, res.Signal, took)
+ }
+ return fmt.Sprintf("run %s ended with exit %d after %s", id, res.Exit, took)
+}
+
+// runRefusedWords is why the box did not start the run. An unknown code
+// renders as itself, as the CLI's does.
+func runRefusedWords(res runs.Result) string {
+ switch res.Refused {
+ case runs.RefusedFlat:
+ return "the box is not on the nested layout yet"
+ case runs.RefusedClaim:
+ return "the box has host claims armed"
+ case runs.RefusedWake:
+ return fmt.Sprintf("the instance did not wake. %s", res.Detail)
+ case runs.RefusedIncarnation:
+ return "the instance was deleted and created again after the run was requested"
+ case runs.RefusedImport:
+ return "the instance is an import that is not committed yet"
+ }
+ return res.Refused
+}
+
+// runEvent publishes one of a run's lines against the record's instance.
+// A box with no log store has no sink, and emits nothing.
+func (w *runsWorker) runEvent(rec provision.Record, line string) {
+ if w.events == nil {
+ return
+ }
+ w.events.Event(rec.Account, rec.App, rec.Host, runEventLevel, line)
+}
diff --git a/internal/host/runevents_linux_test.go b/internal/host/runevents_linux_test.go
new file mode 100644
index 000000000..16f51b560
--- /dev/null
+++ b/internal/host/runevents_linux_test.go
@@ -0,0 +1,114 @@
+package host
+
+import (
+ "context"
+ "errors"
+ "reflect"
+ "strings"
+ "testing"
+ "time"
+
+ "github.com/carlosframework/platform/internal/activator"
+ "github.com/carlosframework/platform/internal/applog"
+ "github.com/carlosframework/platform/internal/instancectl"
+ "github.com/carlosframework/platform/internal/provision"
+ "github.com/carlosframework/platform/internal/release"
+)
+
+// A run that starts logs its start, then its end, against the record's
+// instance, at info, through the worker's sink.
+func TestRunLogsItsStartAndItsEnd(t *testing.T) {
+ s := release.NewDirStore(t.TempDir())
+ rec, req := pickedRun(t, s, 60)
+ req.By = "member@example.com"
+ h := &fakeHandle{polls: make(chan instancectl.CmdStatus, 1)}
+ h.polls <- instancectl.CmdStatus{State: instancectl.CmdDone, InvocationID: "inv1", Result: "exit-code", Status: "3", Code: "1"}
+ var events eventLog
+ w := execWorker(t, s, &fakeLauncher{handle: h, out: "the output\n"}, "boot-1")
+ w.events = &events
+ runOn(t, w, s, rec, req, newRunHandle())
+ ev := events.all()
+ if len(ev) != 2 {
+ t.Fatalf("events %+v, want a start and an end", ev)
+ }
+ want := loggedEvent{rec.Account, rec.App, rec.Host, applog.LevelInfo, "run " + req.ID + " started by member@example.com"}
+ if ev[0] != want {
+ t.Errorf("start %+v, want %+v", ev[0], want)
+ }
+ end := ev[1]
+ if end.acct != rec.Account || end.app != rec.App || end.host != rec.Host || end.level != applog.LevelInfo ||
+ !strings.HasPrefix(end.msg, "run "+req.ID+" ended with exit 3 after ") {
+ t.Errorf("end %+v", end)
+ }
+ for _, e := range ev {
+ if strings.Contains(e.msg, "the output") || strings.Contains(e.msg, "import") {
+ t.Errorf("%q carries the run's output or its arguments", e.msg)
+ }
+ }
+}
+
+// A run the box does not start logs only that it did not start, and why.
+func TestRunNotStartedLogsOnlyItsEnd(t *testing.T) {
+ cases := []struct {
+ err error
+ want string
+ }{
+ {activator.ErrCmdClaim, "did not start: the box has host claims armed"},
+ {activator.ErrCmdNotNested, "did not start: the box is not on the nested layout yet"},
+ {&activator.CmdStoppedError{Reason: activator.StopRestart}, "did not start: the instance was restarted"},
+ // A failed start may have started the unit (a lost response): the
+ // line hedges rather than say it never ran.
+ {errors.New("start cmd unit: 502"), "was interrupted: the box could not start the command. it may have done part of its work"},
+ }
+ for _, c := range cases {
+ s := release.NewDirStore(t.TempDir())
+ rec, req := pickedRun(t, s, 60)
+ var events eventLog
+ w := execWorker(t, s, &fakeLauncher{err: c.err}, "boot-1")
+ w.events = &events
+ runOn(t, w, s, rec, req, newRunHandle())
+ want := []loggedEvent{{rec.Account, rec.App, rec.Host, applog.LevelInfo, "run " + req.ID + " " + c.want}}
+ if ev := events.all(); !reflect.DeepEqual(ev, want) {
+ t.Errorf("%v: events %+v, want %+v", c.err, ev, want)
+ }
+ }
+}
+
+// A run whose result never landed logs no ending of its own: the run stays
+// picked, and the next agent's close-out writes and logs the one ending,
+// so the log never holds two that contradict each other (Astra round 3).
+func TestRunWhoseResultNeverLandedLeavesTheEndingToTheCloseOut(t *testing.T) {
+ defer func(d time.Duration) { runFinishBound = d }(runFinishBound)
+ runFinishBound = 300 * time.Millisecond
+ dir := release.NewDirStore(t.TempDir())
+ rec, req := pickedRun(t, dir, 60)
+ req.By = "member@example.com"
+ h := &fakeHandle{polls: make(chan instancectl.CmdStatus, 1)}
+ h.polls <- instancectl.CmdStatus{State: instancectl.CmdDone, InvocationID: "inv1", Result: "exit-code", Status: "0", Code: "1"}
+ var events eventLog
+ w := execWorker(t, &failingPuts{Store: dir, part: "/result.json"}, &fakeLauncher{handle: h}, "boot-1")
+ w.events = &events
+ rt, _ := runOwnedRoute(runHost)(runHost)
+ w.execute(context.Background(), rec, req, *rt, newRunHandle())
+ if r := currentRun(t, dir); r.State != provision.RunPicked {
+ t.Fatalf("run %+v, want still picked", r)
+ }
+ // The agent restarts once storage has recovered.
+ cur, err := provision.GetRecord(context.Background(), dir, rec.Account, rec.App, rec.Host)
+ if err != nil {
+ t.Fatal(err)
+ }
+ var l execLog
+ next := testWorker(dir, runOwnedRoute(runHost), "box-1", "boot-2", &l)
+ next.events = &events
+ next.consider(context.Background(), *cur)
+ var endings []string
+ for _, e := range events.all() {
+ if !strings.Contains(e.msg, " started by ") {
+ endings = append(endings, e.msg)
+ }
+ }
+ if len(endings) != 1 || !strings.Contains(endings[0], "the box's agent restarted") {
+ t.Fatalf("endings %q, want only the close-out's", endings)
+ }
+}
diff --git a/internal/host/runevents_test.go b/internal/host/runevents_test.go
new file mode 100644
index 000000000..3375c4e4f
--- /dev/null
+++ b/internal/host/runevents_test.go
@@ -0,0 +1,206 @@
+package host
+
+import (
+ "context"
+ "reflect"
+ "strings"
+ "sync"
+ "testing"
+ "time"
+
+ "github.com/carlosframework/platform/internal/activator"
+ "github.com/carlosframework/platform/internal/applog"
+ "github.com/carlosframework/platform/internal/provision"
+ "github.com/carlosframework/platform/internal/release"
+ "github.com/carlosframework/platform/internal/runs"
+)
+
+// eventLog records what a worker hands its EventSink.
+type eventLog struct {
+ mu sync.Mutex
+ events []loggedEvent
+}
+
+type loggedEvent struct{ acct, app, host, level, msg string }
+
+func (l *eventLog) App(acct, app, host, line string) {}
+
+func (l *eventLog) Event(acct, app, host, level, msg string) {
+ l.mu.Lock()
+ defer l.mu.Unlock()
+ l.events = append(l.events, loggedEvent{acct, app, host, level, msg})
+}
+
+func (l *eventLog) all() []loggedEvent {
+ l.mu.Lock()
+ defer l.mu.Unlock()
+ return append([]loggedEvent(nil), l.events...)
+}
+
+func TestRunEndedLineSaysHowTheRunEnded(t *testing.T) {
+ start := time.Date(2026, 10, 20, 12, 0, 0, 0, time.UTC)
+ end := start.Add(90*time.Second + 400*time.Millisecond)
+ ran := func(r runs.Result) runs.Result { r.Started, r.Ended = start, end; return r }
+ cases := []struct {
+ res runs.Result
+ started bool
+ want string
+ }{
+ {ran(runs.Result{}), true, "run r1 ended with exit 0 after 1m30s"},
+ {ran(runs.Result{Exit: 3}), true, "run r1 ended with exit 3 after 1m30s"},
+ {ran(runs.Result{Signal: "9"}), true, "run r1 was ended by signal 9 after 1m30s"},
+ {ran(runs.Result{TimedOut: true}), true, "run r1 timed out after 1m30s"},
+ {runs.Result{TimedOut: true, Ended: end}, false, "run r1 timed out before it started"},
+ {ran(runs.Result{Cancelled: true, Exit: 143}), true, "run r1 was cancelled after 1m30s"},
+ {runs.Result{Cancelled: true, Ended: end}, false, "run r1 was cancelled before it started"},
+ {ran(runs.Result{Interrupted: activator.StopRestart}), true,
+ "run r1 was interrupted: the instance was restarted. it may have done part of its work"},
+ {runs.Result{Interrupted: runs.InterruptedAgentRestart, Ended: end}, true,
+ "run r1 was interrupted: the box's agent restarted. it may have done part of its work"},
+ {runs.Result{Interrupted: activator.StopRestart, Ended: end}, false,
+ "run r1 did not start: the instance was restarted"},
+ {runs.Result{Interrupted: runs.InterruptedStartFailed, Ended: end}, false,
+ "run r1 was interrupted: the box could not start the command. it may have done part of its work"},
+ {runs.Result{Refused: runs.RefusedFlat}, false, "run r1 did not start: the box is not on the nested layout yet"},
+ {runs.Result{Refused: runs.RefusedClaim}, false, "run r1 did not start: the box has host claims armed"},
+ {runs.Result{Refused: runs.RefusedWake, Detail: "wake failed: restore"}, false,
+ "run r1 did not start: the instance did not wake. wake failed: restore"},
+ {runs.Result{Refused: runs.RefusedIncarnation}, false,
+ "run r1 did not start: the instance was deleted and created again after the run was requested"},
+ {runs.Result{Refused: runs.RefusedImport}, false, "run r1 did not start: the instance is an import that is not committed yet"},
+ {runs.Result{Refused: "something-new"}, false, "run r1 did not start: something-new"},
+ }
+ for _, c := range cases {
+ if got := runEndedLine("r1", c.res, c.started); got != c.want {
+ t.Errorf("%+v (started %v):\n got %q\nwant %q", c.res, c.started, got, c.want)
+ }
+ }
+}
+
+// The start line names the run and who asked for it, and never the
+// command's arguments: they can carry what a log reader should not see.
+func TestRunStartedLineCarriesNoArguments(t *testing.T) {
+ req := runs.Request{ID: "r1", By: "member@example.com", Argv: []string{"import", "--token", "s3cret"}}
+ got := runStartedLine(req)
+ if got != "run r1 started by member@example.com" {
+ t.Fatalf("got %q", got)
+ }
+ for _, a := range req.Argv {
+ if strings.Contains(got, a) {
+ t.Fatalf("%q carries the argument %q", got, a)
+ }
+ }
+}
+
+// A run closed out after an agent restart is logged as interrupted once,
+// however many passes still read it as picked.
+func TestRunClosedOutAfterAnAgentRestartIsLoggedOnce(t *testing.T) {
+ s := release.NewDirStore(t.TempDir())
+ _, id := queueRun(t, s, time.Now().Add(time.Minute))
+ got, err := provision.SetRecordRun(context.Background(), s, "bab", "shop", runHost, provision.RunPick(id, "box-1", "boot-old", time.Now().Add(time.Hour)))
+ if err != nil {
+ t.Fatal(err)
+ }
+ var l execLog
+ var events eventLog
+ w := testWorker(s, runOwnedRoute(runHost), "box-1", "boot-new", &l)
+ w.events = &events
+ // got is the stale read a second pass would also have noted.
+ w.consider(context.Background(), *got)
+ w.consider(context.Background(), *got)
+ want := []loggedEvent{{"bab", "shop", runHost, applog.LevelInfo,
+ "run " + id + " was interrupted: the box's agent restarted. it may have done part of its work"}}
+ if ev := events.all(); !reflect.DeepEqual(ev, want) {
+ t.Fatalf("events %+v, want %+v", ev, want)
+ }
+}
+
+// A restart after the command's own result landed, but before its done
+// CAS did, closes the run out without a second ending: the boot that ran
+// the command logged it (Astra review, finding 2).
+func TestRunClosedOutAfterItsOwnResultLogsNothing(t *testing.T) {
+ s := release.NewDirStore(t.TempDir())
+ _, id := queueRun(t, s, time.Now().Add(time.Minute))
+ got, err := provision.SetRecordRun(context.Background(), s, "bab", "shop", runHost, provision.RunPick(id, "box-1", "boot-old", time.Now().Add(time.Hour)))
+ if err != nil {
+ t.Fatal(err)
+ }
+ if err := runs.WriteResult(context.Background(), s, "bab", "shop", id, runs.Result{Exit: 0, Box: "box-1", Ended: time.Now().UTC()}); err != nil {
+ t.Fatal(err)
+ }
+ var l execLog
+ var events eventLog
+ w := testWorker(s, runOwnedRoute(runHost), "box-1", "boot-new", &l)
+ w.events = &events
+ w.consider(context.Background(), *got)
+ if ev := events.all(); len(ev) != 0 {
+ t.Fatalf("events %+v, want none", ev)
+ }
+ if r := currentRun(t, s); r.State != provision.RunDone {
+ t.Fatalf("run %+v, want done", r)
+ }
+ if res, _ := runs.ReadResult(context.Background(), s, "bab", "shop", id); res == nil || res.Interrupted != "" {
+ t.Fatalf("result %+v, want the command's own", res)
+ }
+}
+
+// A stale pass after the run was acknowledged (its result deleted, the
+// record cleared) recreates a result, but its done CAS fails, so it logs
+// no second ending (Astra round 2, finding 2).
+func TestRunClosedOutByAStalePassAfterTheAckLogsNothing(t *testing.T) {
+ s := release.NewDirStore(t.TempDir())
+ _, id := queueRun(t, s, time.Now().Add(time.Minute))
+ got, err := provision.SetRecordRun(context.Background(), s, "bab", "shop", runHost, provision.RunPick(id, "box-1", "boot-old", time.Now().Add(time.Hour)))
+ if err != nil {
+ t.Fatal(err)
+ }
+ var l execLog
+ var events eventLog
+ w := testWorker(s, runOwnedRoute(runHost), "box-1", "boot-new", &l)
+ w.events = &events
+ w.consider(context.Background(), *got)
+ // The CLI acknowledges the run: the record is cleared and the result
+ // deleted, as handleAPIRunAck does.
+ if _, err := provision.SetRecordRun(context.Background(), s, "bab", "shop", runHost, provision.RunClear(id)); err != nil {
+ t.Fatal(err)
+ }
+ if err := runs.DeleteRun(context.Background(), s, "bab", "shop", id); err != nil {
+ t.Fatal(err)
+ }
+ w.consider(context.Background(), *got)
+ if ev := events.all(); len(ev) != 1 {
+ t.Fatalf("events %+v, want the first pass's ending only", ev)
+ }
+}
+
+// A done CAS whose answer was lost loses the line rather than risk a
+// second one: run lines are at most once, and result.json is the record.
+func TestRunClosedOutWithALostDoneAnswerIsNotLoggedTwice(t *testing.T) {
+ dir := release.NewDirStore(t.TempDir())
+ _, id := queueRun(t, dir, time.Now().Add(time.Minute))
+ got, err := provision.SetRecordRun(context.Background(), dir, "bab", "shop", runHost, provision.RunPick(id, "box-1", "boot-old", time.Now().Add(time.Hour)))
+ if err != nil {
+ t.Fatal(err)
+ }
+ var l execLog
+ var events eventLog
+ w := testWorker(&lostAnswer{Store: dir, land: true}, runOwnedRoute(runHost), "box-1", "boot-new", &l)
+ w.events = &events
+ w.consider(context.Background(), *got)
+ w.consider(context.Background(), *got)
+ if r := currentRun(t, dir); r.State != provision.RunDone {
+ t.Fatalf("run %+v, want done (the CAS landed)", r)
+ }
+ if ev := events.all(); len(ev) != 0 {
+ t.Fatalf("events %+v, want none: the done answer was lost", ev)
+ }
+ if res, _ := runs.ReadResult(context.Background(), dir, "bab", "shop", id); res == nil || res.Interrupted != runs.InterruptedAgentRestart {
+ t.Fatalf("result %+v, want the interrupted result", res)
+ }
+}
+
+// A worker with no sink, as on a box with no log store, still runs.
+func TestRunEventWithoutASinkIsANoop(t *testing.T) {
+ w := &runsWorker{}
+ w.runEvent(provision.Record{Account: "bab", App: "shop", Host: runHost}, "run r1 started by member@example.com")
+}
diff --git a/internal/host/runexec.go b/internal/host/runexec.go
index 4b8aacf1f..f3c0004cc 100644
--- a/internal/host/runexec.go
+++ b/internal/host/runexec.go
@@ -208,6 +208,7 @@ func (w *runsWorker) execute(ctx context.Context, rec provision.Record, req runs
return
}
log.Printf("agent: runs: %s: run %s started (%s)", rec.Host, req.ID, handle.Invocation())
+ w.runEvent(rec, runStartedLine(req))
res := runs.Result{Started: w.now().UTC()}
status, doneAt := w.follow(ctx, rec, req, handle, h, &res)
bound := time.AfterFunc(runOutputGrace, endOutput)
@@ -440,11 +441,20 @@ func (w *runsWorker) finish(ctx context.Context, rec provision.Record, req runs.
})
if err != nil {
log.Printf("agent: runs: %s %s: result: %v", rec.Host, req.ID, err)
- } else if err := untilLanded(fctx, func(ctx context.Context) error {
- _, err := provision.SetRecordRun(ctx, w.store, rec.Account, rec.App, rec.Host, runFinishOurs(req.ID, w.box, w.boot))
- return err
- }); err != nil && !errors.Is(err, provision.ErrRunConflict) && !errors.Is(err, os.ErrNotExist) {
- log.Printf("agent: runs: %s %s: done: %v", rec.Host, req.ID, err)
+ } else {
+ // The ending is logged only once the result has landed (amadan
+ // #325: run lines are at most once). A result that never landed
+ // leaves the run picked, and a later agent's closeInterrupted
+ // writes and logs its own ending; logging this one too would put
+ // two contradictory endings in the log. A run with no handle never
+ // had its unit started.
+ w.runEvent(rec, runEndedLine(req.ID, res, handle != nil))
+ if err := untilLanded(fctx, func(ctx context.Context) error {
+ _, err := provision.SetRecordRun(ctx, w.store, rec.Account, rec.App, rec.Host, runFinishOurs(req.ID, w.box, w.boot))
+ return err
+ }); err != nil && !errors.Is(err, provision.ErrRunConflict) && !errors.Is(err, os.ErrNotExist) {
+ log.Printf("agent: runs: %s %s: done: %v", rec.Host, req.ID, err)
+ }
}
w.cleanUp(rec, req, handle)
}
diff --git a/internal/host/runs.go b/internal/host/runs.go
index cab2cd423..f85eccefd 100644
--- a/internal/host/runs.go
+++ b/internal/host/runs.go
@@ -48,6 +48,9 @@ type runsWorker struct {
boot string
now func() time.Time
exec func(ctx context.Context, rec provision.Record, req runs.Request, rt registry.Route, h *runHandle)
+ // events is where a run's start and end reach `carlos logs`
+ // (runevents.go); nil on a box with no log store.
+ events activator.EventSink
// start runs a picked run's exec: on its own goroutine in the agent,
// inline in tests that count launches.
start func(func())
@@ -311,12 +314,36 @@ func (w *runsWorker) closeInterrupted(ctx context.Context, rec provision.Record)
return
}
res := runs.Result{Interrupted: runs.InterruptedAgentRestart, Box: w.box, Ended: w.now().UTC(), LastSeq: last}
- if err := runs.WriteResult(ctx, w.store, rec.Account, rec.App, id, res); err != nil {
- log.Printf("agent: runs: %s %s: result: %v", rec.Host, id, err)
+ // A run's log lines are at most once and best effort (amadan #325), like
+ // the rest of the platform stream; result.json and the audit log are its
+ // record. So the ending is logged only by a pass that wrote the run's
+ // result itself (read before, read back after) AND whose own done CAS
+ // landed. Every pass that still holds a picked snapshot comes back here:
+ // the create-only write answers a second time as if it had landed, a
+ // result already there is the boot's that ran the command (which logged
+ // its own ending), and a stale pass after the run was acknowledged
+ // recreates a result but its CAS fails. A lost answer anywhere loses the
+ // line rather than risk a second one.
+ prior, err := runs.ReadResult(ctx, w.store, rec.Account, rec.App, id)
+ if err != nil {
+ log.Printf("agent: runs: %s %s: read the result: %v", rec.Host, id, err)
return
}
- if _, err := provision.SetRecordRun(ctx, w.store, rec.Account, rec.App, rec.Host, provision.RunFinish(id)); err != nil &&
- !errors.Is(err, provision.ErrRunConflict) && !errors.Is(err, os.ErrNotExist) {
+ ours := false
+ if prior == nil {
+ werr := runs.WriteResult(ctx, w.store, rec.Account, rec.App, id, res)
+ got, err := runs.ReadResult(ctx, w.store, rec.Account, rec.App, id)
+ if err != nil || got == nil {
+ log.Printf("agent: runs: %s %s: result: %v", rec.Host, id, errors.Join(werr, err))
+ return
+ }
+ ours = got.Box == res.Box && got.Ended.Equal(res.Ended) && got.Interrupted == res.Interrupted
+ }
+ if _, err := provision.SetRecordRun(ctx, w.store, rec.Account, rec.App, rec.Host, provision.RunFinish(id)); err == nil {
+ if ours {
+ w.runEvent(rec, runEndedLine(id, res, true))
+ }
+ } else if !errors.Is(err, provision.ErrRunConflict) && !errors.Is(err, os.ErrNotExist) {
log.Printf("agent: runs: %s %s: done: %v", rec.Host, id, err)
}
if err := runs.RemoveRunDir(provision.InstanceDir(w.dataDir, rec.Host), id); err != nil && !errors.Is(err, os.ErrNotExist) {
@@ -326,8 +353,10 @@ func (w *runsWorker) closeInterrupted(ctx context.Context, rec provision.Record)
}
// armRunsPass arms the runs worker on a box with an activator. Thin, like
-// armMovesPass: the behaviour is the worker's, tested there.
-func armRunsPass(svc *activator.Service, reg *registry.Registry, dataDir string) {
+// armMovesPass: the behaviour is the worker's, tested there. events must be
+// a genuinely nil interface when there is no log store, never a nil
+// *applog.Sink (the trap agent.go documents).
+func armRunsPass(svc *activator.Service, reg *registry.Registry, dataDir string, events activator.EventSink) {
if svc == nil || reg == nil {
return
}
@@ -337,6 +366,7 @@ func armRunsPass(svc *activator.Service, reg *registry.Registry, dataDir string)
return
}
w := newRunsWorker(store, reg.Get, svc, dataDir, BoxLabel(), newBootID())
+ w.events = events
armedRuns.Store(w)
log.Printf("agent: runs armed (box %s, boot %s)", w.box, w.boot)
}
diff --git a/internal/provision/plan14_root_reads_test.go b/internal/provision/plan14_root_reads_test.go
index bb7eb8269..2fff1e9c1 100644
--- a/internal/provision/plan14_root_reads_test.go
+++ b/internal/provision/plan14_root_reads_test.go
@@ -1034,20 +1034,34 @@ func TestPlan14RootReadCensus(t *testing.T) {
t.Fatal(err)
}
seal = "a21dba12b0f3cd0811c624ec352d6ff5c46936ef0da1d4ce9d31cdd13cc0f262"
+ if errs := checkRootReadLegacy(inv, seal); len(errs) != 0 {
+ t.Fatal(errs)
+ }
+ // Census overlay run-lifecycle-logs-325 (amadan #325: the box's carlos
+ // run worker emits run started and run ended as member log events
+ // through the agent's EventSink), loaded last, after scan-demand-revival. Proposed; ruling asked of
+ // the census owner on #280. No root read, file read or record write is
+ // added: runAgent and runsWorker.execute are re-pinned at their class and
+ // task, and the internal/host envelope is re-pinned. The seal moves
+ // because execute's legacy declaration was re-pinned.
+ if err = loadRootReadInventory(filepath.Join(root, "internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv"), &inv, true); err != nil {
+ t.Fatal(err)
+ }
+ seal = "cf0a526b5f7c913160b1e6a76fa34c34dacd60cbacfd8019e736c2ab852399e3"
// Census overlay design-plans-and-caps (plans 1: plan catalog, account
// plans, limits record publisher and operator door), loaded last.
// PROPOSED-design-plans-and-caps, asked of the census owner on #280.
// New console store methods, LoadCatalog and the CLI's --sponsored read
// are accepted legacy at their siblings' disposition; serve and
// Store.migrate are re-frozen. Frozen declarations are added, so the
- // seal moves; scan-demand-revival's is checked first.
+ // seal moves; run-lifecycle-logs-325's is checked first.
if errs := checkRootReadLegacy(inv, seal); len(errs) != 0 {
t.Fatal(errs)
}
if err = loadRootReadInventory(filepath.Join(root, "internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv"), &inv, true); err != nil {
t.Fatal(err)
}
- seal = "495f610f68f2d95dc1aca1973687d87e2f197b37f178fab51de85b573443876a"
+ seal = "4f5e0ed6adf7d6bcefdfc9ce50599a21adb06ae3e6d49cab71835e116968df17"
errs := append(compareRootReads(got, inv), checkRootReadLegacy(inv, seal)...)
errs = append(errs, checkRootReadDeclarations(got, inv)...)
if len(errs) > 0 {
diff --git a/internal/provision/plan9_b8_census_test.go b/internal/provision/plan9_b8_census_test.go
index 206d1023e..49dfe13cd 100644
--- a/internal/provision/plan9_b8_census_test.go
+++ b/internal/provision/plan9_b8_census_test.go
@@ -1102,9 +1102,11 @@ var plan9B8CensusInventory = []censusEntry{
// The run sweep clears a terminal run past retention through SetRecordRun (RunClear).
{"internal/console/runsweep.go", "Server.sweepTerminalRun", "record-writer", "key:SetRecordRun", "78e3510bbf056dbf28446391b552c87060094ca803a3b1a8b7d7013163ee136b"},
// The box records a run's end through SetRecordRun (runFinishOurs).
- {"internal/host/runexec.go", "runsWorker.finish", "record-writer", "key:SetRecordRun", "570fe08f48923e8b2d94104a2b895410fad712efc3a14c278ca5547309ceaff2"},
+ // Re-reviewed for run-lifecycle-logs-325 (amadan #325, proposed): emits the run's end as a member log event once its result has landed (at most once); record writes unchanged.
+ {"internal/host/runexec.go", "runsWorker.finish", "record-writer", "key:SetRecordRun", "42f8628f74fcdfd3a0a56d302caa6f423f6c8fe8726c3561028e94ad97037041"},
// The box closes a run an agent restart interrupted through SetRecordRun (runFinishOurs).
- {"internal/host/runs.go", "runsWorker.closeInterrupted", "record-writer", "key:SetRecordRun", "ccd125779b839856806e888a8d0897bd379625756c5e3d78ba88c41b9c868f27"},
+ // Re-reviewed for run-lifecycle-logs-325 (amadan #325, proposed): reads result.json before and after its create-only write and emits the run's end as a member log event only when the result is its own and its done CAS landed (at most once); record writes unchanged.
+ {"internal/host/runs.go", "runsWorker.closeInterrupted", "record-writer", "key:SetRecordRun", "b540e246a977470c50d3ebbbef080f9b8a824490fd3bb8bd6f98537bc882adee"},
// The box finishes a run of this boot whose result is written through SetRecordRun (RunFinish).
{"internal/host/runs.go", "runsWorker.finishStranded", "record-writer", "key:SetRecordRun", "2d775d33b9ba97e4ed2953eb1880d33affcfba95fe5857dcdde72eb0f9acadf0"},
// The box picks a queued run up by CAS through SetRecordRun (RunPick).
diff --git a/internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv b/internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv
index a70c8dcea..260fe0284 100644
--- a/internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv
+++ b/internal/provision/testdata/plan14-root-reads-design-plans-and-caps.tsv
@@ -1,4 +1,4 @@
-# Census overlay design-plans-and-caps (plans 1: the plan catalog, account_plans table, limits record publisher and operator door), loaded LAST, after scan-demand-revival. PROPOSED-design-plans-and-caps, asked of the census owner on #280.
+# Census overlay design-plans-and-caps (plans 1: the plan catalog, account_plans table, limits record publisher and operator door), loaded LAST, after run-lifecycle-logs-325. PROPOSED-design-plans-and-caps, asked of the census owner on #280.
# Every unit is console or CLI code that makes no root decision. New units: the account_plans store methods (console SQL on its own table, J4 root-input like their store siblings), LoadCatalog (reads the operator's CARLOS_PLAN_CATALOG once at start) and the CLI's --sponsored file read (runs as the invoking user). Changed legacy units serve (starts the plan limits worker, loads the catalog) and Store.migrate (adds the account_plans table) are re-frozen at their main disposition. Frozen declarations are added, so the seal moves.
@legacy 1b9b193a3f55138826e8a065961f0980f18388627ebe489becdbf5ffac494ac4 internal/console/accountplans.go Store.SetAccountPlan legacy accepted-legacy accepted-legacy;rev3=PROPOSED-design-plans-and-caps;basis=root-input; console SQL on its own account_plans table, as its store siblings (J4). file:QueryRow@442 7eb5c9bbffd4d730b95505d852a5a75fd7f07753ecf2d66d3b68407cbe76f69c
@legacy 488e0480e559bc7f74cdc7eb6a093b306f5eafde135d5c7b9dc5ab0b9515daea internal/console/accountplans.go Store.EnsureDefaultPlans legacy accepted-legacy accepted-legacy;rev3=PROPOSED-design-plans-and-caps;basis=root-input; console SQL on its own account_plans table, as its store siblings (J4). file:Exec@98 c9e38a24f10b5506742cf8fb34f6fb10a0bd0f629f4803cbfdcc2d6694ab6a3d
diff --git a/internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv b/internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv
new file mode 100644
index 000000000..66275f483
--- /dev/null
+++ b/internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv
@@ -0,0 +1,6 @@
+# Census overlay run-lifecycle-logs-325 (amadan #325: the box's carlos run worker emits run started and run ended as info-level member log events through the agent's EventSink), loaded LAST, after bootstrap-carlos-follows-316. Proposed; ruling asked of the census owner on #280.
+# No root read, file read or record write is added: the events are pure string formatting plus one EventSink.Event call, so runAgent (which passes the sink to armRunsPass) and runsWorker.execute (which emits the two events) keep their class, task and read sites, and only their digests, runAgent's Route offset and the internal/host envelope move. execute is accepted-legacy, so its declaration is re-pinned and the seal moves.
+@coverage internal/host 577cb4d70b0aa1e49d6b1ab9203295039b69e0171e63d181ee358b1ed00c2118
+@legacy 6f7ae8c101088f20464d1a727c898190b04726de1f08ee6040212be2ad840caa internal/host/runexec.go runsWorker.execute legacy accepted-legacy accepted-legacy;rev3=census-ruling-carlos-run;basis=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos): runs one picked run to its result in the bucket; every root action goes through instance control;rev3=PROPOSED-325;identity=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos);basis=emits the run's start and end as member log events through the agent's EventSink; reads unchanged file:Prepare@1838,whole:Route@2539 1b075de70048003120c62153a50f6d83bd3eff6615f9ea5008ddc747846c8fbb
+internal/host/runexec.go runsWorker.execute legacy accepted-legacy accepted-legacy;rev3=census-ruling-carlos-run;basis=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos): runs one picked run to its result in the bucket; every root action goes through instance control;rev3=PROPOSED-325;identity=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos);basis=emits the run's start and end as member log events through the agent's EventSink; reads unchanged file:Prepare@1838,whole:Route@2539 1b075de70048003120c62153a50f6d83bd3eff6615f9ea5008ddc747846c8fbb
+internal/host/agent.go runAgent authority B,C,D,F rev3=census-ruling-seeded-instances;basis=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos): main's body with wireSeedPlacement called in the activator start's Configure step, before armMovesPass, and the startup sweep's result stored for the import rollback in Recover; read sites unchanged, offsets moved; main's B,C,D,F authority retained PROPOSED E46: captured claim selection and root journal mutation; root RPC outside service host exclusion; SQL/route data never grants root authority. Executing identity: service controller; root for inventory/retirement callbacks.;rev3=PROPOSED-325;identity=the agent (/opt/carlos/carlos agent, carlos-edge.service, user carlos);basis=passes the agent's log sink to armRunsPass; reads unchanged file:Exec@13802,file:Open@731,registry:App@10065,whole:Route@10057,whole:Route@23122 9250dbd16a071a1f01e835f0fb8419e4de59effaa6f1d178b23547957ff66d86