carlos / platform Public

host: large-box startup test, review round 2 (#281 ask 2)

Astra's re-review of 7e16dd01, both findings in the test:

- The wiring guard checked text order, so `go recoverLayoutAtStart(...)`
  and `func() { <-startupDone }()` before the edge both passed. It now
  orders only calls made on the function's own goroutine (none in a go or
  defer statement, none in a function literal unless it is invoked on the
  spot) and matches callees by their own name. Each step the child copies
  must be called that way: runAgent's latch, Run, edge, cancel, join and
  Shutdown; Recover's three calls; Sweep and Ready. Inside the one
  background goroutine activatorStart.Run starts (found as the go
  statement that runs startActivator), startActivator comes before the key
  pass. startActivator calls its sweep, recover and start parameters in
  order (matched by position), the start closure calls Start then Ready,
  and recoverLayoutAtStart calls Recover then RestoreHolds. A closure
  invoked on the spot before the edge is searched for waits like the rest
  of runAgent's body.
- A missed listen deadline was retried if the log also showed a bind
  failure. Retrying is now decided by largeBoxRetryable: only an agent that
  exited, with an edge listener line naming one of the test's own
  addresses as in use. A deadline is checked before an exit and never
  retried; TestLargeBoxRetriesOnlyItsOwnBindFailure pins that.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
claude agent, operated by paul@keymail.dev 6662ee8c05c472177d4ba73660b5e984fbbc3a07 parent 7e16dd0
1 file changed, +329 −169
  • internal/host/startup_largebox_linux_test.go +329 −169

CI cancelled — superseded by a newer push — run details

diff --git a/internal/host/startup_largebox_linux_test.go b/internal/host/startup_largebox_linux_test.go
index b23550fa0..58410ee4a 100644
--- a/internal/host/startup_largebox_linux_test.go
+++ b/internal/host/startup_largebox_linux_test.go
@@ -363,14 +363,18 @@ func testLargeBoxShutdownMidStartup(t *testing.T) {
// --- runAgent's wiring ------------------------------------------------------------
-// TestRunAgentStartupWiring reads runAgent's source and fails if its
-// startup wiring drifts from what runLargeBoxAgent rebuilds, or if
-// anything on runAgent's path to the edge waits for startup to finish.
-// It checks structure, not text, so comments, formatting and unrelated
-// statements can change freely.
+// TestRunAgentStartupWiring reads the startup's source and fails if it
+// drifts from what runLargeBoxAgent rebuilds, or if anything on runAgent's
+// path to the edge waits for startup to finish. Calls are matched on the
+// callee's own name (a selector's Sel), and order means execution order on
+// one goroutine: a step inside a go or defer statement, or inside a
+// function literal that is not invoked on the spot, does not count as
+// taken. Where the hotfix does mean a step to run in the background, the
+// one goroutine it runs on is found structurally and its order checked
+// inside it.
func TestRunAgentStartupWiring(t *testing.T) {
fset := token.NewFileSet()
- var fn *ast.FuncDecl
+ decls := map[string]*ast.FuncDecl{} // runAgent, startActivator, recoverLayoutAtStart, activatorStart.Run
files, err := filepath.Glob("*.go")
if err != nil {
t.Fatal(err)
@@ -384,97 +388,81 @@ func TestRunAgentStartupWiring(t *testing.T) {
t.Fatal(err)
}
for _, d := range f.Decls {
- if fd, ok := d.(*ast.FuncDecl); ok && fd.Recv == nil && fd.Name.Name == "runAgent" {
- fn = fd
+ fd, ok := d.(*ast.FuncDecl)
+ if !ok {
+ continue
+ }
+ key := fd.Name.Name
+ if fd.Recv != nil && len(fd.Recv.List) == 1 {
+ key = types.ExprString(fd.Recv.List[0].Type) + "." + key
+ }
+ switch key {
+ case "runAgent", "startActivator", "recoverLayoutAtStart", "activatorStart.Run":
+ decls[key] = fd
}
}
}
- if fn == nil {
- t.Fatal("runAgent not found in package host")
+ for _, key := range []string{"runAgent", "startActivator", "recoverLayoutAtStart", "activatorStart.Run"} {
+ if decls[key] == nil {
+ t.Fatalf("%s not found in package host", key)
+ }
}
str := types.ExprString
- // The calls and statements this test anchors on, by position.
- var (
- run *ast.CallExpr // activatorStart{...}.Run(startupCtx)
- lit *ast.CompositeLit // its activatorStart literal
- edgeCall *ast.CallExpr // edge.RunWithActivatorReady(...)
- latch token.Pos // svc.Startup = started
- cancels []token.Pos // cancelStartup() (a defer of it comes first)
- joins []token.Pos // joinAgentStartup(..., startupDone)
- stops []token.Pos // svc.Shutdown(...)
- bootPass *ast.GoStmt // the go statement running runWorkerBootPass
- waiters = map[string]bool{} // local closures that wait on the latch
- )
- ast.Inspect(fn.Body, func(n ast.Node) bool {
- switch n := n.(type) {
- case *ast.CallExpr:
- switch s := str(n.Fun); {
- case s == "edge.RunWithActivatorReady":
- edgeCall = n
- case s == "cancelStartup":
- cancels = append(cancels, n.Pos())
- case s == "joinAgentStartup" && len(n.Args) == 2 && str(n.Args[1]) == "startupDone":
- joins = append(joins, n.Pos())
- case s == "svc.Shutdown":
- stops = append(stops, n.Pos())
- }
- if sel, ok := n.Fun.(*ast.SelectorExpr); ok && sel.Sel.Name == "Run" {
- if cl, ok := sel.X.(*ast.CompositeLit); ok && str(cl.Type) == "activatorStart" {
- run, lit = n, cl
- }
- }
- case *ast.AssignStmt:
- if len(n.Lhs) == 1 && len(n.Rhs) == 1 && str(n.Lhs[0]) == "svc.Startup" && str(n.Rhs[0]) == "started" {
- latch = n.Pos()
- }
- if len(n.Lhs) == 1 && len(n.Rhs) == 1 {
- if fl, ok := n.Rhs[0].(*ast.FuncLit); ok && receivesFrom(fl.Body, "started") {
- waiters[str(n.Lhs[0])] = true
- }
- }
- case *ast.GoStmt:
- if fl, ok := n.Call.Fun.(*ast.FuncLit); ok && callsNamed(fl.Body, "runWorkerBootPass") {
- bootPass = n
+ // runAgent: the latch is set, the start sequence is handed the startup
+ // context, the edge runs, then cancel, join and Shutdown, all on
+ // runAgent's own goroutine.
+ runAgent := decls["runAgent"].Body
+ sync := syncCalls(runAgent)
+ var run, edgeCall *ast.CallExpr
+ var lit *ast.CompositeLit
+ for _, c := range sync {
+ if sel, ok := c.Fun.(*ast.SelectorExpr); ok && sel.Sel.Name == "Run" {
+ if cl, ok := sel.X.(*ast.CompositeLit); ok && str(cl.Type) == "activatorStart" {
+ run, lit = c, cl
}
}
+ if calleeName(c) == "RunWithActivatorReady" {
+ edgeCall = c
+ }
+ }
+ if run == nil || edgeCall == nil {
+ t.Fatalf("runAgent: activatorStart{...}.Run called synchronously: %v; edge.RunWithActivatorReady called synchronously: %v", run != nil, edgeCall != nil)
+ }
+ if len(run.Args) != 1 || str(run.Args[0]) != "startupCtx" {
+ t.Errorf("activatorStart.Run is given %v, want startupCtx", run.Args)
+ }
+ var latch token.Pos
+ ast.Inspect(runAgent, func(n ast.Node) bool {
+ if a, ok := n.(*ast.AssignStmt); ok && len(a.Lhs) == 1 && len(a.Rhs) == 1 && selName(a.Lhs[0]) == "Startup" && str(a.Rhs[0]) == "started" {
+ latch = a.Pos()
+ }
return true
})
- if run == nil || edgeCall == nil {
- t.Fatalf("runAgent: activatorStart{...}.Run found %v, edge.RunWithActivatorReady found %v", run != nil, edgeCall != nil)
+ if latch == token.NoPos || latch > run.Pos() {
+ t.Error("runAgent: svc.Startup = started is not set before activatorStart.Run")
}
-
- // The order the child copies: the latch set, the start sequence handed
- // the startup context, the edge, then cancel, join, Shutdown (the first
- // of each after the edge returns).
- afterEdge := func(ps []token.Pos) token.Pos {
- for _, p := range ps {
- if p > edgeCall.Pos() {
- return p
+ after := func(name string, arg string) token.Pos {
+ for _, c := range sync {
+ if c.Pos() > edgeCall.Pos() && calleeName(c) == name && (arg == "" || (len(c.Args) > 0 && str(c.Args[len(c.Args)-1]) == arg)) {
+ return c.Pos()
}
}
return token.NoPos
}
- cancel, join, shutdown := afterEdge(cancels), afterEdge(joins), afterEdge(stops)
- if len(run.Args) != 1 || str(run.Args[0]) != "startupCtx" {
- t.Errorf("activatorStart.Run is given %v, want startupCtx", run.Args)
- }
- order := []struct {
- name string
- pos token.Pos
- }{
- {"svc.Startup = started", latch}, {"activatorStart{...}.Run", run.Pos()}, {"edge.RunWithActivatorReady", edgeCall.Pos()},
- {"cancelStartup()", cancel}, {"joinAgentStartup(_, startupDone)", join}, {"svc.Shutdown", shutdown},
- }
- for i, o := range order {
- if o.pos == token.NoPos {
- t.Errorf("runAgent: %s not found", o.name)
- } else if i > 0 && order[i-1].pos != token.NoPos && o.pos < order[i-1].pos {
- t.Errorf("runAgent: %s comes before %s", o.name, order[i-1].name)
+ prev, prevName := edgeCall.Pos(), "edge.RunWithActivatorReady"
+ for _, step := range []struct{ name, arg string }{{"cancelStartup", ""}, {"joinAgentStartup", "startupDone"}, {"Shutdown", ""}} {
+ p := after(step.name, step.arg)
+ if p == token.NoPos || p < prev {
+ t.Errorf("runAgent: %s is not called synchronously after %s", step.name, prevName)
+ continue
}
+ prev, prevName = p, step.name
}
- // The activatorStart fields the child copies.
+ // The activatorStart fields the child copies, and the steps inside
+ // them. Run calls each field on its background goroutine, so inside a
+ // field each step must be synchronous.
fields := map[string]ast.Expr{}
for _, el := range lit.Elts {
if kv, ok := el.(*ast.KeyValueExpr); ok {
@@ -482,54 +470,119 @@ func TestRunAgentStartupWiring(t *testing.T) {
}
}
for field, want := range map[string]string{
- "Start": "svc.Start", "Publish": "armedLayoutPass.Store", "Slot": "svc.PrepareScheduledToken",
- "Routes": "reg.List", "Route": "reg.Get", "Claims": "claims.Writes.Enabled",
+ "Start": "Start", "Publish": "Store", "Slot": "PrepareScheduledToken",
+ "Routes": "List", "Route": "Get", "Claims": "Enabled",
} {
- if got := fields[field]; got == nil || str(got) != want {
- t.Errorf("activatorStart.%s is %v, want %s", field, exprOrNil(got), want)
+ if got := selName(fields[field]); got != want {
+ t.Errorf("activatorStart.%s is %s, want a %s method value", field, exprOrNil(fields[field]), want)
}
}
- funcField := func(name string) *ast.FuncLit {
+ funcField := func(name string) ast.Node {
fl, _ := fields[name].(*ast.FuncLit)
if fl == nil {
t.Errorf("activatorStart.%s is not a func literal", name)
+ return nil
}
- return fl
+ return fl.Body
}
- if fl := funcField("Ready"); fl != nil && !callsWith(fl.Body, "close", "started") {
- t.Error("activatorStart.Ready does not close started")
+ if body := funcField("Recover"); body != nil {
+ requireSteps(t, "activatorStart.Recover", body, "newLayoutPass", "startupRecoveryIntent", "recoverLayoutAtStart")
}
- if fl := funcField("Sweep"); fl != nil && !callsNamed(fl.Body, "eb.Control.Sweep") {
- t.Error("activatorStart.Sweep does not call eb.Control.Sweep")
+ if body := funcField("Sweep"); body != nil {
+ requireSteps(t, "activatorStart.Sweep", body, "Sweep")
}
- if fl := funcField("Recover"); fl != nil {
- var seq []string
- ast.Inspect(fl.Body, func(n ast.Node) bool {
- if c, ok := n.(*ast.CallExpr); ok {
- switch s := str(c.Fun); s {
- case "newLayoutPass", "startupRecoveryIntent", "recoverLayoutAtStart":
- seq = append(seq, s)
- }
+ if body := funcField("Ready"); body != nil {
+ closes := false
+ for _, c := range syncCalls(body) {
+ closes = closes || (calleeName(c) == "close" && len(c.Args) == 1 && str(c.Args[0]) == "started")
+ }
+ if !closes {
+ t.Error("activatorStart.Ready does not close started synchronously")
+ }
+ }
+
+ // activatorStart.Run: on a legacy box, one goroutine runs the start
+ // sequence and then the key pass, in that order; start itself is
+ // Start, then Ready.
+ runBody := decls["activatorStart.Run"].Body
+ var background []*ast.FuncLit
+ ast.Inspect(runBody, func(n ast.Node) bool {
+ if g, ok := n.(*ast.GoStmt); ok {
+ if fl, ok := g.Call.Fun.(*ast.FuncLit); ok && hasCall(syncCalls(fl.Body), "startActivator") {
+ background = append(background, fl)
}
- return true
- })
- if strings.Join(seq, ",") != "newLayoutPass,startupRecoveryIntent,recoverLayoutAtStart" {
- t.Errorf("activatorStart.Recover calls %v, want newLayoutPass, startupRecoveryIntent, recoverLayoutAtStart in that order", seq)
+ }
+ return true
+ })
+ if len(background) != 1 {
+ t.Errorf("activatorStart.Run: %d goroutines run startActivator, want the one background start", len(background))
+ } else {
+ requireSteps(t, "activatorStart.Run's background goroutine", background[0].Body, "startActivator", "backfillInstanceKeys")
+ }
+ var startBody ast.Node
+ ast.Inspect(runBody, func(n ast.Node) bool {
+ if a, ok := n.(*ast.AssignStmt); ok && len(a.Lhs) == 1 && len(a.Rhs) == 1 && str(a.Lhs[0]) == "start" {
+ if fl, ok := a.Rhs[0].(*ast.FuncLit); ok {
+ startBody = fl.Body
+ }
+ }
+ return true
+ })
+ if startBody == nil {
+ t.Error("activatorStart.Run: no start closure")
+ } else {
+ requireSteps(t, "activatorStart.Run's start", startBody, "Start", "Ready")
+ }
+
+ // startActivator: its sweep, recoverLayout and start parameters, called
+ // in that order, synchronously (matched by position, not name).
+ sa := decls["startActivator"]
+ var params []string
+ for _, f := range sa.Type.Params.List {
+ for _, n := range f.Names {
+ params = append(params, n.Name)
}
}
+ if len(params) != 4 {
+ t.Errorf("startActivator takes %v, want (ctx, sweep, recoverLayout, start)", params)
+ } else {
+ requireSteps(t, "startActivator", sa.Body, params[1], params[2], params[3])
+ }
+
+ // recoverLayoutAtStart: journal recovery, then hold restoration.
+ requireSteps(t, "recoverLayoutAtStart", decls["recoverLayoutAtStart"].Body, "Recover", "RestoreHolds")
// The worker boot pass waits on the latch or the startup context, then
// lists and wakes.
+ var bootPass *ast.FuncLit
+ ast.Inspect(runAgent, func(n ast.Node) bool {
+ if g, ok := n.(*ast.GoStmt); ok {
+ if fl, ok := g.Call.Fun.(*ast.FuncLit); ok && hasCall(syncCalls(fl.Body), "runWorkerBootPass") {
+ bootPass = fl
+ }
+ }
+ return true
+ })
if bootPass == nil {
t.Error("runAgent: no goroutine runs runWorkerBootPass")
- } else if body := bootPass.Call.Fun.(*ast.FuncLit).Body; !receivesFrom(body, "started") || !callsNamed(body, "startupCtx.Done") {
+ } else if !receivesFrom(bootPass.Body, "started") || !hasCall(syncCalls(bootPass.Body), "Done") {
t.Error("runAgent: the worker boot pass does not wait on started and startupCtx.Done")
}
- // Nothing before the edge waits for startup. Outside func literals and
- // go statements: no receive at all, no join, and a closure that waits
- // on the latch is only called directly on a claim box, where Run has
- // already started the activator before it returns.
+ // Nothing before the edge waits for startup. On runAgent's own
+ // goroutine (closures invoked on the spot included): no receive at all,
+ // no join, and a closure that waits on startup is only called directly
+ // on a claim box, where Run has already started the activator before
+ // it returns.
+ waiters := map[string]bool{}
+ ast.Inspect(runAgent, func(n ast.Node) bool {
+ if a, ok := n.(*ast.AssignStmt); ok && len(a.Lhs) == 1 && len(a.Rhs) == 1 {
+ if fl, ok := a.Rhs[0].(*ast.FuncLit); ok && (receivesFrom(fl.Body, "started") || receivesFrom(fl.Body, "startupDone") || hasCall(syncCalls(fl.Body), "joinAgentStartup")) {
+ waiters[str(a.Lhs[0])] = true
+ }
+ }
+ return true
+ })
var walk func(n ast.Node, claimBranch bool)
walk = func(n ast.Node, claimBranch bool) {
ast.Inspect(n, func(n ast.Node) bool {
@@ -537,14 +590,14 @@ func TestRunAgentStartupWiring(t *testing.T) {
return false
}
switch n := n.(type) {
- case *ast.FuncLit, *ast.GoStmt:
+ case *ast.FuncLit, *ast.GoStmt, *ast.DeferStmt:
return false
case *ast.IfStmt:
if n.Init != nil {
walk(n.Init, claimBranch)
}
walk(n.Cond, claimBranch)
- walk(n.Body, claimBranch || str(n.Cond) == "claims.Writes.Enabled")
+ walk(n.Body, claimBranch || selName(n.Cond) == "Enabled")
if n.Else != nil {
walk(n.Else, claimBranch)
}
@@ -554,50 +607,119 @@ func TestRunAgentStartupWiring(t *testing.T) {
t.Errorf("runAgent waits on %s at %s, before the edge listens", str(n.X), fset.Position(n.Pos()))
}
case *ast.CallExpr:
- s := str(n.Fun)
- if s == "joinAgentStartup" {
+ name := calleeName(n)
+ if name == "joinAgentStartup" {
t.Errorf("runAgent joins startup at %s, before the edge listens", fset.Position(n.Pos()))
}
- if waiters[s] && !claimBranch {
- t.Errorf("runAgent calls %s, which waits on the latch, at %s, before the edge listens", s, fset.Position(n.Pos()))
+ if waiters[str(n.Fun)] && !claimBranch {
+ t.Errorf("runAgent calls %s, which waits on startup, at %s, before the edge listens", str(n.Fun), fset.Position(n.Pos()))
+ }
+ if fl, ok := n.Fun.(*ast.FuncLit); ok { // invoked on the spot: its body runs here
+ walk(fl.Body, claimBranch)
+ for _, a := range n.Args {
+ walk(a, claimBranch)
+ }
+ return false
}
}
return true
})
}
- walk(fn.Body, false)
+ walk(runAgent, false)
}
-// receivesFrom reports whether body receives from the channel named ch
-// (in a select case or a bare receive).
-func receivesFrom(body ast.Node, ch string) bool {
- found := false
+// syncCalls lists, in source order, the calls body makes on its own
+// goroutine: none inside a go or defer statement, and none inside a
+// function literal unless the literal is invoked right there.
+func syncCalls(body ast.Node) []*ast.CallExpr {
+ var out []*ast.CallExpr
ast.Inspect(body, func(n ast.Node) bool {
- if u, ok := n.(*ast.UnaryExpr); ok && u.Op == token.ARROW && types.ExprString(u.X) == ch {
- found = true
+ switch n := n.(type) {
+ case *ast.GoStmt, *ast.DeferStmt, *ast.FuncLit:
+ return false
+ case *ast.CallExpr:
+ out = append(out, n)
+ if fl, ok := n.Fun.(*ast.FuncLit); ok {
+ for _, a := range n.Args {
+ out = append(out, syncCalls(a)...)
+ }
+ out = append(out, syncCalls(fl.Body)...)
+ return false
+ }
}
- return !found
+ return true
})
- return found
+ return out
}
-// callsNamed reports whether body calls a function whose expression is name.
-func callsNamed(body ast.Node, name string) bool {
- found := false
+// requireSteps fails unless body calls each step synchronously, in order,
+// and calls none of them anywhere else (in a go or defer statement, or a
+// literal that is not invoked on the spot).
+func requireSteps(t *testing.T, where string, body ast.Node, steps ...string) {
+ t.Helper()
+ sync := syncCalls(body)
+ inSync := map[*ast.CallExpr]bool{}
+ for _, c := range sync {
+ inSync[c] = true
+ }
ast.Inspect(body, func(n ast.Node) bool {
- if c, ok := n.(*ast.CallExpr); ok && types.ExprString(c.Fun) == name {
- found = true
+ if c, ok := n.(*ast.CallExpr); ok && !inSync[c] {
+ for _, s := range steps {
+ if calleeName(c) == s {
+ t.Errorf("%s: %s is called off its goroutine (go, defer, or a literal not invoked there)", where, s)
+ }
+ }
}
- return !found
+ return true
})
- return found
+ i := 0
+ for _, c := range sync {
+ if i < len(steps) && calleeName(c) == steps[i] {
+ i++
+ }
+ }
+ if i < len(steps) {
+ t.Errorf("%s: want %v called in that order on its goroutine; %s is missing or out of order", where, steps, steps[i])
+ }
+}
+
+// calleeName is the name a call is matched on: the function's own name,
+// whatever the receiver or package it is reached through.
+func calleeName(c *ast.CallExpr) string {
+ switch f := c.Fun.(type) {
+ case *ast.Ident:
+ return f.Name
+ case *ast.SelectorExpr:
+ return f.Sel.Name
+ }
+ return ""
+}
+
+func selName(e ast.Expr) string {
+ switch e := e.(type) {
+ case *ast.SelectorExpr:
+ return e.Sel.Name
+ case *ast.Ident:
+ return e.Name
+ }
+ return ""
}
-// callsWith reports whether body calls name with arg as its only argument.
-func callsWith(body ast.Node, name, arg string) bool {
+func hasCall(calls []*ast.CallExpr, name string) bool {
+ for _, c := range calls {
+ if calleeName(c) == name {
+ return true
+ }
+ }
+ return false
+}
+
+// receivesFrom reports whether body receives from the channel named ch
+// (in a select case or a bare receive).
+func receivesFrom(body ast.Node, ch string) bool {
found := false
ast.Inspect(body, func(n ast.Node) bool {
- if c, ok := n.(*ast.CallExpr); ok && types.ExprString(c.Fun) == name && len(c.Args) == 1 && types.ExprString(c.Args[0]) == arg {
+ if u, ok := n.(*ast.UnaryExpr); ok && u.Op == token.ARROW && types.ExprString(u.X) == ch {
found = true
}
return !found
@@ -1033,29 +1155,82 @@ type largeBoxAgent struct {
// answered and its TLS listener accepts. The edge's -http and -https take
// an address, and :0 would bind, but the edge never says which port it
// got, so the test picks free ports and hands them over. A port taken in
-// between makes the agent's listener fail and the agent exit, which is
-// told apart from any other failure by its log, and the agent is started
-// again on fresh ports.
+// between makes the edge's listener fail and the agent exit; only that is
+// retried on fresh ports (largeBoxRetryable). A deadline missed is the
+// failure this test exists to catch, and is never retried.
func (b *largeBox) startAgent(t *testing.T) *largeBoxAgent {
t.Helper()
for attempt := 1; ; attempt++ {
b.httpAddr, b.httpsAddr = freeLoopbackAddr(t), freeLoopbackAddr(t)
a := b.launchAgent(t)
- err := a.awaitListening()
- if err == nil {
- err = a.awaitTLS()
+ outcome, err := a.awaitListening()
+ if outcome == largeBoxUp {
+ outcome, err = a.awaitTLS()
}
- if err == nil {
+ if outcome == largeBoxUp {
return a
}
- if a.collided() && attempt < largeBoxBindAttempts {
- t.Logf("attempt %d: a port was taken before the agent bound it; starting again on fresh ports", attempt)
+ agentLog, _ := os.ReadFile(a.log)
+ if largeBoxRetryable(outcome, string(agentLog), b.httpAddr, b.httpsAddr) && attempt < largeBoxBindAttempts {
+ t.Logf("attempt %d: %v; a port the test handed the agent was taken before it bound it, starting again on fresh ports", attempt, err)
continue
}
t.Fatal(err)
}
}
+// largeBoxOutcome is how waiting for the agent to come up ended.
+type largeBoxOutcome int
+
+const (
+ largeBoxUp largeBoxOutcome = iota
+ largeBoxLate // a deadline passed: a failure, never retried
+ largeBoxExited // the agent exited before it was up
+)
+
+// largeBoxRetryable reports whether a start may be retried on fresh
+// ports: only when the agent exited, and its log says the edge could not
+// bind one of the addresses the test handed it because it was in use.
+// Edge listener failures are logged as "edge: http listener <addr>: ..."
+// (edge.RunWithActivatorReady).
+func largeBoxRetryable(o largeBoxOutcome, agentLog string, addrs ...string) bool {
+ if o != largeBoxExited {
+ return false
+ }
+ for _, line := range strings.Split(agentLog, "\n") {
+ if !strings.Contains(line, "address already in use") {
+ continue
+ }
+ for _, addr := range addrs {
+ if strings.Contains(line, " listener "+addr+": ") {
+ return true
+ }
+ }
+ }
+ return false
+}
+
+func TestLargeBoxRetriesOnlyItsOwnBindFailure(t *testing.T) {
+ const plain, tls = "127.0.0.1:40001", "127.0.0.1:40002"
+ bind := "edge: https listener " + tls + ": listen tcp " + tls + ": bind: address already in use\n"
+ for _, c := range []struct {
+ name string
+ o largeBoxOutcome
+ log string
+ want bool
+ }{
+ {"own bind failure", largeBoxExited, "edge: serving 300 route(s)\n" + bind, true},
+ {"deadline missed, bind failure logged too", largeBoxLate, bind, false},
+ {"exited for another reason", largeBoxExited, "edge: tunnels: invalid\n", false},
+ {"someone else's address", largeBoxExited, "edge: http listener 127.0.0.1:1: listen tcp 127.0.0.1:1: bind: address already in use\n", false},
+ {"in use, but not a listener line", largeBoxExited, "agent: something: address already in use\n", false},
+ } {
+ if got := largeBoxRetryable(c.o, c.log, plain, tls); got != c.want {
+ t.Errorf("%s: retry = %v, want %v", c.name, got, c.want)
+ }
+ }
+}
+
func (b *largeBox) launchAgent(t *testing.T) *largeBoxAgent {
t.Helper()
cfgDir := t.TempDir()
@@ -1118,8 +1293,8 @@ func (b *largeBox) launchAgent(t *testing.T) *largeBoxAgent {
// productionSysOps.probeEdge): GET / on the edge's plain-HTTP listener,
// three-second client timeout, no redirect followed, and any HTTP answer
// passes. It records how long after the process started the first answer
-// came, and fails past largeBoxListenBound.
-func (a *largeBoxAgent) awaitListening() error {
+// came; an answer past largeBoxListenBound, or none by then, is late.
+func (a *largeBoxAgent) awaitListening() (largeBoxOutcome, error) {
probe := &http.Client{
Timeout: 3 * time.Second,
Transport: &http.Transport{Proxy: nil, DisableKeepAlives: true},
@@ -1132,18 +1307,18 @@ func (a *largeBoxAgent) awaitListening() error {
resp.Body.Close()
a.listen = time.Since(a.began)
if a.listen > largeBoxListenBound {
- return fmt.Errorf("gate probe answered %s after the agent started, over %s", a.listen, largeBoxListenBound)
+ return largeBoxLate, fmt.Errorf("gate probe answered %s after the agent started, over %s", a.listen, largeBoxListenBound)
}
- return nil
+ return largeBoxUp, nil
+ }
+ if time.Now().After(deadline) {
+ return largeBoxLate, fmt.Errorf("gate probe unanswered %s after the agent started: %v", time.Since(a.began), err)
}
select {
case <-a.exited:
- return fmt.Errorf("agent exited before listening: %v", a.exitErr)
+ return largeBoxExited, fmt.Errorf("agent exited before listening: %v", a.exitErr)
default:
}
- if time.Now().After(deadline) {
- return fmt.Errorf("gate probe unanswered %s after the agent started: %v", time.Since(a.began), err)
- }
time.Sleep(20 * time.Millisecond)
}
}
@@ -1151,43 +1326,28 @@ func (a *largeBoxAgent) awaitListening() error {
// awaitTLS waits, boundedly, for the edge's TLS listener: the edge binds
// it in its own goroutine, beside the plain-HTTP one the gate probes, so
// it can come up a moment later. Not part of the gate's measurement.
-func (a *largeBoxAgent) awaitTLS() error {
+func (a *largeBoxAgent) awaitTLS() (largeBoxOutcome, error) {
deadline := time.Now().Add(largeBoxListenBound)
for {
c, err := net.DialTimeout("tcp", a.b.httpsAddr, time.Second)
if err == nil {
c.Close()
- select {
- case <-a.exited:
- return fmt.Errorf("agent exited after binding: %v", a.exitErr)
- default:
- return nil
- }
}
select {
case <-a.exited:
- return fmt.Errorf("agent exited before its TLS listener came up: %v", a.exitErr)
+ return largeBoxExited, fmt.Errorf("agent exited before its TLS listener was up: %v", a.exitErr)
default:
}
+ if err == nil {
+ return largeBoxUp, nil
+ }
if time.Now().After(deadline) {
- return fmt.Errorf("TLS listener not up %s after the gate probe: %v", largeBoxListenBound, err)
+ return largeBoxLate, fmt.Errorf("TLS listener not up %s after the gate probe: %v", largeBoxListenBound, err)
}
time.Sleep(20 * time.Millisecond)
}
}
-// collided reports whether the agent exited because a port it was handed
-// had been taken.
-func (a *largeBoxAgent) collided() bool {
- select {
- case <-a.exited:
- case <-time.After(time.Second):
- return false
- }
- out, _ := os.ReadFile(a.log)
- return strings.Contains(string(out), "address already in use")
-}
-
func (a *largeBoxAgent) signal(t *testing.T, sig os.Signal) {
t.Helper()
if err := a.cmd.Process.Signal(sig); err != nil {