internal/store/builds_test.go
529 lines · 15967 bytes
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, false); 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}, false)
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}, false); 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, false); 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}
215
216// A success is found by tree across commits; an empty tree never matches,
217// so builds queued without one (scheduled, tag) are never reused (#177).
218func TestSuccessBuildForTree(t *testing.T) {
219 s := open(t)
220 if err := s.MigrateUp(); err != nil {
221 t.Fatal(err)
222 }
223 uid, err := s.CreateUser("cmc", true)
224 if err != nil {
225 t.Fatal(err)
226 }
227 repoID, err := s.CreateRepo("user", uid, "app", "public")
228 if err != nil {
229 t.Fatal(err)
230 }
231 if _, err := s.CreateBuild(repoID, "unit", "aaa", "main", `["true"]`, "", "tree1", true); err != nil {
232 t.Fatal(err)
233 }
234 b, _ := s.BuildsForCommit(repoID, "aaa")
235 if _, ok, err := s.ClaimBuild([]int64{repoID}, false); err != nil || !ok {
236 t.Fatalf("claim: ok=%v err=%v", ok, err)
237 }
238 if err := s.FinishBuild(b["unit"].ID, "success"); err != nil {
239 t.Fatal(err)
240 }
241 if prev, ok, _ := s.SuccessBuildForTree(repoID, "tree1", "unit"); !ok || prev.SHA != "aaa" {
242 t.Fatalf("success not found by tree: ok=%v prev=%+v", ok, prev)
243 }
244 if _, ok, _ := s.SuccessBuildForTree(repoID, "tree1", "other"); ok {
245 t.Error("matched a different job")
246 }
247 if _, ok, _ := s.SuccessBuildForTree(repoID, "", "unit"); ok {
248 t.Error("an empty tree matched")
249 }
250}
251
252// A running build whose log stream ended is reaped after StaleLogGrace,
253// well before the deadline; one whose stream is still open is not (#179).
254func TestReapStaleBuildsAfterLogClosed(t *testing.T) {
255 s := open(t)
256 if err := s.MigrateUp(); err != nil {
257 t.Fatal(err)
258 }
259 uid, _ := s.CreateUser("cmc", true)
260 repoID, _ := s.CreateRepo("user", uid, "app", "public")
261 for _, job := range []string{"gone", "alive"} {
262 if _, err := s.CreateBuild(repoID, job, "abc", "main", `["true"]`, "", "", true); err != nil {
263 t.Fatal(err)
264 }
265 if _, ok, err := s.ClaimBuild([]int64{repoID}, false); err != nil || !ok {
266 t.Fatalf("claim %s: %v", job, err)
267 }
268 }
269 builds, _ := s.BuildsForCommit(repoID, "abc")
270 gone := builds["gone"].ID
271 if err := s.MarkBuildLogClosed(gone); err != nil {
272 t.Fatal(err)
273 }
274 // Just closed: within the grace period, nothing is reaped.
275 if stale, _ := s.ReapStaleBuilds(); len(stale) != 0 {
276 t.Fatalf("reaped inside the grace period: %+v", stale)
277 }
278 // Backdate the close past the grace period.
279 if _, err := s.DB.Exec("UPDATE builds SET log_closed_at = '2020-01-01T00:00:00Z' WHERE id = ?", gone); err != nil {
280 t.Fatal(err)
281 }
282 stale, err := s.ReapStaleBuilds()
283 if err != nil {
284 t.Fatal(err)
285 }
286 if len(stale) != 1 || stale[0].ID != gone {
287 t.Fatalf("reaped %+v, want only the build whose log closed", stale)
288 }
289 if b, _ := s.BuildByID(gone); b.Status != "failure" {
290 t.Errorf("reaped build is %s, want failure", b.Status)
291 }
292 if b, _ := s.BuildByID(builds["alive"].ID); b.Status != "running" {
293 t.Errorf("build with an open stream is %s, want running", b.Status)
294 }
295 // Marking is a no-op on a build that is no longer running.
296 if err := s.MarkBuildLogClosed(gone); err != nil {
297 t.Fatal(err)
298 }
299}
300
301// AVG is a float in SQLite; the stats scan it as whole seconds.
302func TestQueueStatsFractionalAverage(t *testing.T) {
303 s := open(t)
304 if err := s.MigrateUp(); err != nil {
305 t.Fatal(err)
306 }
307 uid, err := s.CreateUser("cmc", true)
308 if err != nil {
309 t.Fatal(err)
310 }
311 if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil {
312 t.Fatal(err)
313 }
314 for range 2 {
315 if _, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, "", "", true); err != nil {
316 t.Fatal(err)
317 }
318 if _, ok, err := s.ClaimBuild(nil, false); err != nil || !ok {
319 t.Fatalf("claim: %v ok=%v", err, ok)
320 }
321 }
322 // Waits of 1 s and 2 s: an average of 1.5.
323 if _, err := s.DB.Exec(`UPDATE builds SET created_at = strftime('%Y-%m-%dT%H:%M:%SZ', started_at, '-' || number || ' seconds')`); err != nil {
324 t.Fatal(err)
325 }
326 q, err := s.QueueStats()
327 if err != nil {
328 t.Fatal(err)
329 }
330 if q.Claimed24h != 2 || q.ClaimWaitAvgS != 1 || q.ClaimWaitMaxS != 2 || q.Pending != 0 || q.Reaped24h != 0 {
331 t.Fatalf("stats: %+v", q)
332 }
333}
334
335// ListBuilds narrows on ref, status and job independently, and combines
336// when more than one is given (#224).
337func TestListBuildsFilters(t *testing.T) {
338 s := open(t)
339 if err := s.MigrateUp(); err != nil {
340 t.Fatal(err)
341 }
342 uid, err := s.CreateUser("cmc", true)
343 if err != nil {
344 t.Fatal(err)
345 }
346 repoID, err := s.CreateRepo("user", uid, "app", "public")
347 if err != nil {
348 t.Fatal(err)
349 }
350 if _, err := s.CreateBuild(repoID, "unit", "aaa", "main", `["true"]`, "", "", true); err != nil {
351 t.Fatal(err)
352 }
353 if _, err := s.CreateBuild(repoID, "lint", "bbb", "feature", `["true"]`, "", "", true); err != nil {
354 t.Fatal(err)
355 }
356 if err := s.FinishBuild(mustClaim(t, s, repoID).ID, "failure"); err != nil {
357 t.Fatal(err)
358 }
359
360 all, err := s.ListBuilds(repoID, BuildFilter{}, 10)
361 if err != nil || len(all) != 2 {
362 t.Fatalf("unfiltered: %+v %v", all, err)
363 }
364 if byRef, err := s.ListBuilds(repoID, BuildFilter{Ref: "main"}, 10); err != nil || len(byRef) != 1 || byRef[0].Ref != "main" {
365 t.Fatalf("by ref: %+v %v", byRef, err)
366 }
367 if byJob, err := s.ListBuilds(repoID, BuildFilter{Job: "lint"}, 10); err != nil || len(byJob) != 1 || byJob[0].Job != "lint" {
368 t.Fatalf("by job: %+v %v", byJob, err)
369 }
370 if byStatus, err := s.ListBuilds(repoID, BuildFilter{Status: "failure"}, 10); err != nil || len(byStatus) != 1 || byStatus[0].Status != "failure" {
371 t.Fatalf("by status: %+v %v", byStatus, err)
372 }
373 if combined, err := s.ListBuilds(repoID, BuildFilter{Ref: "main", Status: "failure"}, 10); err != nil || len(combined) != 1 {
374 t.Fatalf("combined filter: %+v %v", combined, err)
375 }
376 if none, err := s.ListBuilds(repoID, BuildFilter{Ref: "main", Status: "pending"}, 10); err != nil || len(none) != 0 {
377 t.Fatalf("non-matching combination: %+v %v", none, err)
378 }
379}
380
381// mustClaim claims the oldest pending build for repoID, failing the test
382// if none is available.
383func mustClaim(t *testing.T, s *Store, repoID int64) Build {
384 t.Helper()
385 b, ok, err := s.ClaimBuild([]int64{repoID}, false)
386 if err != nil || !ok {
387 t.Fatalf("claim: %v ok=%v", err, ok)
388 }
389 return b
390}
391
392// A merge request head from a fork is untrusted. A claim skips it unless
393// the runner asked for untrusted builds, so a runner on someone's laptop
394// never executes a stranger's branch by default.
395func TestClaimBuildSkipsUntrustedUnlessAsked(t *testing.T) {
396 s := open(t)
397 if err := s.MigrateUp(); err != nil {
398 t.Fatal(err)
399 }
400 uid, err := s.CreateUser("cmc", true)
401 if err != nil {
402 t.Fatal(err)
403 }
404 repo, err := s.CreateRepo("user", uid, "app", "public")
405 if err != nil {
406 t.Fatal(err)
407 }
408 // Queued first, so an unfiltered claim would take it.
409 forkBuild, err := s.CreateBuild(repo, "unit", "abc123", "refs/merge-requests/1/head", `["true"]`, "", "", false)
410 if err != nil {
411 t.Fatal(err)
412 }
413 own, err := s.CreateBuild(repo, "unit", "def456", "main", `["true"]`, "", "", true)
414 if err != nil {
415 t.Fatal(err)
416 }
417 b, ok, err := s.ClaimBuild(nil, false)
418 if err != nil || !ok || b.Number != own {
419 t.Fatalf("trusted-only claim: err=%v ok=%v number=%d, want %d", err, ok, b.Number, own)
420 }
421 if _, ok, _ := s.ClaimBuild(nil, false); ok {
422 t.Fatal("trusted-only claim took the fork build")
423 }
424 b, ok, err = s.ClaimBuild(nil, true)
425 if err != nil || !ok || b.Number != forkBuild {
426 t.Fatalf("untrusted claim: err=%v ok=%v number=%d, want %d", err, ok, b.Number, forkBuild)
427 }
428}
429
430// A follower's channel closes on each kind of change to its build, and
431// only its build.
432func TestBuildLogWaitWakes(t *testing.T) {
433 s := open(t)
434 if err := s.MigrateUp(); err != nil {
435 t.Fatal(err)
436 }
437 uid, err := s.CreateUser("cmc", true)
438 if err != nil {
439 t.Fatal(err)
440 }
441 if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil {
442 t.Fatal(err)
443 }
444 newBuild := func() int64 {
445 t.Helper()
446 id, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, "", "", true)
447 if err != nil {
448 t.Fatal(err)
449 }
450 return id
451 }
452 closed := func(ch <-chan struct{}) bool {
453 select {
454 case <-ch:
455 return true
456 default:
457 return false
458 }
459 }
460
461 a, b := newBuild(), newBuild()
462 wa, wb := s.BuildLogWait(a), s.BuildLogWait(b)
463 if err := s.AppendBuildLog(a, []byte("x")); err != nil {
464 t.Fatal(err)
465 }
466 if !closed(wa) {
467 t.Error("append did not wake its build")
468 }
469 if closed(wb) {
470 t.Error("append woke another build")
471 }
472
473 mustClaim(t, s, 1) // claims a, the oldest
474 wa = s.BuildLogWait(a)
475 if err := s.FinishBuild(a, "success"); err != nil {
476 t.Fatal(err)
477 }
478 if !closed(wa) {
479 t.Error("finish did not wake")
480 }
481
482 if err := s.CancelBuild(b); err != nil {
483 t.Fatal(err)
484 }
485 if !closed(wb) {
486 t.Error("cancel did not wake")
487 }
488}
489
490// Offsets are bytes, not characters: || stores the log as text, and a
491// multibyte character must not shift where the next read starts.
492func TestBuildLogFrom(t *testing.T) {
493 s := open(t)
494 if err := s.MigrateUp(); err != nil {
495 t.Fatal(err)
496 }
497 uid, err := s.CreateUser("cmc", true)
498 if err != nil {
499 t.Fatal(err)
500 }
501 if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil {
502 t.Fatal(err)
503 }
504 id, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, "", "", true)
505 if err != nil {
506 t.Fatal(err)
507 }
508 first := "héllo — ok\n"
509 for _, c := range []string{first, "wörld\n"} {
510 if err := s.AppendBuildLog(id, []byte(c)); err != nil {
511 t.Fatal(err)
512 }
513 }
514 status, all, err := s.BuildLogFrom(id, 0)
515 if err != nil || status != "pending" || string(all) != first+"wörld\n" {
516 t.Fatalf("from 0: %q %q %v", status, all, err)
517 }
518 _, rest, err := s.BuildLogFrom(id, int64(len(first)))
519 if err != nil || string(rest) != "wörld\n" {
520 t.Fatalf("from %d: %q %v", len(first), rest, err)
521 }
522 _, none, err := s.BuildLogFrom(id, int64(len(all)))
523 if err != nil || len(none) != 0 {
524 t.Fatalf("from the end: %q %v", none, err)
525 }
526 if _, _, err := s.BuildLogFrom(9999, 0); err != ErrNotFound {
527 t.Fatalf("missing build: %v", err)
528 }
529}