diff --git a/cmd/mesh-controller/batches.go b/cmd/mesh-controller/batches.go index 12bc80a1..ae7627a1 100644 --- a/cmd/mesh-controller/batches.go +++ b/cmd/mesh-controller/batches.go @@ -800,9 +800,9 @@ type keptMerge struct { // FirstBuild says the merge is a first merge into a repository the mesh builds nothing from, kept to ask the first // build of its modules once mesh-delivery's word on it is kept (novox/hq ADR 0432, issue 1146). FirstBuild bool `json:"first_build,omitempty"` - // Held says the first build was refused for a word the running build-agent does not read: the merge waits for a - // build-agent that reads it, and is never failed (novox/hq ADR 0482 §5, issue 1173). - Held *heldFirstBuild `json:"held,omitempty"` + // Held says which first builds of the merge were refused for a word the running build-agent does not read: the merge + // waits for a build-agent that reads them, and is never failed (novox/hq ADR 0482 §5, issue 1173). + Held []heldFirstBuild `json:"held,omitempty"` } // announcedOf is a kept merge as the forge announced it, and what it moved; empty where the record says none. diff --git a/cmd/mesh-controller/first_builds.go b/cmd/mesh-controller/first_builds.go index 961e20cf..fb05302b 100644 --- a/cmd/mesh-controller/first_builds.go +++ b/cmd/mesh-controller/first_builds.go @@ -103,7 +103,7 @@ func (f following) resumeFirstBuilds(ctx context.Context, d deliveryMerge) error } for _, w := range waiting { k := announcedOf(w) - if !k.FirstBuild || k.Held != nil || !strings.EqualFold(k.Owner+"/"+k.Repo, d.Owner+"/"+d.Repo) || k.Number != d.Number || + if !k.FirstBuild || len(k.Held) > 0 || !strings.EqualFold(k.Owner+"/"+k.Repo, d.Owner+"/"+d.Repo) || k.Number != d.Number || k.HeadSHA != d.HeadSHA { continue } @@ -177,18 +177,55 @@ func firstBuildsOf(ctx context.Context, inv catalogueReader, m link.SourceMoved, // and its merge is kept waiting for a build-agent that reads it (novox/hq ADR 0482 §5, issue 1173). type heldFirstBuild struct { Module string `json:"module"` + Path string `json:"path"` Word string `json:"word"` At time.Time `json:"at"` } -// judgeRefusedFirstBuild is the hold a first build's outcome puts its merge under: nil unless the build failed on a word -// of its manifest the running build-agent does not know. -func judgeRefusedFirstBuild(result link.BuildResult, req inventory.BuildRequest, merge inventory.BatchedMerge) *heldFirstBuild { +// judgeRefusedFirstBuild is the hold a first build's outcome puts its merge under: every module the merge holds already, +// and this one, unless it is among them; nil unless the build failed on a word of its manifest the running build-agent +// does not know, and was asked for a first merge, answered by the record of merges no plan answers or put back to waiting +// by an earlier hold (a second refusal in one merge is held too, review of issue 1173). +func judgeRefusedFirstBuild(result link.BuildResult, req inventory.BuildRequest, merge inventory.BatchedMerge) []heldFirstBuild { word := refusedWord(result.Failed) - if word == "" || req.For != "merge" || merge.Plan != inventory.WaitingRecord { + if word == "" || req.For != "merge" { return nil } - return &heldFirstBuild{Module: req.Name(), Word: word, At: time.Now().UTC()} + var held []heldFirstBuild + switch k := announcedOf(merge); { + case merge.Plan == inventory.WaitingRecord: + // Answered when its builds were asked: a hold from before (a build asked again) is over, and starts anew. + case merge.Plan == "" && len(k.Held) > 0: + held = k.Held + default: + return nil + } + this := heldFirstBuild{Module: req.Name(), Path: strings.Trim(req.Path, "/"), Word: word, At: time.Now().UTC()} + for i, h := range held { + if strings.Trim(h.Path, "/") == this.Path { + out := append([]heldFirstBuild(nil), held...) + out[i] = this + return out + } + } + return append(append([]heldFirstBuild(nil), held...), this) +} + +// heldDirsOf is the directories a held merge asks again: its held modules' own, each once, "." for the repository's root. +func heldDirsOf(k keptMerge) []string { + var dirs []string + seen := map[string]bool{} + for _, h := range k.Held { + dir := strings.Trim(h.Path, "/") + if dir == "" { + dir = "." + } + if !seen[dir] { + seen[dir] = true + dirs = append(dirs, dir) + } + } + return dirs } // unknownWord is how the strict reading of a manifest says a word is not one it knows: encoding/json's own words, which @@ -219,7 +256,7 @@ func holdRefusedFirstBuild(ctx context.Context, inv *inventory.Inventory, result return false, err } held := judgeRefusedFirstBuild(result, req, merge) - if held == nil { + if len(held) == 0 { return false, nil } k := announcedOf(merge) @@ -231,9 +268,15 @@ func holdRefusedFirstBuild(ctx context.Context, inv *inventory.Inventory, result if err := inv.HoldMerge(ctx, merge.Repository, merge.Commit, event); err != nil { return false, err } + this := held[len(held)-1] + for _, h := range held { + if h.Path == strings.Trim(req.Path, "/") { + this = h + } + } fmt.Printf("%s: the first build of %s was refused for the word %q, which the running build-agent does not read; the "+ - "merge %.8s of %s is kept waiting for a build-agent that reads it, and the build is asked again when one is delivered\n", - result.ID, held.Module, held.Word, merge.Commit, merge.Repository) + "merge %.8s of %s is kept waiting for a build-agent that reads it (holding %s), and the build is asked again when "+ + "one is delivered\n", result.ID, this.Module, this.Word, merge.Commit, merge.Repository, heldNames(held)) return true, nil } @@ -257,7 +300,7 @@ func firstBuildObservations(waiting []inventory.BatchedMerge, now time.Time) []c var out []conditions.Observation for _, w := range waiting { k := announcedOf(w) - if k.Held != nil { + if len(k.Held) > 0 { out = append(out, heldFirstBuildObservation(k)) continue } @@ -283,22 +326,34 @@ func firstBuildObservations(waiting []inventory.BatchedMerge, now time.Time) []c return out } -// heldFirstBuildObservation names a first merge held for a build-agent that reads its manifest: at once, since nothing -// is lost and nothing times out, but the operator can see what the merge waits for. +// heldNames is the modules a merge holds, each with the word it waits for: "watchman (key-ttl), view (per-machine)". +func heldNames(held []heldFirstBuild) string { + names := make([]string, 0, len(held)) + for _, h := range held { + names = append(names, fmt.Sprintf("%s (%q)", h.Module, h.Word)) + } + return strings.Join(names, ", ") +} + +// heldFirstBuildObservation names a first merge held for a build-agent that reads its manifests: at once, since nothing +// is lost and nothing times out, but the operator can see what the merge waits for. One condition names every module held. func heldFirstBuildObservation(k keptMerge) conditions.Observation { repository := k.Owner + "/" + k.Repo + modules := make([]string, 0, len(k.Held)) + for _, h := range k.Held { + modules = append(modules, h.Module) + } + held := heldNames(k.Held) return conditions.Observation{Scope: conditions.ScopeMerge, ID: fmt.Sprintf("%s_%.8s", repository, k.Commit), Kind: kindFirstBuildHeld, Severity: conditions.Warning, - Summary: fmt.Sprintf("the merge %.8s of %s adds the module %s, whose manifest uses the word %q: the running "+ - "build-agent does not read it, so the merge waits for a build-agent that reads it", k.Commit, repository, - k.Held.Module, k.Held.Word), - Said: fmt.Sprintf("%s at %s waits for a build-agent that reads %q (module %s)", repository, k.Commit, k.Held.Word, - k.Held.Module), - Headline: fmt.Sprintf("The first build of %s waits for a newer build-agent", k.Held.Module), - Explanation: fmt.Sprintf("The merge %.8s into %s adds the module %s, and its manifest uses the word %q, which "+ - "the build-agent now running does not know. The merge is kept, not failed: the first build is asked again "+ - "when a delivery of build-agent ends.", k.Commit, repository, k.Held.Module, k.Held.Word), - Resolved: "a delivery of build-agent ends and the first build registers the module, or a hand `build` does", + Summary: fmt.Sprintf("the merge %.8s of %s adds modules whose manifests use words the running build-agent does not "+ + "read: %s; the merge waits for a build-agent that reads them", k.Commit, repository, held), + Said: fmt.Sprintf("%s at %s waits for a build-agent that reads the words of %s", repository, k.Commit, held), + Headline: fmt.Sprintf("The first build of %s waits for a newer build-agent", strings.Join(modules, ", ")), + Explanation: fmt.Sprintf("The merge %.8s into %s adds modules whose manifests use words the build-agent now "+ + "running does not know: %s. The merge is kept, not failed: their first builds are asked again when a delivery "+ + "of build-agent ends.", k.Commit, repository, held), + Resolved: "a delivery of build-agent ends and the first builds register the modules, or a hand `build` does", } } @@ -329,29 +384,32 @@ func askHeldFirstBuildsAgain(ctx context.Context, open *stores, p inventory.Plan asked := 0 for _, w := range waiting { k := announcedOf(w) - if k.Held == nil { + if len(k.Held) == 0 { continue } - entries, err := inv.Catalogued(ctx) + // Its own held modules, not the rule of a first merge: a module of the merge that passed is registered by now, + // and the repository no longer counts as one the mesh builds nothing from (review of issue 1173). + why, err := approvedAnnounced(ctx, inv, k.Owner, k.Repo, keptMerge{SourceMoved: k.SourceMoved}) if err != nil { - fmt.Printf("%s delivered build-agent, and the catalogue could not be read: %v\n", p.ID, err) - return asked - } - read, err := readForPlanning(ctx, inv) - if err != nil { - fmt.Printf("%s delivered build-agent, and what the builds read could not be read: %v\n", p.ID, err) - return asked - } - added, why, err := firstBuildsOf(ctx, inv, k.SourceMoved, entries, read) - if err != nil || len(added) == 0 { fmt.Printf("%s delivered build-agent, and the merge %.8s of %s held for it asks no build now (%v): it stays "+ "waiting\n", p.ID, w.Commit, w.Repository, err) continue } - fmt.Printf("%s delivered build-agent: the first build of %s, held for the word %q, is asked again\n", p.ID, - k.Held.Module, k.Held.Word) - if err := askFirstBuilds(ctx, inv, k.SourceMoved, time.Now().UTC(), added, why); err != nil { - fmt.Printf(" and could not be asked: %v\n", err) + dirs := heldDirsOf(k) + fmt.Printf("%s delivered build-agent: the first builds of %s are asked again\n", p.ID, heldNames(k.Held)) + paths := make([]string, 0, len(dirs)) + for _, dir := range dirs { + if dir == "." { + dir = "" + } + paths = append(paths, dir) + } + repository := k.Owner + "/" + k.Repo + askBuilds(withFirstBuildWarrant(ctx, repository, paths, why), inv, k.SourceMoved, + buildSource{Repository: repository, Seat: gitSeat}, dirs) + // Answered: it no longer waits, so this end asks nothing twice; a refusal that comes again holds it anew. + if err := inv.AnswerMerge(ctx, w.Repository, w.Commit, inventory.WaitingRecord, false); err != nil { + fmt.Printf(" and the merge could not be marked answered: %v\n", err) continue } asked++ diff --git a/cmd/mesh-controller/first_builds_held_integration_test.go b/cmd/mesh-controller/first_builds_held_integration_test.go index 8fb33193..fb69d5e2 100644 --- a/cmd/mesh-controller/first_builds_held_integration_test.go +++ b/cmd/mesh-controller/first_builds_held_integration_test.go @@ -4,6 +4,8 @@ package main import ( "context" + "fmt" + "strings" "testing" "time" @@ -57,7 +59,7 @@ func TestAHeldFirstMergeIsAskedAgainWhenABuildAgentIsDelivered(t *testing.T) { t.Fatal("1173/AC1: a refused first build was recorded as a failed build") } waiting, err := inv.WaitingMerges(ctx) - if err != nil || len(waiting) != 1 || announcedOf(waiting[0]).Held == nil { + if err != nil || len(waiting) != 1 || len(announcedOf(waiting[0]).Held) == 0 { t.Fatalf("1173/AC1: the merges waiting are %+v (%v), want the first merge, held", waiting, err) } if obs := firstBuildObservations(waiting, time.Now()); len(obs) != 1 || obs[0].Kind != kindFirstBuildHeld { @@ -89,3 +91,131 @@ func TestAHeldFirstMergeIsAskedAgainWhenABuildAgentIsDelivered(t *testing.T) { t.Fatal("1173/AC3: the module is not registered after the first build passed") } } + +// aTwoModuleFirstMerge is a first merge into novox/mesh-delivery adding the modules watchman and view, made on the +// operator's Approve of its head, whose first builds are asked; asked says the build id asked for each path, in order. +func aTwoModuleFirstMerge(t *testing.T, open *stores, commit string) *[][2]string { + t.Helper() + const head = "b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2" + a := aDeliveryMergeOf(t, head, map[string]string{"novox/mesh-delivery@b2b2b2b2b2b2": head}) + wasKept, wasAsk, realAsk := keptDeliveryMerge, routerAskOf, askABuild + keptDeliveryMerge = func(context.Context, string, string, int, string) (deliveryMerge, bool, error) { + return a.merge, true, nil + } + routerAskOf = func(context.Context, catalogueReader, string, string) (*asks.Ask, *asks.Warrant, error) { + return &a.ask, &a.warrant, nil + } + asked := &[][2]string{} + askABuild = func(_ context.Context, _ buildSource, path, _ string) (string, error) { + id := fmt.Sprintf("build-%d", len(*asked)+1) + *asked = append(*asked, [2]string{path, id}) + return id, nil + } + t.Cleanup(func() { keptDeliveryMerge, routerAskOf, askABuild = wasKept, wasAsk, realAsk }) + m := link.SourceMoved{Owner: "novox", Repo: "mesh-delivery", Base: "main", HeadSHA: head, Commit: commit, Number: 7, + MergedAt: time.Now().Add(-time.Hour).UTC().Format(time.RFC3339Nano), + Paths: []string{"view/module.json", "view/main.go", "watchman/module.json", "watchman/main.go"}, + ModuleDirs: []string{"view", "watchman"}, ModuleDirsSaid: true} + if err := (following{open: open}).SourceMoved(t.Context(), m); err != nil { + t.Fatal(err) + } + if len(*asked) != 2 { + t.Fatalf("the first merge asked %v, want the two first builds", *asked) + } + return asked +} + +// idOf is the build asked last for path. +func idOf(t *testing.T, asked [][2]string, path string) string { + t.Helper() + for i := len(asked) - 1; i >= 0; i-- { + if asked[i][0] == path { + return asked[i][1] + } + } + t.Fatalf("no build asked for %s: %v", path, asked) + return "" +} + +// built hands the controller a build's outcome: refused for the word, or passing as module. +func built(t *testing.T, open *stores, id, path, commit, refusedFor, module string) { + t.Helper() + r := onTrunk(id, "novox/mesh-delivery", "git", path, map[string]any{"module": module, "version": "1"}) + r.Commit = commit + if refusedFor != "" { + r.Failed, r.Manifest = `this is not a module manifest: json: unknown field "`+refusedFor+`"`, nil + } + if err := (builds{inv: open.inventory, open: open}).Built(t.Context(), r); err != nil { + t.Fatal(err) + } +} + +var buildAgentDelivered = inventory.Plan{ID: "p-ba", State: inventory.PlanDone, WalkSaid: inventory.WalkEnded, + Modules: map[string]*inventory.PlanModule{"build-agent": {State: "built"}}} + +// 1173/AC3 (review round 1, item 1): in a first merge of two modules where view passes and watchman is refused, the +// held watchman is asked again when build-agent is delivered, though the repository builds view by then. +func TestAHeldModuleIsAskedAgainAfterItsSiblingRegistered(t *testing.T) { + const commit = "0177ea7b00000000" + open := aMesh(t) + ctx := t.Context() + asked := aTwoModuleFirstMerge(t, open, commit) + + built(t, open, idOf(t, *asked, "view"), "view", commit, "", "mesh-delivery-view") + if _, known := inventoryHolds(t, open.inventory, "mesh-delivery-view"); !known { + t.Fatal("view is not registered after its first build passed") + } + refused := idOf(t, *asked, "watchman") + built(t, open, refused, "watchman", commit, "key-ttl", "") + if _, recorded, _ := open.inventory.BuildByID(ctx, refused); recorded { + t.Fatal("1173/AC1: the refused first build of watchman was recorded as a failed build") + } + waiting, err := open.inventory.WaitingMerges(ctx) + if err != nil || len(waiting) != 1 || len(announcedOf(waiting[0]).Held) != 1 { + t.Fatalf("1173/AC1: the merges waiting are %+v (%v), want the first merge, holding watchman", waiting, err) + } + + if n := askHeldFirstBuildsAgain(ctx, open, buildAgentDelivered); n != 1 || len(*asked) != 3 || (*asked)[2][0] != "watchman" { + t.Fatalf("1173/AC3: the delivery of build-agent asked %d merges again (%v), want watchman's first build alone", n, *asked) + } + built(t, open, idOf(t, *asked, "watchman"), "watchman", commit, "", "mesh-delivery-watchman") + if _, known := inventoryHolds(t, open.inventory, "mesh-delivery-watchman"); !known { + t.Fatal("1173/AC3: watchman is not registered after the first build asked again passed") + } +} + +// 1173/AC1, AC2, AC3 (review round 1, item 2): in a first merge of two modules both refused, neither is recorded as a +// failed build, the condition names both, and the delivery of build-agent asks both again. +func TestTwoRefusedModulesOfOneFirstMergeAreBothHeld(t *testing.T) { + const commit = "0177ea7c00000000" + open := aMesh(t) + ctx := t.Context() + asked := aTwoModuleFirstMerge(t, open, commit) + + for _, path := range []string{"watchman", "view"} { + id := idOf(t, *asked, path) + built(t, open, id, path, commit, "key-ttl", "") + if _, recorded, _ := open.inventory.BuildByID(ctx, id); recorded { + t.Fatalf("1173/AC1: the refused first build of %s was recorded as a failed build", path) + } + } + waiting, err := open.inventory.WaitingMerges(ctx) + if err != nil || len(waiting) != 1 || len(announcedOf(waiting[0]).Held) != 2 { + t.Fatalf("1173/AC1: the merges waiting are %+v (%v), want the first merge, holding both", waiting, err) + } + obs := firstBuildObservations(waiting, time.Now()) + if len(obs) != 1 || !strings.Contains(obs[0].Summary, "watchman") || !strings.Contains(obs[0].Summary, "view") { + t.Fatalf("1173/AC2: the held merge is named by %+v, want one condition naming both", obs) + } + + if n := askHeldFirstBuildsAgain(ctx, open, buildAgentDelivered); n != 1 || len(*asked) != 4 { + t.Fatalf("1173/AC3: the delivery of build-agent asked %d merges again (%v), want both first builds", n, *asked) + } + built(t, open, idOf(t, *asked, "watchman"), "watchman", commit, "", "mesh-delivery-watchman") + built(t, open, idOf(t, *asked, "view"), "view", commit, "", "mesh-delivery-view") + for _, module := range []string{"mesh-delivery-watchman", "mesh-delivery-view"} { + if _, known := inventoryHolds(t, open.inventory, module); !known { + t.Fatalf("1173/AC3: %s is not registered after the first build asked again passed", module) + } + } +} diff --git a/cmd/mesh-controller/first_builds_held_test.go b/cmd/mesh-controller/first_builds_held_test.go index 7190024d..96110263 100644 --- a/cmd/mesh-controller/first_builds_held_test.go +++ b/cmd/mesh-controller/first_builds_held_test.go @@ -28,7 +28,7 @@ func aFirstMergeAnswered() (inventory.BuildRequest, inventory.BatchedMerge) { func TestAFirstBuildRefusedForAnUnknownWordHoldsItsMerge(t *testing.T) { req, merge := aFirstMergeAnswered() held := judgeRefusedFirstBuild(link.BuildResult{ID: "build-1", Failed: refusedKeyTTL}, req, merge) - if held == nil || held.Word != "key-ttl" || held.Module != "watchman" { + if len(held) != 1 || held[0].Word != "key-ttl" || held[0].Module != "watchman" || held[0].Path != "watchman" { t.Fatalf("1173/AC1: a first build refused for \"key-ttl\" is judged %+v, want a hold on that word for watchman", held) } } @@ -39,7 +39,8 @@ func TestAHeldFirstMergeIsNamedByACondition(t *testing.T) { _, merge := aFirstMergeAnswered() var k keptMerge _ = json.Unmarshal(merge.Event, &k) - k.Held = &heldFirstBuild{Module: "watchman", Word: "key-ttl", At: now} + k.Held = []heldFirstBuild{{Module: "watchman", Path: "watchman", Word: "key-ttl", At: now}, + {Module: "view", Path: "view", Word: "per-machine", At: now}} merge.Event, _ = json.Marshal(k) merge.Heard = now.Add(-time.Second) got := firstBuildObservations([]inventory.BatchedMerge{merge}, now) @@ -50,7 +51,7 @@ func TestAHeldFirstMergeIsNamedByACondition(t *testing.T) { if o.Kind != kindFirstBuildHeld || o.Scope != conditions.ScopeMerge { t.Fatalf("1173/AC2: the condition is %+v", o) } - for _, want := range []string{"0177ea7a", "watchman", "key-ttl", "build-agent"} { + for _, want := range []string{"0177ea7a", "watchman", "key-ttl", "view", "per-machine", "build-agent"} { if !strings.Contains(o.Summary, want) { t.Fatalf("1173/AC2: the summary %q does not name %q", o.Summary, want) } @@ -73,6 +74,7 @@ func TestAFirstBuildFailingForAnyOtherReasonIsNotHeld(t *testing.T) { {what: "a missing field", failed: `json: cannot unmarshal string into Go struct field`}, {what: "a build a person asked", failed: refusedKeyTTL, change: func(r *inventory.BuildRequest, _ *inventory.BatchedMerge) { r.For = "build" }}, {what: "a merge a plan answers", failed: refusedKeyTTL, change: func(_ *inventory.BuildRequest, m *inventory.BatchedMerge) { m.Plan = "plan-7" }}, + {what: "a waiting merge held for nothing", failed: refusedKeyTTL, change: func(_ *inventory.BuildRequest, m *inventory.BatchedMerge) { m.Plan = "" }}, } { r, m := req, merge if c.change != nil { @@ -84,6 +86,38 @@ func TestAFirstBuildFailingForAnyOtherReasonIsNotHeld(t *testing.T) { } } +// 1173/AC1, AC2 (review round 1, item 2): a second refusal in a merge already held is held too, its module added to the +// hold, so no failed build is recorded and the condition names both. +func TestASecondRefusalInAHeldMergeIsAddedToTheHold(t *testing.T) { + req, merge := aFirstMergeAnswered() + first := judgeRefusedFirstBuild(link.BuildResult{Failed: refusedKeyTTL}, req, merge) + k := announcedOf(merge) + k.Held = first + merge.Event, _ = json.Marshal(k) + merge.Plan = "" // HoldMerge put it back to waiting + req.ID, req.Path = "build-2", "view" + held := judgeRefusedFirstBuild(link.BuildResult{Failed: `json: unknown field "per-machine"`}, req, merge) + if len(held) != 2 || held[0].Module != "watchman" || held[1].Module != "view" || held[1].Word != "per-machine" { + t.Fatalf("1173/AC1: the second refusal in a held merge is judged %+v, want watchman and view held", held) + } + // The same module refused again is held once. + k.Held = held + merge.Event, _ = json.Marshal(k) + if again := judgeRefusedFirstBuild(link.BuildResult{Failed: refusedKeyTTL}, req, merge); len(again) != 2 { + t.Fatalf("1173/AC1: view refused again is held as %+v, want it once", again) + } +} + +// 1173/AC3 (review round 1, item 1): a held merge is asked again for its own held modules' directories, not by the rule of +// a first merge, which finds nothing once another module of the repository is registered. +func TestAHeldMergeIsAskedAgainForItsHeldModulesAlone(t *testing.T) { + k := keptMerge{Held: []heldFirstBuild{{Module: "watchman", Path: "watchman"}, {Module: "mesh-delivery", Path: ""}, + {Module: "watchman", Path: "/watchman/"}}} + if got := heldDirsOf(k); strings.Join(got, ",") != "watchman,." { + t.Fatalf("1173/AC3: a held merge asks again %v, want watchman and the root once each", got) + } +} + // 1173/AC3 (the part that needs no store): only a plan that ended delivered with build-agent built in it is the end a held // first build waits for. func TestOnlyADeliveredPlanOfBuildAgentIsWhatAHeldFirstBuildWaitsFor(t *testing.T) {