internal/store/builds.go
368 lines · 12357 bytes
1package store
2
3import (
4 "database/sql"
5 "errors"
6 "os"
7 "strconv"
8 "strings"
9 "time"
10)
11
12// Build is one CI job execution for one commit.
13type Build struct {
14 ID int64
15 RepoID int64
16 Number int64
17 Job string
18 SHA string
19 Ref string
20 Steps string // JSON array of shell commands
21 Image string // container image for the steps; "" means the runner default
22 Tree string // the commit's tree; "" when not deduplicated by tree
23 Status string // pending|running|success|failure
24 CreatedAt string
25 StartedAt string
26 FinishedAt string
27 // LogClosedAt is when the runner's log stream ended; "" while it is
28 // open or was never opened. Set on a running build only.
29 LogClosedAt string
30 // Trusted is false for a merge request head fetched from another
31 // repository: its steps run without the target's secrets.
32 Trusted bool
33}
34
35// MaxBuildLog caps a build's stored log; appends past it are dropped.
36const MaxBuildLog = 2 << 20
37
38// truncNotice is appended once when a log first hits the cap. A log that
39// simply stops is indistinguishable from a build that died mid-step, which
40// is the reading that sent people hunting for a nonexistent test failure.
41var truncNotice = []byte("\n[log truncated: reached the " +
42 strconv.Itoa(MaxBuildLog>>20) + " MiB cap; earlier output is above]\n")
43
44// CreateBuild allocates the per-repo build number in the same transaction
45// as the insert, like issue and MR numbers.
46func (s *Store) CreateBuild(repoID int64, job, sha, ref, stepsJSON, image, tree string, trusted bool) (int64, error) {
47 tx, err := s.DB.Begin()
48 if err != nil {
49 return 0, err
50 }
51 defer tx.Rollback()
52 if _, err := tx.Exec("UPDATE repos SET build_counter = build_counter + 1 WHERE id = ?", repoID); err != nil {
53 return 0, err
54 }
55 var n int64
56 if err := tx.QueryRow("SELECT build_counter FROM repos WHERE id = ?", repoID).Scan(&n); err != nil {
57 return 0, err
58 }
59 if _, err := tx.Exec(
60 "INSERT INTO builds (repo_id, number, job, sha, ref, steps, image, tree, trusted) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)",
61 repoID, n, job, sha, ref, stepsJSON, image, tree, trusted); err != nil {
62 return 0, err
63 }
64 return n, tx.Commit()
65}
66
67const buildSelect = `
68 SELECT id, repo_id, number, job, sha, ref, steps, image, tree, status, created_at, started_at, finished_at, log_closed_at, trusted
69 FROM builds`
70
71func scanBuild(row interface{ Scan(...any) error }) (Build, error) {
72 var b Build
73 var trusted int
74 err := row.Scan(&b.ID, &b.RepoID, &b.Number, &b.Job, &b.SHA, &b.Ref, &b.Steps, &b.Image, &b.Tree,
75 &b.Status, &b.CreatedAt, &b.StartedAt, &b.FinishedAt, &b.LogClosedAt, &trusted)
76 b.Trusted = trusted != 0
77 return b, err
78}
79
80// ClaimBuild atomically hands the oldest pending build to a runner.
81// ClaimBuild takes the oldest pending build and marks it running. A
82// non-empty repoIDs restricts the claim to those repositories, which is how
83// a runner on a machine that should not execute every repository's steps
84// limits what it picks up.
85func (s *Store) ClaimBuild(repoIDs []int64) (Build, bool, error) {
86 tx, err := s.DB.Begin()
87 if err != nil {
88 return Build{}, false, err
89 }
90 defer tx.Rollback()
91 query := "SELECT id FROM builds WHERE status = 'pending' ORDER BY id LIMIT 1"
92 args := []any{}
93 if len(repoIDs) > 0 {
94 marks := strings.TrimSuffix(strings.Repeat("?,", len(repoIDs)), ",")
95 query = "SELECT id FROM builds WHERE status = 'pending' AND repo_id IN (" +
96 marks + ") ORDER BY id LIMIT 1"
97 for _, id := range repoIDs {
98 args = append(args, id)
99 }
100 }
101 var id int64
102 err = tx.QueryRow(query, args...).Scan(&id)
103 if errors.Is(err, sql.ErrNoRows) {
104 return Build{}, false, nil
105 }
106 if err != nil {
107 return Build{}, false, err
108 }
109 if _, err := tx.Exec(
110 "UPDATE builds SET status = 'running', started_at = strftime('%Y-%m-%dT%H:%M:%SZ','now') WHERE id = ?", id); err != nil {
111 return Build{}, false, err
112 }
113 b, err := scanBuild(tx.QueryRow(buildSelect+" WHERE id = ?", id))
114 if err != nil {
115 return Build{}, false, err
116 }
117 return b, true, tx.Commit()
118}
119
120// StaleBuildDeadline is how long a claimed build may stay running before the
121// server gives up on it. Comfortably longer than the runner's own -timeout
122// (45m by default), so this only fires when the runner never reported at all —
123// it was killed, restarted, or lost the network mid-build.
124const StaleBuildDeadline = 90 * time.Minute
125
126// staleBuildDeadline is StaleBuildDeadline unless GITBAY_STALE_BUILD_DEADLINE
127// shortens it, which tests do.
128func staleBuildDeadline() time.Duration {
129 if v := os.Getenv("GITBAY_STALE_BUILD_DEADLINE"); v != "" {
130 if d, err := time.ParseDuration(v); err == nil && d > 0 {
131 return d
132 }
133 }
134 return StaleBuildDeadline
135}
136
137// StaleLogGrace is how long a running build may go on after its log
138// stream ended before it is treated as abandoned. The runner reports the
139// outcome right after closing the stream, retrying for about thirty
140// seconds if the server is unreachable; two minutes outlasts that.
141const StaleLogGrace = 2 * time.Minute
142
143// MarkBuildLogClosed records that the runner's log stream for a build
144// ended, on a build still running. A build that finishes normally is
145// reported moments later and the mark is moot; one that is not has lost
146// its runner, and ReapStaleBuilds fails it after StaleLogGrace rather
147// than at the deadline (#179).
148func (s *Store) MarkBuildLogClosed(id int64) error {
149 _, err := s.DB.Exec(`
150 UPDATE builds SET log_closed_at = strftime('%Y-%m-%dT%H:%M:%SZ','now')
151 WHERE id = ? AND status = 'running' AND log_closed_at = ''`, id)
152 return err
153}
154
155// ReapStaleBuilds fails every running build whose runner is gone and
156// returns them, so the caller can resolve their commit statuses: one whose
157// log stream ended more than StaleLogGrace ago with no outcome reported,
158// or one running past the deadline with no stream ever seen. A runner that
159// dies between claiming a build and reporting it otherwise leaves the row
160// claimed forever, and the commit pending forever with it.
161func (s *Store) ReapStaleBuilds() ([]Build, error) {
162 const layout = "2006-01-02T15:04:05Z"
163 now := time.Now().UTC()
164 cutoff := now.Add(-staleBuildDeadline()).Format(layout)
165 logCutoff := now.Add(-StaleLogGrace).Format(layout)
166 rows, err := s.DB.Query(buildSelect+
167 " WHERE status = 'running' AND ((started_at != '' AND started_at < ?)"+
168 " OR (log_closed_at != '' AND log_closed_at < ?))", cutoff, logCutoff)
169 if err != nil {
170 return nil, err
171 }
172 defer rows.Close()
173 var stale []Build
174 for rows.Next() {
175 b, err := scanBuild(rows)
176 if err != nil {
177 return nil, err
178 }
179 stale = append(stale, b)
180 }
181 if err := rows.Err(); err != nil {
182 return nil, err
183 }
184 for _, b := range stale {
185 if err := s.AppendBuildLog(b.ID, []byte(
186 "\nbuild abandoned: the runner never reported an outcome\n")); err != nil {
187 return nil, err
188 }
189 if err := s.FinishBuild(b.ID, "failure"); err != nil {
190 return nil, err
191 }
192 }
193 return stale, nil
194}
195
196// AppendBuildLog adds a chunk to the build's log, dropping bytes past the cap.
197func (s *Store) AppendBuildLog(id int64, chunk []byte) error {
198 res, err := s.DB.Exec(`
199 UPDATE builds SET log = log || ?
200 WHERE id = ? AND length(log) < ?`, chunk, id, MaxBuildLog)
201 if err != nil {
202 return err
203 }
204 if n, _ := res.RowsAffected(); n > 0 {
205 return nil
206 }
207 // Over the cap. The bounds match exactly once: appending the notice puts
208 // the log past the upper bound, so later chunks fall through silently.
209 _, err = s.DB.Exec(`
210 UPDATE builds SET log = log || ?
211 WHERE id = ? AND length(log) >= ? AND length(log) < ?`,
212 truncNotice, id, MaxBuildLog, MaxBuildLog+len(truncNotice))
213 return err
214}
215
216// FinishBuild records the outcome of a running build.
217func (s *Store) FinishBuild(id int64, status string) error {
218 res, err := s.DB.Exec(`
219 UPDATE builds SET status = ?, finished_at = strftime('%Y-%m-%dT%H:%M:%SZ','now')
220 WHERE id = ? AND status = 'running'`, status, id)
221 if err != nil {
222 return err
223 }
224 if n, _ := res.RowsAffected(); n == 0 {
225 return ErrNotFound
226 }
227 return nil
228}
229
230func (s *Store) BuildByID(id int64) (Build, error) {
231 b, err := scanBuild(s.DB.QueryRow(buildSelect+" WHERE id = ?", id))
232 if errors.Is(err, sql.ErrNoRows) {
233 return b, ErrNotFound
234 }
235 return b, err
236}
237
238func (s *Store) BuildByNumber(repoID, number int64) (Build, error) {
239 b, err := scanBuild(s.DB.QueryRow(buildSelect+" WHERE repo_id = ? AND number = ?", repoID, number))
240 if errors.Is(err, sql.ErrNoRows) {
241 return b, ErrNotFound
242 }
243 return b, err
244}
245
246func (s *Store) ListBuilds(repoID int64, limit int) ([]Build, error) {
247 rows, err := s.DB.Query(buildSelect+" WHERE repo_id = ? ORDER BY number DESC LIMIT ?", repoID, limit)
248 if err != nil {
249 return nil, err
250 }
251 defer rows.Close()
252 var out []Build
253 for rows.Next() {
254 b, err := scanBuild(rows)
255 if err != nil {
256 return nil, err
257 }
258 out = append(out, b)
259 }
260 return out, rows.Err()
261}
262
263// BuildLog returns the stored log bytes.
264func (s *Store) BuildLog(id int64) ([]byte, error) {
265 var log []byte
266 err := s.DB.QueryRow("SELECT log FROM builds WHERE id = ?", id).Scan(&log)
267 if errors.Is(err, sql.ErrNoRows) {
268 return nil, ErrNotFound
269 }
270 return log, err
271}
272
273// LatestBuild returns the newest build for a repo, optionally narrowed to
274// one job. It is what a status badge reports.
275func (s *Store) LatestBuild(repoID int64, job string) (Build, error) {
276 q := buildSelect + " WHERE repo_id = ?"
277 args := []any{repoID}
278 if job != "" {
279 q += " AND job = ?"
280 args = append(args, job)
281 }
282 q += " ORDER BY number DESC LIMIT 1"
283 b, err := scanBuild(s.DB.QueryRow(q, args...))
284 if errors.Is(err, sql.ErrNoRows) {
285 return b, ErrNotFound
286 }
287 return b, err
288}
289
290// BuildsForCommit returns the newest build per job for one commit. A merge
291// request's checks are ci/<job> statuses; this is where their timing comes
292// from, in one query rather than one per check.
293func (s *Store) BuildsForCommit(repoID int64, sha string) (map[string]Build, error) {
294 rows, err := s.DB.Query(buildSelect+" WHERE repo_id = ? AND sha = ? ORDER BY number ASC", repoID, sha)
295 if err != nil {
296 return nil, err
297 }
298 defer rows.Close()
299 out := map[string]Build{}
300 for rows.Next() {
301 b, err := scanBuild(rows)
302 if err != nil {
303 return nil, err
304 }
305 out[b.Job] = b // ascending: the last row for a job wins
306 }
307 return out, rows.Err()
308}
309
310// Elapsed reports how long a build ran. Zero until it has both a start and
311// a finish, which is every state but success and failure.
312func (b Build) Elapsed() time.Duration {
313 const layout = "2006-01-02T15:04:05Z"
314 start, err := time.Parse(layout, b.StartedAt)
315 if err != nil {
316 return 0
317 }
318 end, err := time.Parse(layout, b.FinishedAt)
319 if err != nil {
320 return 0
321 }
322 if d := end.Sub(start); d > 0 {
323 return d.Round(time.Second)
324 }
325 return 0
326}
327
328// CancelBuild withdraws a queued or running build. A running one is
329// ended by the runner, which learns of the cancellation when its log
330// session is closed, and whose later report lands on a row that already
331// says cancelled.
332func (s *Store) CancelBuild(id int64) error {
333 res, err := s.DB.Exec(`UPDATE builds SET status = 'cancelled',
334 finished_at = strftime('%Y-%m-%dT%H:%M:%SZ','now') WHERE id = ? AND status IN ('pending', 'running')`, id)
335 if err != nil {
336 return err
337 }
338 if n, _ := res.RowsAffected(); n == 0 {
339 return ErrNotFound
340 }
341 return nil
342}
343
344// SuccessBuildFor finds a passed build of the commit for the job, on any
345// ref: what a cancelled duplicate can point back at.
346// SuccessBuildForTree is SuccessBuildFor keyed by tree rather than
347// commit: a rebase that changes nothing in the tree has already been
348// built (#177). An empty tree never matches.
349func (s *Store) SuccessBuildForTree(repoID int64, tree, job string) (Build, bool, error) {
350 if tree == "" {
351 return Build{}, false, nil
352 }
353 b, err := scanBuild(s.DB.QueryRow(buildSelect+
354 " WHERE repo_id = ? AND tree = ? AND job = ? AND status = 'success' ORDER BY number DESC LIMIT 1", repoID, tree, job))
355 if errors.Is(err, sql.ErrNoRows) {
356 return Build{}, false, nil
357 }
358 return b, err == nil, err
359}
360
361func (s *Store) SuccessBuildFor(repoID int64, sha, job string) (Build, bool, error) {
362 b, err := scanBuild(s.DB.QueryRow(buildSelect+
363 " WHERE repo_id = ? AND sha = ? AND job = ? AND status = 'success' ORDER BY number DESC LIMIT 1", repoID, sha, job))
364 if errors.Is(err, sql.ErrNoRows) {
365 return Build{}, false, nil
366 }
367 return b, err == nil, err
368}