internal/store/builds_test.go
214 lines · 6052 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"]`)
25 if err != nil {
26 t.Fatal(err)
27 }
28 fresh, err := s.CreateBuild(1, "pages", "abc123", "main", `["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"]`); err != nil {
91 t.Fatal(err)
92 }
93 }
94 if _, err := s.CreateBuild(repoID, "lint", "def456", "main", `["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"]`); err != nil {
144 t.Fatal(err)
145 }
146 wanted, err := s.CreateBuild(mine, "deploy", "def456", "main", `["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"]`)
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}