internal/store/builds_test.go

  1package store
  2
  3import (
  4	"strings"
  5	"testing"
  6)
  7
  8// A runner that dies between claiming a build and reporting it leaves the row
  9// claimed. The next claim resolves it rather than leaving the build running and
 10// the commit pending forever.
 11func TestReapStaleBuilds(t *testing.T) {
 12	s := open(t)
 13	if err := s.MigrateUp(); err != nil {
 14		t.Fatal(err)
 15	}
 16	uid, err := s.CreateUser("cmc", true)
 17	if err != nil {
 18		t.Fatal(err)
 19	}
 20	if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil {
 21		t.Fatal(err)
 22	}
 23
 24	stuck, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, true)
 25	if err != nil {
 26		t.Fatal(err)
 27	}
 28	fresh, err := s.CreateBuild(1, "pages", "abc123", "main", `["true"]`, true)
 29	if err != nil {
 30		t.Fatal(err)
 31	}
 32
 33	// Claim both, then age only the first past the deadline.
 34	for range 2 {
 35		if _, ok, err := s.ClaimBuild(nil); err != nil || !ok {
 36			t.Fatalf("claim: %v ok=%v", err, ok)
 37		}
 38	}
 39	if _, err := s.DB.Exec(
 40		`UPDATE builds SET started_at = '2020-01-01T00:00:00Z' WHERE number = ?`, stuck); err != nil {
 41		t.Fatal(err)
 42	}
 43
 44	reaped, err := s.ReapStaleBuilds()
 45	if err != nil {
 46		t.Fatal(err)
 47	}
 48	if len(reaped) != 1 || reaped[0].Number != stuck {
 49		t.Fatalf("reaped %+v, want only build %d", reaped, stuck)
 50	}
 51
 52	b, err := s.BuildByNumber(1, stuck)
 53	if err != nil {
 54		t.Fatal(err)
 55	}
 56	if b.Status != "failure" || b.FinishedAt == "" {
 57		t.Fatalf("stale build is %s finished %q, want failure with a timestamp", b.Status, b.FinishedAt)
 58	}
 59	log, err := s.BuildLog(b.ID)
 60	if err != nil {
 61		t.Fatal(err)
 62	}
 63	if !strings.Contains(string(log), "abandoned") {
 64		t.Fatalf("log does not say why it failed: %q", log)
 65	}
 66
 67	// A build still inside the deadline is left alone.
 68	if b, err := s.BuildByNumber(1, fresh); err != nil || b.Status != "running" {
 69		t.Fatalf("fresh build is %v (%v), want running", b.Status, err)
 70	}
 71}
 72
 73// Checks on a merge request report how long their build ran, which means
 74// pairing ci/<job> statuses with builds on the same commit.
 75func TestBuildsForCommitTiming(t *testing.T) {
 76	s := open(t)
 77	if err := s.MigrateUp(); err != nil {
 78		t.Fatal(err)
 79	}
 80	uid, err := s.CreateUser("cmc", true)
 81	if err != nil {
 82		t.Fatal(err)
 83	}
 84	repoID, err := s.CreateRepo("user", uid, "lib", "public")
 85	if err != nil {
 86		t.Fatal(err)
 87	}
 88	// Two runs of the same job on one commit: the retry is what counts.
 89	for range 2 {
 90		if _, err := s.CreateBuild(repoID, "test", "abc123", "main", `["true"]`, true); err != nil {
 91			t.Fatal(err)
 92		}
 93	}
 94	if _, err := s.CreateBuild(repoID, "lint", "def456", "main", `["true"]`, true); err != nil {
 95		t.Fatal(err)
 96	}
 97	if _, err := s.DB.Exec(`UPDATE builds SET started_at = '2026-08-28T04:42:54Z',
 98		finished_at = '2026-08-28T04:44:06Z', status = 'success' WHERE number = 2`); err != nil {
 99		t.Fatal(err)
100	}
101
102	byJob, err := s.BuildsForCommit(repoID, "abc123")
103	if err != nil {
104		t.Fatal(err)
105	}
106	if len(byJob) != 1 {
107		t.Fatalf("builds for commit: %+v", byJob)
108	}
109	b := byJob["test"]
110	if b.Number != 2 {
111		t.Fatalf("older run won: %d", b.Number)
112	}
113	if got := b.Elapsed().String(); got != "1m12s" {
114		t.Fatalf("elapsed: %s", got)
115	}
116	// A build that never finished has no duration to report.
117	if d := byJob["lint"].Elapsed(); d != 0 {
118		t.Fatalf("unfinished build reported %s", d)
119	}
120}
121
122// A runner that names repositories claims only their builds, so a runner on a
123// machine that should not execute every repository's steps does not pick one
124// up by being first to ask.
125func TestClaimBuildScopedToRepos(t *testing.T) {
126	s := open(t)
127	if err := s.MigrateUp(); err != nil {
128		t.Fatal(err)
129	}
130	uid, err := s.CreateUser("cmc", true)
131	if err != nil {
132		t.Fatal(err)
133	}
134	mine, err := s.CreateRepo("user", uid, "site", "public")
135	if err != nil {
136		t.Fatal(err)
137	}
138	theirs, err := s.CreateRepo("user", uid, "stranger", "public")
139	if err != nil {
140		t.Fatal(err)
141	}
142	// Queued first, so an unscoped claim would take it.
143	if _, err := s.CreateBuild(theirs, "evil", "abc123", "main", `["true"]`, true); err != nil {
144		t.Fatal(err)
145	}
146	wanted, err := s.CreateBuild(mine, "deploy", "def456", "main", `["true"]`, true)
147	if err != nil {
148		t.Fatal(err)
149	}
150
151	b, ok, err := s.ClaimBuild([]int64{mine})
152	if err != nil || !ok {
153		t.Fatalf("claim: %v ok=%v", err, ok)
154	}
155	if b.RepoID != mine || b.Number != wanted {
156		t.Fatalf("claimed repo %d build %d, want repo %d build %d",
157			b.RepoID, b.Number, mine, wanted)
158	}
159
160	// Nothing left for that scope, even though another repo's build is pending.
161	if _, ok, err := s.ClaimBuild([]int64{mine}); err != nil || ok {
162		t.Fatalf("second scoped claim: err=%v ok=%v, want no build", err, ok)
163	}
164	// An unscoped runner still takes it.
165	if b, ok, err := s.ClaimBuild(nil); err != nil || !ok || b.RepoID != theirs {
166		t.Fatalf("unscoped claim: err=%v ok=%v repo=%d", err, ok, b.RepoID)
167	}
168}
169
170// A log that stops at the cap reads exactly like a build that died mid-step,
171// which is what sent people hunting for a test failure that was never there.
172// It says so instead, once.
173func TestBuildLogSaysWhenItTruncates(t *testing.T) {
174	s := open(t)
175	if err := s.MigrateUp(); err != nil {
176		t.Fatal(err)
177	}
178	uid, err := s.CreateUser("cmc", true)
179	if err != nil {
180		t.Fatal(err)
181	}
182	if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil {
183		t.Fatal(err)
184	}
185	id, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, true)
186	if err != nil {
187		t.Fatal(err)
188	}
189
190	chunk := make([]byte, 256<<10)
191	for i := range chunk {
192		chunk[i] = 'x'
193	}
194	// Well past the cap, so plenty of appends land after it.
195	for written := 0; written < MaxBuildLog+(4*len(chunk)); written += len(chunk) {
196		if err := s.AppendBuildLog(id, chunk); err != nil {
197			t.Fatal(err)
198		}
199	}
200
201	log, err := s.BuildLog(id)
202	if err != nil {
203		t.Fatal(err)
204	}
205	if n := strings.Count(string(log), "log truncated"); n != 1 {
206		t.Errorf("truncation notice appears %d times, want exactly 1", n)
207	}
208	if !strings.HasSuffix(string(log), string(truncNotice)) {
209		t.Error("notice is not at the end of the log")
210	}
211	if len(log) > MaxBuildLog+len(truncNotice)+len(chunk) {
212		t.Errorf("log grew to %d, past the cap plus one chunk", len(log))
213	}
214}