amadan
Merge remote-tracking branch 'origin/main' into s3-polling-336
19 files changed,
+1121
−245
AGENTS.md+14 −1apimode_test.go+0 −5auth_e2e_test.go+77 −4auth_test.go+3 −1docs/site/cli.md+2 −0e2e_test.go+52 −180export_test.go+15 −0internal/host/agent.go+1 −1internal/host/runevents.go+88 −0internal/host/runevents_linux_test.go+114 −0internal/host/runevents_test.go+206 −0internal/host/runexec.go+15 −5internal/host/runs.go+36 −6internal/provision/plan14_root_reads_test.go+14 −0internal/provision/plan9_b8_census_test.go+4 −2internal/provision/testdata/plan14-root-reads-run-lifecycle-logs-325.tsv+6 −0internal/sim/litestreamfacts/facts_test.go+13 −1internal/stopevidence/fdholders_alias_linux_test.go+56 −32main_test.go+405 −7
diff --git a/AGENTS.md b/AGENTS.md| index cedb4c57c..8b81caa89 100644 |
| --- a/AGENTS.md |
| +++ b/AGENTS.md |
| @@ -296,7 +296,20 @@ anything. |
| **and set `cmd.Dir` to a scratch dir** — the binary walks cwd ancestors for |
| `.carlos/config`. The fallback is the operator's real login and default |
| console; a logged-in laptop running `go test ./...` minted 40+ real accounts |
| - on the production console before this was isolated. |
| + on the production console before this was isolated. A `t.TempDir()` is |
| + scratch in that sense only because the root package's `TestMain` |
| + (`isolateTempRoot`, main_test.go) checks both temp roots, TMPDIR and |
| + GOTMPDIR (`t.TempDir()` uses GOTMPDIR when it is set), and moves whichever |
| + has a `.carlos/config` above it, which is the case wherever one is under a |
| + logged-in home (#226, #258). The move is to a new |
| + `/var/tmp/carlos-test-*` directory, named on stderr and removed when the |
| + run ends. A run that is aborted (`log.Fatal`, a panic, a timeout) leaves |
| + that one directory behind: remove it by the name that was printed, never |
| + by pattern. `/tmp` is never used, and with `/var/tmp` unavailable the |
| + binary stops and says which variable to set. `TestMain` also drops an |
| + exported `CARLOS_CONFIG` and `CARLOS_DESTINATION`, which no shared helper |
| + pins. A test that leaves its cwd at the checkout is not covered by any of |
| + that. |
| - **A sidecar is a member that nothing can dial.** `Kind == "sidecar"` rows |
| carry no socket and no addr, and are refused by the edge ON KIND — not |
| merely unmatched by it — before dispatch ever looks at shape. That refusal |
diff --git a/apimode_test.go b/apimode_test.go| index d3296c017..33abb4f9d 100644 |
| --- a/apimode_test.go |
| +++ b/apimode_test.go |
| @@ -1054,11 +1054,6 @@ func TestShipVerbAPIMode(t *testing.T) { |
| useTempCredentials(t) |
| clearDeploymentEnv(t) |
| checkNoRegistry := requireNoRegistryTouch(t) |
| - // The working directory useTempCredentials picks is under $TMPDIR, which |
| - // can sit inside the operator's real home; the .carlos/config walk goes |
| - // up from it and would find the real ~/.carlos/config. Name a config |
| - // file of the test's own (missing, so no opinion) and skip discovery. |
| - t.Setenv("CARLOS_CONFIG", filepath.Join(t.TempDir(), "config")) |
| var reqCount int32 |
| mux := http.NewServeMux() |
diff --git a/auth_e2e_test.go b/auth_e2e_test.go| index 22ee1dfb7..9e0079637 100644 |
| --- a/auth_e2e_test.go |
| +++ b/auth_e2e_test.go |
| @@ -6,6 +6,7 @@ import ( |
| "crypto/sha256" |
| "encoding/hex" |
| "encoding/json" |
| + "fmt" |
| "io" |
| "net/http" |
| "net/http/httptest" |
| @@ -14,6 +15,8 @@ import ( |
| "os/exec" |
| "path/filepath" |
| "strings" |
| + "sync" |
| + "sync/atomic" |
| "testing" |
| "time" |
| @@ -25,19 +28,89 @@ import ( |
| // buildCarlos builds the real binary, the way TestStatusCLI does, so these |
| // tests exercise the actual command line an operator types rather than the |
| // functions underneath it. |
| +// |
| +// The binary is built once per test process (sharedCarlos), not once per |
| +// test: linking it takes seconds and about 135 tests wanted it. |
| func buildCarlos(t *testing.T) string { |
| + t.Helper() |
| + return sharedCarlos(t) |
| +} |
| + |
| +// The shared binary's state. moduleRoot, carlosBuildEnv and carlosTmpParent |
| +// are set by TestMain, after isolateTempRoot and before any test can |
| +// t.Chdir or t.Setenv, because the build has to run in the module, with the |
| +// real HOME and Go cache and the isolated temp root, whichever test asks |
| +// first. carlosDir is made by the build itself, in carlosTmpParent, so a run |
| +// that never asks for the binary makes nothing (a re-executed test binary, |
| +// like the child of TestQueryCleansUpWhenStdoutIsClosed, runs TestMain too |
| +// and exits without cleanup). TestMain removes it when the tests return. |
| +var ( |
| + moduleRoot string |
| + carlosBuildEnv []string |
| + carlosTmpParent string |
| + carlosDir string |
| + |
| + carlosBuilds atomic.Int32 |
| + sharedCarlosState carlosShared |
| +) |
| + |
| +// carlosShared is the one build for the whole test process: one Once, one |
| +// path, one error. The external test package (package main_test) reaches it |
| +// through export_test.go, so there is no second copy to disagree with. |
| +type carlosShared struct { |
| + once sync.Once |
| + path string |
| + err error |
| +} |
| + |
| +func (s *carlosShared) get(build func() (string, error)) (string, error) { |
| + s.once.Do(func() { s.path, s.err = build() }) |
| + return s.path, s.err |
| +} |
| + |
| +// sharedCarlos returns the path of the carlos binary, built from the module |
| +// on the first call and reused by every later one in this test process. The |
| +// build is lazy so a run that never needs the binary never pays for it. |
| +// |
| +// The file is read-only by contract: it is shared by every test, so a test |
| +// that writes to it, replaces it or moves it breaks the ones that run after. |
| +// It is mode 0555 to make that fail loudly. A test that needs a binary of |
| +// its own to modify or swap must copy it to its own directory first. A build |
| +// failure is kept, and fails every caller with the compiler's output. |
| +func sharedCarlos(t testing.TB) string { |
| t.Helper() |
| goBin, err := exec.LookPath("go") |
| if err != nil { |
| t.Skip("go toolchain not found; skipping CLI subprocess test") |
| } |
| - bin := filepath.Join(t.TempDir(), "carlos") |
| + path, err := sharedCarlosState.get(func() (string, error) { return buildSharedCarlos(goBin) }) |
| + if err != nil { |
| + t.Fatalf("build carlos: %v", err) |
| + } |
| + return path |
| +} |
| + |
| +// buildSharedCarlos is the build itself, run once. The directory goes under |
| +// GOTMPDIR when that is set, as t.TempDir() does, so the 120 MB file lands |
| +// wherever the tests' other scratch does. |
| +func buildSharedCarlos(goBin string) (string, error) { |
| + carlosBuilds.Add(1) |
| + dir, err := os.MkdirTemp(carlosTmpParent, "carlos-bin-") |
| + if err != nil { |
| + return "", fmt.Errorf("no directory for the shared binary: %w", err) |
| + } |
| + carlosDir = dir |
| + bin := filepath.Join(dir, "carlos") |
| build := exec.Command(goBin, "build", "-o", bin, ".") |
| - build.Env = os.Environ() |
| + build.Dir = moduleRoot |
| + build.Env = carlosBuildEnv |
| if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| + return "", fmt.Errorf("%v\n%s", err, out) |
| + } |
| + if err := os.Chmod(bin, 0o555); err != nil { |
| + return "", err |
| } |
| - return bin |
| + return bin, nil |
| } |
| // TestAuthCLI drives `carlos auth` as a subprocess against a fake console: |
diff --git a/auth_test.go b/auth_test.go| index 5a51b4955..b15d338bb 100644 |
| --- a/auth_test.go |
| +++ b/auth_test.go |
| @@ -17,7 +17,9 @@ import ( |
| // the credentials file, $HOME, the working directory, CARLOS_CONSOLE — at |
| // scratch space for the length of one test. Config resolution (config.go) |
| // consults all four; a developer's real ~/.carlos/config must never change |
| -// a test's answer. |
| +// a test's answer. The working directory is only scratch space because |
| +// TestMain (main_test.go isolateTempRoot) keeps every t.TempDir() clear of |
| +// a .carlos/config above it: discovery walks up from here. |
| func useTempCredentials(t *testing.T) string { |
| t.Helper() |
| home := t.TempDir() |
diff --git a/docs/site/cli.md b/docs/site/cli.md| index f44e5112f..782888cec 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/e2e_test.go b/e2e_test.go| index 977a38e5f..f4ed78414 100644 |
| --- a/e2e_test.go |
| +++ b/e2e_test.go |
| @@ -29,10 +29,12 @@ import ( |
| "path/filepath" |
| "reflect" |
| "regexp" |
| + "runtime" |
| "strings" |
| "testing" |
| "time" |
| + platform "github.com/carlosframework/platform" |
| "github.com/carlosframework/platform/internal/appconfig" |
| "github.com/carlosframework/platform/internal/domains" |
| "github.com/carlosframework/platform/internal/edge" |
| @@ -101,6 +103,38 @@ func carlosTestEnv(t *testing.T, extra ...string) []string { |
| return append(env, extra...) |
| } |
| +// sharedCarlos is the one shared carlos build (auth_e2e_test.go), reached |
| +// through export_test.go: this file is package main_test and cannot see |
| +// package main's test helpers any other way. The binary is built at most once |
| +// per test process, whichever package asks first, and is read-only. |
| +func sharedCarlos(t testing.TB) string { |
| + t.Helper() |
| + return platform.SharedCarlosForTest(t) |
| +} |
| + |
| +// The external package gets the very file the internal one does: one build |
| +// for the process, whoever asked first, read-only. |
| +func TestSharedCarlosFromTheExternalPackage(t *testing.T) { |
| + if testing.Short() { |
| + t.Skip("builds a binary") |
| + } |
| + t.Chdir(t.TempDir()) |
| + first, second := sharedCarlos(t), sharedCarlos(t) |
| + if first != second { |
| + t.Fatalf("calls gave %s and %s, want one path", first, second) |
| + } |
| + if n := platform.SharedCarlosBuildsForTest(); n != 1 { |
| + t.Errorf("%d builds in this process, want 1", n) |
| + } |
| + info, err := os.Stat(first) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + if runtime.GOOS != "windows" && info.Mode().Perm() != 0o555 { |
| + t.Errorf("mode %v, want r-xr-xr-x", info.Mode().Perm()) |
| + } |
| +} |
| + |
| func e2eShipSite(t *testing.T, store release.Store, version string, files map[string]string) { |
| t.Helper() |
| dir := t.TempDir() |
| @@ -507,17 +541,8 @@ func TestEndToEndSmoke(t *testing.T) { |
| // - a bare `carlos status` (no -dry-run) must exit non-zero — RunStatus's |
| // own input validation, not the pipeline it wraps. |
| func TestStatusCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found; skipping status CLI test") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| dryRunDir := filepath.Join(tmp, "dryrun") |
| if err := os.MkdirAll(dryRunDir, 0o755); err != nil { |
| @@ -722,17 +747,8 @@ func TestMultiAccountEndToEnd(t *testing.T) { |
| // the account-qualified prefix WITHOUT ever deleting the legacy ones — |
| // deletion is a separate operator step behind the verification gate. |
| func TestAccountsCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| // The subprocess must never see the operator's real ~/.carlos — a genuine |
| @@ -923,17 +939,8 @@ func TestAccountsCLI(t *testing.T) { |
| // RUNTIME does (qualified wins per key), say that it saw both, and verify |
| // afterwards that what the destination now serves is what the source served. |
| func TestAccountsMigrateTakesTheLiveObjects(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
| @@ -1089,17 +1096,8 @@ func TestAccountsMigrateTakesTheLiveObjects(t *testing.T) { |
| // (verifyMigratedPointers checks channel pointers, not this). The verb skips |
| // it and says so, loudly, because the alternative failure is invisible. |
| func TestAccountsMigrateDoesNotCopyTheProductionFlag(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
| @@ -1193,17 +1191,8 @@ func TestAccountsMigrateDoesNotCopyTheProductionFlag(t *testing.T) { |
| // end: the re-run would hit the create-only copy and die at "already exists |
| // with different content", so the instruction forbade the only exit. |
| func TestAccountsMigrateConvergesADivergedPointer(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
| @@ -1311,17 +1300,8 @@ func TestAccountsMigrateConvergesADivergedPointer(t *testing.T) { |
| // unenforced (still the operator's call), and -db always persists onto the |
| // route when given. |
| func TestAddUnitBackingRequiresDBForHibernate(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", out, err) |
| - } |
| + carlosBin := sharedCarlos(t) |
| regPath := filepath.Join(tmp, "registry.db") |
| @@ -1392,17 +1372,8 @@ func TestAddUnitBackingRequiresDBForHibernate(t *testing.T) { |
| // discoverable only by correlating 503s with child stderr in the journal |
| // (issue #70, vitogo's first deploy). |
| func TestAddRefusesRelativeDBOnExecRoutes(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| regPath := filepath.Join(tmp, "registry.db") |
| run := func(args ...string) (string, error) { |
| @@ -1471,17 +1442,8 @@ func TestAddRefusesRelativeDBOnExecRoutes(t *testing.T) { |
| // (accounts_resolve_test.go); the refusal itself is log.Fatal, so only a |
| // real subprocess can observe the exit status and the absent row. |
| func TestAddAccountIDRefusesAName(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| regPath := filepath.Join(tmp, "registry.db") |
| out, err := exec.Command(carlosBin, "add", "-registry", regPath, "-app", "kass", |
| @@ -1545,17 +1507,8 @@ func TestAddAccountIDRefusesAName(t *testing.T) { |
| // incident (issue #69) started with `added vito.platform.tito.io` printed |
| // over what was actually a rewrite of an existing row. |
| func TestAddOnExistingRouteSaysUpdated(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| regPath := filepath.Join(tmp, "registry.db") |
| run := func(args ...string) (string, error) { |
| @@ -1606,17 +1559,8 @@ func TestAddOnExistingRouteSaysUpdated(t *testing.T) { |
| // That left every ops app stranded on legacy keys and made the read-fallback |
| // impossible to retire. |
| func TestAccountsMigrateLegacyIntoOps(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
| @@ -1740,17 +1684,8 @@ func TestAccountsMigrateLegacyIntoOps(t *testing.T) { |
| } |
| func TestEnvCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| env := carlosTestEnv(t, "CARLOS_DEPLOYMENT_DIR="+storeDir) |
| @@ -1793,17 +1728,8 @@ func TestEnvCLI(t *testing.T) { |
| } |
| func TestSecretsCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| baseEnv := carlosTestEnv(t) |
| @@ -1874,17 +1800,8 @@ func TestSecretsCLI(t *testing.T) { |
| // key, created implicitly on first `set` exactly like the default bundle — |
| // and never touched by a write to the other. |
| func TestEnvironmentBundlesCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| env := carlosTestEnv(t, "CARLOS_DEPLOYMENT_DIR="+storeDir) |
| run := func(args ...string) string { |
| @@ -2026,17 +1943,8 @@ func TestEnvironmentBundlesCLI(t *testing.T) { |
| // clearing words refusing each other's ("off" vs "inherit"), following |
| // TestEnvCLI's build-a-real-binary pattern. |
| func TestExecDeliveryCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| env := carlosTestEnv(t, "CARLOS_DEPLOYMENT_DIR="+storeDir) |
| run := func(args ...string) string { |
| @@ -2173,17 +2081,8 @@ func TestExecDeliveryCLI(t *testing.T) { |
| // route bound to that environment would actually receive has the override |
| // applied and everything else inherited from default. |
| func TestEnvironmentMergeVisibleFromCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| env := carlosTestEnv(t, "CARLOS_DEPLOYMENT_DIR="+storeDir) |
| run := func(args ...string) { |
| @@ -2239,17 +2138,8 @@ func TestEnvironmentMergeVisibleFromCLI(t *testing.T) { |
| // that must never happen by accident (the keymail.dev canary/keymail -> |
| // stable move this verb was built for). |
| func TestRouteCLI(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
| @@ -2550,17 +2440,8 @@ type routeTestFixture struct { |
| func newRouteTestFixture(t *testing.T) *routeTestFixture { |
| t.Helper() |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - bin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", bin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + bin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| seed, pubB64, err := release.GenerateKey() |
| if err != nil { |
| @@ -3550,17 +3431,8 @@ func TestRouteNeitherChannelNorEnvironmentIsUsageError(t *testing.T) { |
| // caught only because the next adopt pass printed the downgrade. The verb |
| // now keeps a differing qualified pointer and says so. |
| func TestAccountsMigrateLegacyKeepsNewerQualifiedPointer(t *testing.T) { |
| - goBin, err := exec.LookPath("go") |
| - if err != nil { |
| - t.Skip("go toolchain not found") |
| - } |
| tmp := t.TempDir() |
| - carlosBin := filepath.Join(tmp, "carlos") |
| - build := exec.Command(goBin, "build", "-o", carlosBin, ".") |
| - build.Env = os.Environ() |
| - if out, err := build.CombinedOutput(); err != nil { |
| - t.Fatalf("build carlos: %v\n%s", err, out) |
| - } |
| + carlosBin := sharedCarlos(t) |
| storeDir := filepath.Join(tmp, "store") |
| regPath := filepath.Join(tmp, "registry.db") |
| store := release.NewDirStore(storeDir) |
diff --git a/export_test.go b/export_test.go| new file mode 100644 |
| index 000000000..c8b4baa6a |
| --- /dev/null |
| +++ b/export_test.go |
| @@ -0,0 +1,15 @@ |
| +package main |
| + |
| +import "testing" |
| + |
| +// SharedCarlosForTest hands the one shared carlos build (sharedCarlos, |
| +// auth_e2e_test.go) to the external test package, package main_test, which |
| +// cannot see unexported names. Two copies of the build would be two Onces |
| +// that disagree about whether it failed. |
| +func SharedCarlosForTest(t testing.TB) string { |
| + t.Helper() |
| + return sharedCarlos(t) |
| +} |
| + |
| +// SharedCarlosBuildsForTest is how many times this process has built it. |
| +func SharedCarlosBuildsForTest() int { return int(carlosBuilds.Load()) } |
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 b56965763..fbe046f3d 100644 |
| --- a/internal/provision/plan14_root_reads_test.go |
| +++ b/internal/provision/plan14_root_reads_test.go |
| @@ -1034,6 +1034,20 @@ 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" |
| 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 5b08dd5dd..4b065caba 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-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 |
diff --git a/internal/sim/litestreamfacts/facts_test.go b/internal/sim/litestreamfacts/facts_test.go| index 2f76c6e5c..f66168944 100644 |
| --- a/internal/sim/litestreamfacts/facts_test.go |
| +++ b/internal/sim/litestreamfacts/facts_test.go |
| @@ -817,7 +817,19 @@ func TestGate_AnchoredLineageThroughStore(t *testing.T) { |
| for _, lvl := range []int{1, 2, 3} { |
| waitFor(t, fmt.Sprintf("a level-%d compaction", lvl), 5*time.Second, func() bool { return len(files(t, gen, lvl)) > 0 }) |
| } |
| - waitFor(t, "snapshot retention", 5*time.Second, func() bool { return len(files(t, gen, 9)) == 1 }) |
| + // Retention is awaited at the state that lasts: one snapshot, at the |
| + // round's final position. One snapshot alone can be a moment in |
| + // passing. The monitor snapshots every interval and keeps the previous |
| + // snapshot while it is younger than the retention, so a tick that runs |
| + // 100 ms late removes the previous one and leaves a single snapshot |
| + // that is behind the position; the next tick adds the final snapshot |
| + // beside it, and a round that had stopped waiting closed the store |
| + // with two (#266). Once the only snapshot is at the final position a |
| + // later tick can only rewrite that same file. |
| + waitFor(t, "snapshot retention", 5*time.Second, func() bool { |
| + l9 := files(t, gen, 9) |
| + return len(l9) == 1 && int(l9[0].MaxTXID) == pos |
| + }) |
| waitFor(t, "level-0 expiry", 5*time.Second, func() bool { return len(files(t, gen, 0)) < l0Before+8 }) |
| if err := store.Close(ctx); err != nil { |
| t.Fatal(err) |
diff --git a/internal/stopevidence/fdholders_alias_linux_test.go b/internal/stopevidence/fdholders_alias_linux_test.go| index b0ee488ce..002a827d1 100644 |
| --- a/internal/stopevidence/fdholders_alias_linux_test.go |
| +++ b/internal/stopevidence/fdholders_alias_linux_test.go |
| @@ -3,8 +3,10 @@ |
| package stopevidence |
| import ( |
| + "bufio" |
| "context" |
| "errors" |
| + "fmt" |
| "io/fs" |
| "os" |
| "os/exec" |
| @@ -17,21 +19,62 @@ import ( |
| "time" |
| ) |
| -// holdOpen starts a child that holds path open as descriptor 3 and sleeps. |
| +// heldAndQuiet ends every holder's script: the shell says it has finished |
| +// starting, then blocks in its own read on a pipe nothing is written to. |
| +// |
| +// A scan must not meet a holder that is still starting. A process that has |
| +// just been exec'd opens and closes the linker cache, libc and the locale |
| +// files in turn, each on the first free descriptor. A scan that reads one of |
| +// them between its close and the next open sees a descriptor whose stat says |
| +// gone and whose entry is there, which is ErrIncomplete by design |
| +// (TestFDHoldersStatGoneWhileTheEntryRemains). The holders here used to be |
| +// `sleep 60`, scanned as soon as it was started, and the hard-link test |
| +// failed that way once under load (#274). |
| +const heldAndQuiet = "echo ready && read wait" |
| + |
| +// startHolder starts cmd, a shell whose script ends in heldAndQuiet, and |
| +// returns its pid once it has said ready. An error means it never did. |
| +func startHolder(t *testing.T, cmd *exec.Cmd) (int, error) { |
| + t.Helper() |
| + // Wait closes this end, and until then the child's read has nothing. |
| + if _, err := cmd.StdinPipe(); err != nil { |
| + t.Fatal(err) |
| + } |
| + r, w, err := os.Pipe() |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + defer r.Close() |
| + cmd.Stdout = w |
| + err = cmd.Start() |
| + w.Close() |
| + if err != nil { |
| + return 0, err |
| + } |
| + t.Cleanup(func() { cmd.Process.Kill(); cmd.Wait() }) |
| + r.SetReadDeadline(time.Now().Add(10 * time.Second)) |
| + if line, err := bufio.NewReader(r).ReadString('\n'); line != "ready\n" { |
| + return 0, fmt.Errorf("the holder said %q before it stopped: %v", line, err) |
| + } |
| + return cmd.Process.Pid, nil |
| +} |
| + |
| +// holdOpen starts a child that holds path open as descriptor 3 and opens |
| +// nothing more. |
| func holdOpen(t *testing.T, path string) int { |
| t.Helper() |
| f, err := os.Open(path) |
| if err != nil { |
| t.Fatal(err) |
| } |
| - cmd := exec.Command("sleep", "60") |
| + defer f.Close() |
| + cmd := exec.Command("sh", "-c", heldAndQuiet) |
| cmd.ExtraFiles = []*os.File{f} |
| - if err := cmd.Start(); err != nil { |
| + pid, err := startHolder(t, cmd) |
| + if err != nil { |
| t.Fatal(err) |
| } |
| - f.Close() |
| - t.Cleanup(func() { cmd.Process.Kill(); cmd.Wait() }) |
| - return cmd.Process.Pid |
| + return pid |
| } |
| // projectPIDs is a scan root holding only these processes' real /proc |
| @@ -124,35 +167,16 @@ func TestFDIdentityFindsAHolderInAnotherMountNamespace(t *testing.T) { |
| t.Fatal(err) |
| } |
| aliased := filepath.Join(alias, filepath.Base(db)) |
| + // The shell opens the database on descriptor 3 itself, after the mount, |
| + // and says ready only then: until that point descriptor 3 can be some |
| + // other file (the dynamic loader's libc, while unshare or sh starts). |
| cmd := exec.Command("unshare", "--user", "--map-root-user", "--mount", "sh", "-c", |
| - `mount --bind "$1" "$2" && exec sleep 60 3<"$3"`, "sh", filepath.Join(dir, "real"), alias, aliased) |
| - if err := cmd.Start(); err != nil { |
| - t.Skip("cannot start unshare:", err) |
| - } |
| - t.Cleanup(func() { cmd.Process.Kill(); cmd.Wait() }) |
| - pid := cmd.Process.Pid |
| - fd3 := filepath.Join("/proc", strconv.Itoa(pid), "fd", "3") |
| - // Until sh has run the mount and exec'd sleep, fd 3 can be some other |
| - // file (the dynamic loader's libc, while unshare or sh starts), so wait |
| - // for fd 3 to be the database itself, by identity: stat through the |
| - // magic link reaches the file the descriptor holds in any namespace. |
| - want, err := os.Stat(db) |
| + `mount --bind "$1" "$2" && exec 3<"$3" && `+heldAndQuiet, "sh", filepath.Join(dir, "real"), alias, aliased) |
| + pid, err := startHolder(t, cmd) |
| if err != nil { |
| - t.Fatal(err) |
| - } |
| - var target string |
| - held := false |
| - for deadline := time.Now().Add(5 * time.Second); time.Now().Before(deadline); time.Sleep(20 * time.Millisecond) { |
| - if fi, err := os.Stat(fd3); err == nil && os.SameFile(fi, want) { |
| - target, _ = os.Readlink(fd3) |
| - held = true |
| - break |
| - } |
| - } |
| - if !held { |
| - t.Skip("the namespace holder never came up holding the database (unprivileged user namespaces refused?)") |
| + t.Skip("the namespace holder never came up holding the database (unprivileged user namespaces refused?):", err) |
| } |
| - if target != aliased { |
| + if target, _ := os.Readlink(filepath.Join("/proc", strconv.Itoa(pid), "fd", "3")); target != aliased { |
| t.Logf("descriptor text %q (expected the bind path %q)", target, aliased) |
| } |
| root := projectPIDs(t, pid) |
diff --git a/main_test.go b/main_test.go| index b8711d2d9..1d6cc7c00 100644 |
| --- a/main_test.go |
| +++ b/main_test.go |
| @@ -1,16 +1,414 @@ |
| package main |
| import ( |
| + "errors" |
| + "fmt" |
| "os" |
| + "os/exec" |
| + "path/filepath" |
| + "runtime" |
| + "strings" |
| "testing" |
| ) |
| -// TestMain keeps an exported deploy token out of the root package's tests. |
| -// resolveMode reads CARLOS_SERVICE_TOKEN, and a CI shell running `go test` |
| -// may well export one. In-process tests that call run() or a verb directly |
| -// would then inherit it. Tests that want a token set it with t.Setenv, which |
| -// still works after this Unsetenv. |
| +// TestMain keeps the operator's own state out of the root package's tests. |
| +// |
| +// Three exported variables are dropped before any test runs. No shared |
| +// helper pins all three, and each steers a test that calls run() or a verb |
| +// directly, and every child that inherits os.Environ(). A test that wants |
| +// one sets it with t.Setenv, which still works after an Unsetenv. |
| +// |
| +// - CARLOS_SERVICE_TOKEN: resolveMode reads it, and a CI shell running |
| +// `go test` may well export one. |
| +// - CARLOS_CONFIG: it names the one config file read and switches |
| +// discovery off, so with it exported every test that relies on its |
| +// scratch directory holding no config reads the developer's file |
| +// instead, and ships to the console it names. |
| +// - CARLOS_DESTINATION: it selects a block in whatever config a test |
| +// wrote, and a config that does not define it is an error. |
| +// |
| +// CARLOS_CONSOLE and CARLOS_CREDENTIALS stay: the shared helpers pin both. |
| +// HOME stays too, because the tests' own `go build` needs the real one. |
| +// |
| +// The operator's .carlos/config: see isolateTempRoot. The binary refuses to |
| +// run rather than work under one. |
| func TestMain(m *testing.M) { |
| - os.Unsetenv("CARLOS_SERVICE_TOKEN") |
| - os.Exit(m.Run()) |
| + for _, name := range []string{"CARLOS_SERVICE_TOKEN", "CARLOS_CONFIG", "CARLOS_DESTINATION"} { |
| + os.Unsetenv(name) |
| + } |
| + // /var/tmp alone. /tmp is not offered: the tests build binaries into |
| + // the temp root, and on a machine where /tmp is shared memory the move |
| + // would put them there without anyone having asked. |
| + moved, cleanup, err := isolateTempRoot([]string{"/var/tmp"}) |
| + if err != nil { |
| + fmt.Fprintln(os.Stderr, err) |
| + os.Exit(1) |
| + } |
| + if moved != "" { |
| + fmt.Fprintln(os.Stderr, moved) |
| + } |
| + // The shared carlos binary (sharedCarlos) is built lazily and its |
| + // directory made by the build. What is fixed here, after isolateTempRoot |
| + // and before any test can change directory or HOME: the module to build, |
| + // the environment to build in, and where the directory goes. GOTMPDIR |
| + // first, because that is where t.TempDir() puts things. |
| + moduleRoot, _ = os.Getwd() |
| + carlosBuildEnv = os.Environ() |
| + if carlosTmpParent = os.Getenv("GOTMPDIR"); carlosTmpParent == "" { |
| + carlosTmpParent = os.TempDir() |
| + } |
| + code := m.Run() |
| + if carlosDir != "" { |
| + os.RemoveAll(carlosDir) |
| + } |
| + cleanup() |
| + os.Exit(code) |
| +} |
| + |
| +// tempRootPrefix names the directory isolateTempRoot makes. Its cleanup runs |
| +// only when the tests return: a log.Fatal, a panic or a timeout leaves that |
| +// one directory behind, and the line TestMain prints says where it is. |
| +const tempRootPrefix = "carlos-test-" |
| + |
| +// isolateTempRoot makes sure no .carlos/config sits above the directories |
| +// the tests' scratch space comes from, before any test asks for one. |
| +// |
| +// The tests pin HOME, but the CLI's config discovery (config.go |
| +// walkConfigFiles) walks up from the working directory, and that directory |
| +// is a t.TempDir() for every test that uses useTempCredentials or runs the |
| +// binary from a scratch cmd.Dir. Where the temp root is inside a logged-in |
| +// operator's home (TMPDIR=~/.cache/tmp/..., the default in a sandboxed agent |
| +// session) the walk reached the real ~/.carlos/config: two dozen tests |
| +// failed with "not logged in" to the operator's console, and one offered a |
| +// re-login to it and waited ten minutes (#226, #258). Pinning CARLOS_CONFIG |
| +// in the shared helpers is not the fix, because it switches discovery off |
| +// for the tests that write a .carlos/config of their own. |
| +// |
| +// There are two roots. os.TempDir() is TMPDIR. t.TempDir() is GOTMPDIR |
| +// when that is set and os.TempDir() only when it is not (testing.go |
| +// makeTempDir: os.MkdirTemp(os.Getenv("GOTMPDIR"), pattern)), so a clear |
| +// TMPDIR says nothing about a GOTMPDIR under a home. |
| +// |
| +// Roots with nothing above them are left alone, which is every CI run. |
| +// Otherwise the tests get one fresh directory under the first of bases that |
| +// is clear, and each variable whose root was not clear is pointed at it, so |
| +// child processes follow. An explicit GOTMPDIR is pointed there rather than |
| +// cleared: cleared, t.TempDir() would fall back to TMPDIR, which may be the |
| +// very place the developer set GOTMPDIR to keep the tests' binaries off. |
| +// moved says where, and the returned cleanup removes it. When no directory |
| +// can be made the variables are put back, the error names the ones to set, |
| +// and TestMain stops. |
| +func isolateTempRoot(bases []string) (moved string, cleanup func(), err error) { |
| + var why, names []string |
| + if p := configAbove(os.TempDir()); p != "" { |
| + why = append(why, fmt.Sprintf("%s is above the temp directory %s", p, os.TempDir())) |
| + names = append(names, "TMPDIR") |
| + } |
| + if root := os.Getenv("GOTMPDIR"); root != "" { |
| + if p := configAbove(root); p != "" { |
| + why = append(why, fmt.Sprintf("%s is above GOTMPDIR %s", p, root)) |
| + names = append(names, "GOTMPDIR") |
| + } |
| + } |
| + if len(names) == 0 { |
| + return "", func() {}, nil |
| + } |
| + type was struct { |
| + value string |
| + set bool |
| + } |
| + before := map[string]was{} |
| + for _, name := range names { |
| + v, ok := os.LookupEnv(name) |
| + before[name] = was{v, ok} |
| + } |
| + for _, base := range bases { |
| + dir, err := os.MkdirTemp(base, tempRootPrefix) |
| + if err != nil { |
| + continue |
| + } |
| + for _, name := range names { |
| + os.Setenv(name, dir) |
| + } |
| + // Asked of both roots again rather than assumed: the base may sit |
| + // under a config too, and not every platform reads TMPDIR. |
| + if configAbove(os.TempDir()) == "" && configAbove(os.Getenv("GOTMPDIR")) == "" { |
| + moved = fmt.Sprintf("carlos tests: %s, so the tests work in %s instead (an aborted run leaves it behind)", strings.Join(why, " and "), dir) |
| + return moved, func() { os.RemoveAll(dir) }, nil |
| + } |
| + os.Remove(dir) |
| + for name, w := range before { |
| + if w.set { |
| + os.Setenv(name, w.value) |
| + } else { |
| + os.Unsetenv(name) |
| + } |
| + } |
| + } |
| + return "", nil, fmt.Errorf("carlos tests: %s, and the CLI's config walk would read it. No directory could be made under %s to work in instead: set %s to a directory with no .carlos/config above it", |
| + strings.Join(why, " and "), strings.Join(bases, " or "), strings.Join(names, " and ")) |
| +} |
| + |
| +// configAbove is the first .carlos/config the CLI's discovery would read |
| +// walking up from dir, "" when there is none or dir is "". The walk is over |
| +// the path as written, which is what discovery follows after a t.Chdir, and |
| +// over the path with its symlinks resolved, which is what it follows when |
| +// PWD is unset. Anything but "does not exist" counts as there: discovery |
| +// fails on a config it cannot read. |
| +func configAbove(dir string) string { |
| + if dir == "" { |
| + return "" |
| + } |
| + if abs, err := filepath.Abs(dir); err == nil { |
| + dir = abs |
| + } |
| + starts := []string{dir} |
| + if resolved, err := filepath.EvalSymlinks(dir); err == nil && resolved != dir { |
| + starts = append(starts, resolved) |
| + } |
| + for _, d := range starts { |
| + for { |
| + path := filepath.Join(d, ".carlos", "config") |
| + if _, err := os.Stat(path); !errors.Is(err, os.ErrNotExist) { |
| + return path |
| + } |
| + parent := filepath.Dir(d) |
| + if parent == d { |
| + break |
| + } |
| + d = parent |
| + } |
| + } |
| + return "" |
| +} |
| + |
| +// TestMain's own promises, read back from inside a test: neither root has a |
| +// config above it, and none of the variables it drops came through. |
| +func TestMainLeavesNoOperatorState(t *testing.T) { |
| + for _, root := range []string{os.TempDir(), os.Getenv("GOTMPDIR"), t.TempDir()} { |
| + if p := configAbove(root); p != "" { |
| + t.Errorf("TestMain let the tests run with %s above %s", p, root) |
| + } |
| + } |
| + for _, name := range []string{"CARLOS_SERVICE_TOKEN", "CARLOS_CONFIG", "CARLOS_DESTINATION"} { |
| + if v, ok := os.LookupEnv(name); ok { |
| + t.Errorf("%s=%q reached the tests", name, v) |
| + } |
| + } |
| +} |
| + |
| +// The guard, against a tree of its own. A root under a config moves to the |
| +// first base that is clear: TMPDIR, GOTMPDIR or both, whichever was under |
| +// it, and only those. The cleanup removes the directory and nothing else. |
| +// With no clear base the binary is told to stop and what to set. |
| +func TestIsolateTempRoot(t *testing.T) { |
| + if runtime.GOOS == "windows" { |
| + t.Skip("os.TempDir does not read TMPDIR on windows, so there is no moving it") |
| + } |
| + home := t.TempDir() |
| + planted := writeConfig(t, home, `{"console": "https://operator.example"}`) |
| + under := filepath.Join(home, "cache", "tmp") |
| + alsoUnder := filepath.Join(home, "var") |
| + clear, otherClear := t.TempDir(), t.TempDir() |
| + for _, d := range []string{under, alsoUnder} { |
| + if err := os.MkdirAll(d, 0o755); err != nil { |
| + t.Fatal(err) |
| + } |
| + } |
| + if got := configAbove(under); got != planted { |
| + t.Fatalf("configAbove(%s) = %q, want %s", under, got, planted) |
| + } |
| + bases := []string{filepath.Join(home, "missing"), alsoUnder, clear} |
| + |
| + for _, c := range []struct { |
| + name string |
| + tmpdir, gotmp string // as the run starts; "" is unset |
| + moveTmp bool |
| + moveGo bool |
| + }{ |
| + {"TMPDIR under a config, no GOTMPDIR", under, "", true, false}, |
| + {"TMPDIR under a config, GOTMPDIR clear", under, otherClear, true, false}, |
| + {"GOTMPDIR under a config, TMPDIR clear", otherClear, under, false, true}, |
| + {"both under a config", under, alsoUnder, true, true}, |
| + } { |
| + t.Run(c.name, func(t *testing.T) { |
| + t.Setenv("TMPDIR", c.tmpdir) |
| + t.Setenv("GOTMPDIR", c.gotmp) |
| + said, cleanup, err := isolateTempRoot(bases) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + made, _ := os.ReadDir(clear) |
| + if len(made) != 1 || !strings.HasPrefix(made[0].Name(), tempRootPrefix) { |
| + t.Fatalf("the clear base holds %v, want one %s directory", made, tempRootPrefix) |
| + } |
| + moved := filepath.Join(clear, made[0].Name()) |
| + wantTmp, wantGo := c.tmpdir, c.gotmp |
| + if c.moveTmp { |
| + wantTmp = moved |
| + } |
| + if c.moveGo { |
| + wantGo = moved |
| + } |
| + if os.TempDir() != wantTmp || os.Getenv("GOTMPDIR") != wantGo { |
| + t.Fatalf("TMPDIR=%s GOTMPDIR=%s, want %s and %s", os.TempDir(), os.Getenv("GOTMPDIR"), wantTmp, wantGo) |
| + } |
| + if !strings.Contains(said, planted) || !strings.Contains(said, moved) || |
| + strings.Contains(said, "above GOTMPDIR") != c.moveGo || strings.Contains(said, "above the temp directory") != c.moveTmp { |
| + t.Fatalf("said %q, want %s, %s and the roots that moved", said, planted, moved) |
| + } |
| + // What the guard is for: a test's own temp directory is clear now. |
| + t.Run("a test's temp directory", func(t *testing.T) { |
| + if p := configAbove(t.TempDir()); p != "" { |
| + t.Fatalf("t.TempDir() is still under %s", p) |
| + } |
| + }) |
| + if left, _ := os.ReadDir(alsoUnder); len(left) != 0 { |
| + t.Fatalf("the refused base kept %v", left) |
| + } |
| + cleanup() |
| + if _, err := os.Stat(moved); !errors.Is(err, os.ErrNotExist) { |
| + t.Fatalf("the cleanup left %s (%v)", moved, err) |
| + } |
| + if _, err := os.Stat(clear); err != nil { |
| + t.Fatalf("the cleanup took the base with it: %v", err) |
| + } |
| + }) |
| + } |
| + |
| + // No clear base: an error naming the config and each variable to set, |
| + // with both variables as they were. |
| + t.Setenv("TMPDIR", otherClear) |
| + t.Setenv("GOTMPDIR", under) |
| + _, _, err := isolateTempRoot([]string{alsoUnder}) |
| + if err == nil || !strings.Contains(err.Error(), planted) || !strings.Contains(err.Error(), "set GOTMPDIR to") { |
| + t.Fatalf("no clear base = %v, want an error naming %s and GOTMPDIR", err, planted) |
| + } |
| + if os.TempDir() != otherClear || os.Getenv("GOTMPDIR") != under { |
| + t.Fatalf("a refusal left TMPDIR=%s GOTMPDIR=%s", os.TempDir(), os.Getenv("GOTMPDIR")) |
| + } |
| + t.Setenv("TMPDIR", under) |
| + if _, _, err := isolateTempRoot([]string{alsoUnder}); err == nil || !strings.Contains(err.Error(), "set TMPDIR and GOTMPDIR to") { |
| + t.Fatalf("no clear base, both roots = %v, want both variables named", err) |
| + } |
| + if left, _ := os.ReadDir(alsoUnder); len(left) != 0 { |
| + t.Fatalf("the refused base kept %v", left) |
| + } |
| + |
| + // Clear roots are not moved at all. |
| + t.Setenv("TMPDIR", clear) |
| + t.Setenv("GOTMPDIR", otherClear) |
| + if said, _, err := isolateTempRoot([]string{filepath.Join(home, "missing")}); err != nil || said != "" || os.TempDir() != clear || os.Getenv("GOTMPDIR") != otherClear { |
| + t.Fatalf("clear roots = %s, %s, %q, %v; want them left alone", os.TempDir(), os.Getenv("GOTMPDIR"), said, err) |
| + } |
| +} |
| + |
| +// The shared binary is one file, found at one path, that is executable and |
| +// that nothing can write to, and it lives inside the directory the build |
| +// made under the temp root. Asked for from a test that has left the module, |
| +// it still builds, and it is built once for the whole process, whichever |
| +// package asked (TestSharedCarlosFromTheExternalPackage asks from the other). |
| +func TestSharedCarlos(t *testing.T) { |
| + if testing.Short() { |
| + t.Skip("builds a binary") |
| + } |
| + t.Chdir(t.TempDir()) |
| + first, second := sharedCarlos(t), sharedCarlos(t) |
| + if first != second { |
| + t.Fatalf("two calls gave %s and %s, want one path", first, second) |
| + } |
| + if n := carlosBuilds.Load(); n != 1 { |
| + t.Errorf("%d builds in this process, want 1", n) |
| + } |
| + info, err := os.Stat(first) |
| + if err != nil { |
| + t.Fatal(err) |
| + } |
| + if runtime.GOOS != "windows" && info.Mode().Perm() != 0o555 { |
| + t.Errorf("mode %v, want r-xr-xr-x: executable and not writable", info.Mode().Perm()) |
| + } |
| + if first != filepath.Join(carlosDir, "carlos") { |
| + t.Errorf("%s is not in the directory the build made, %s", first, carlosDir) |
| + } |
| + if rel, err := filepath.Rel(carlosTmpParent, first); err != nil || strings.HasPrefix(rel, "..") { |
| + t.Errorf("%s is not under %s", first, carlosTmpParent) |
| + } |
| + if os.Geteuid() != 0 { |
| + if f, err := os.OpenFile(first, os.O_WRONLY, 0); err == nil { |
| + f.Close() |
| + t.Error("the shared binary opened for writing") |
| + } |
| + } |
| +} |
| + |
| +// A failed build is the answer for every caller, not just the first: the |
| +// build runs once and its error is kept. |
| +func TestSharedCarlosKeepsABuildFailure(t *testing.T) { |
| + var s carlosShared |
| + builds := 0 |
| + failing := func() (string, error) { |
| + builds++ |
| + return "", errors.New("compile error in the module") |
| + } |
| + for i := 0; i < 3; i++ { |
| + if path, err := s.get(failing); path != "" || err == nil || !strings.Contains(err.Error(), "compile error") { |
| + t.Fatalf("call %d = %q, %v; want the build's error", i, path, err) |
| + } |
| + } |
| + if builds != 1 { |
| + t.Fatalf("the failing build ran %d times, want 1", builds) |
| + } |
| +} |
| + |
| +// Where the directory goes, and when it is made, read from a re-executed test |
| +// binary with scratch roots of its own. GOTMPDIR wins over TMPDIR, as it does |
| +// for t.TempDir(), so the binary is not put on a shared RAM disk that TMPDIR |
| +// names. A process that never asks for the binary makes nothing at all. |
| +// Either way the roots are empty again once the process has exited. |
| +func TestSharedCarlosLocation(t *testing.T) { |
| + if os.Getenv("CARLOS_SHARED_CHILD") != "" { |
| + fmt.Println("SHARED_CARLOS=" + sharedCarlos(t)) |
| + return |
| + } |
| + if testing.Short() { |
| + t.Skip("builds a binary") |
| + } |
| + // The child skips without a toolchain and prints no path; say so here |
| + // rather than fail on the missing line. |
| + if _, err := exec.LookPath("go"); err != nil { |
| + t.Skip("go toolchain not on PATH") |
| + } |
| + run := func(args ...string) (tmp, gotmp, out string) { |
| + t.Helper() |
| + tmp, gotmp = t.TempDir(), t.TempDir() |
| + cmd := exec.Command(os.Args[0], args...) |
| + cmd.Dir = moduleRoot |
| + cmd.Env = append(os.Environ(), "TMPDIR="+tmp, "GOTMPDIR="+gotmp, "CARLOS_SHARED_CHILD=1") |
| + b, err := cmd.CombinedOutput() |
| + if err != nil { |
| + t.Fatalf("child %v: %v\n%s", args, err, b) |
| + } |
| + for _, root := range []string{tmp, gotmp} { |
| + if left, _ := os.ReadDir(root); len(left) != 0 { |
| + t.Errorf("the child left %v in %s", left, root) |
| + } |
| + } |
| + return tmp, gotmp, string(b) |
| + } |
| + |
| + _, _, out := run("-test.run=^$") |
| + if strings.Contains(out, "SHARED_CARLOS=") { |
| + t.Fatalf("a child that ran no test built the binary:\n%s", out) |
| + } |
| + |
| + tmp, gotmp, out := run("-test.run=^TestSharedCarlosLocation$") |
| + var path string |
| + for _, line := range strings.Split(out, "\n") { |
| + if p, ok := strings.CutPrefix(line, "SHARED_CARLOS="); ok { |
| + path = p |
| + } |
| + } |
| + if path == "" || !strings.HasPrefix(path, gotmp+string(filepath.Separator)) { |
| + t.Errorf("the binary is at %q, want it under GOTMPDIR %s (TMPDIR was %s)", path, gotmp, tmp) |
| + } |
| } |