admin runners reports the build queue !350

merged merged by cmc on 2026-09-08 06:11 UTC · krz/gitbay:ci-queue-metrics into main

7 files changed, +60 −7

Layout: unified · split

.gitbay/wiki/Admin.org +4 −1
@@ -403,7 +403,10 @@ necessity, so the boundary is you choosing how to start it.
403 403
404=gitbay dashboard= and =ssh git@<host> admin runners= list every account 404=gitbay dashboard= and =ssh git@<host> admin runners= list every account
405that has polled as a runner: when it last polled, the =-repos= scope it 405that has polled as a runner: when it last polled, the =-repos= scope it
406asked for, and the build it holds. A build a runner claimed and never 406asked for, and the build it holds. =admin runners= also heads the list
407with the queue: builds pending now, and over the last day how many were
408claimed, how long they waited to be claimed (average and worst), and
409how many the reaper ended instead of a runner reporting them. A build a runner claimed and never
407reported is failed by the scheduler's minute tick, whether or not any 410reported is failed by the scheduler's minute tick, whether or not any
408runner is still alive: within about two minutes of its log stream ending 411runner is still alive: within about two minutes of its log stream ending
409with no outcome reported — the runner reports right after closing the 412with no outcome reported — the runner reports right after closing the
cmd/gitbay/main.go +1 −1
@@ -111,7 +111,7 @@ func newRoot() *cobra.Command {
111 ), 111 ),
112 pass("invite", "issue a registration invite and mail its code: --email <address>", passOpts{server: []string{"admin", "invite"}}), 112 pass("invite", "issue a registration invite and mail its code: --email <address>", passOpts{server: []string{"admin", "invite"}}),
113 pass("stats", "instance statistics: counts and per-repository disk usage", passOpts{server: []string{"admin", "stats"}}), 113 pass("stats", "instance statistics: counts and per-repository disk usage", passOpts{server: []string{"admin", "stats"}}),
114 pass("runners", "runner accounts: last poll, scope, the build each holds", passOpts{server: []string{"admin", "runners"}}), 114 pass("runners", "the build queue and runner accounts: last poll, scope, the build each holds", passOpts{server: []string{"admin", "runners"}}),
115 group("repo", "any repository, for moderation (audited)", 115 group("repo", "any repository, for moderation (audited)",
116 pass("list", "every repository with size and last push: [--owner o] [--visibility v] [--limit n] [--cursor c]", passOpts{server: []string{"admin", "repo", "list"}}), 116 pass("list", "every repository with size and last push: [--owner o] [--visibility v] [--limit n] [--cursor c]", passOpts{server: []string{"admin", "repo", "list"}}),
117 pass("archive", "archive a repository: <owner/name>", passOpts{server: []string{"admin", "repo", "archive"}}), 117 pass("archive", "archive a repository: <owner/name>", passOpts{server: []string{"admin", "repo", "archive"}}),
e2e/reap_test.go +11 −3
@@ -80,6 +80,11 @@ func TestStaleBuildReapedWithoutRunner(t *testing.T) {
80 if out, _, _ := inst.ssh(t, aliceKey, "", "build", "log", "alice/app", "1"); !strings.Contains(out, "build abandoned") { 80 if out, _, _ := inst.ssh(t, aliceKey, "", "build", "log", "alice/app", "1"); !strings.Contains(out, "build abandoned") {
81 t.Fatalf("log lacks the abandonment note:\n%s", out) 81 t.Fatalf("log lacks the abandonment note:\n%s", out)
82 } 82 }
83 // The reaper's work is counted, apart from builds runners reported.
84 if out, _, _ := inst.ssh(t, runnerKey, "", "admin", "runners", "--json"); !strings.Contains(out, `"reaped_24h":1`) ||
85 !strings.Contains(out, `"claimed_24h":1`) {
86 t.Fatalf("queue after reap:\n%s", out)
87 }
83} 88}
84 89
85func TestAdminRunners(t *testing.T) { 90func TestAdminRunners(t *testing.T) {
@@ -93,7 +98,8 @@ func TestAdminRunners(t *testing.T) {
93 if _, _, code := inst.ssh(t, aliceKey, "", "admin", "runners"); code != 4 { 98 if _, _, code := inst.ssh(t, aliceKey, "", "admin", "runners"); code != 4 {
94 t.Fatal("non-admin listed runners") 99 t.Fatal("non-admin listed runners")
95 } 100 }
96 if out, _, code := inst.ssh(t, rootKey, "", "admin", "runners", "--json"); code != 0 || strings.TrimSpace(out) != `{"protocol_version":1,"data":[]}` { 101 if out, _, code := inst.ssh(t, rootKey, "", "admin", "runners", "--json"); code != 0 ||
102 strings.TrimSpace(out) != `{"protocol_version":1,"data":{"queue":{"pending":0,"claimed_24h":0,"claim_wait_avg_s":0,"claim_wait_max_s":0,"reaped_24h":0},"runners":[]}}` {
97 t.Fatalf("no runners yet: exit %d %s", code, out) 103 t.Fatalf("no runners yet: exit %d %s", code, out)
98 } 104 }
99 if _, _, code := inst.ssh(t, aliceKey, "", "repo", "create", "alice/app"); code != 0 { 105 if _, _, code := inst.ssh(t, aliceKey, "", "repo", "create", "alice/app"); code != 0 {
@@ -104,7 +110,8 @@ func TestAdminRunners(t *testing.T) {
104 t.Fatal("runner next failed") 110 t.Fatal("runner next failed")
105 } 111 }
106 out, _, _ := inst.ssh(t, rootKey, "", "admin", "runners") 112 out, _, _ := inst.ssh(t, rootKey, "", "admin", "runners")
107 if !strings.HasPrefix(out, "ci\t") || !strings.Contains(out, "\talice/app\tidle") { 113 if !strings.HasPrefix(out, "queue: 0 pending; last 24h: 0 claimed") || !strings.Contains(out, "\nci\t") ||
114 !strings.Contains(out, "\talice/app\tidle") {
108 t.Fatalf("idle runner row:\n%s", out) 115 t.Fatalf("idle runner row:\n%s", out)
109 } 116 }
110 work := t.TempDir() 117 work := t.TempDir()
@@ -133,7 +140,8 @@ func TestAdminRunners(t *testing.T) {
133 if _, _, code := inst.ssh(t, runnerKey, "", "runner", "done", fmt.Sprint(claim.Data.ID), "success"); code != 0 { 140 if _, _, code := inst.ssh(t, runnerKey, "", "runner", "done", fmt.Sprint(claim.Data.ID), "success"); code != 0 {
134 t.Fatal("runner done failed") 141 t.Fatal("runner done failed")
135 } 142 }
136 if out, _, _ := inst.ssh(t, rootKey, "", "admin", "runners"); !strings.Contains(out, "\tany\tidle") { 143 if out, _, _ := inst.ssh(t, rootKey, "", "admin", "runners"); !strings.Contains(out, "\tany\tidle") ||
144 !strings.HasPrefix(out, "queue: 0 pending; last 24h: 1 claimed, wait avg ") {
137 t.Fatalf("runner still holds a build after done:\n%s", out) 145 t.Fatalf("runner still holds a build after done:\n%s", out)
138 } 146 }
139 // Host-local, the same read. 147 // Host-local, the same read.
internal/control/admin.go +12 −2
@@ -30,7 +30,7 @@ func init() {
30 Usage: "admin user demote <username>", 30 Usage: "admin user demote <username>",
31 SSHOnly: true, Run: runAdminUserDemote}) 31 SSHOnly: true, Run: runAdminUserDemote})
32 register(Command{Path: []string{"admin", "runners"}, 32 register(Command{Path: []string{"admin", "runners"},
33 Summary: "runner accounts: last poll, scope, the build each holds (instance admins)", 33 Summary: "the build queue and runner accounts: last poll, scope, the build each holds (instance admins)",
34 Usage: "admin runners", 34 Usage: "admin runners",
35 ReadOnly: true, SSHOnly: true, Run: runAdminRunners}) 35 ReadOnly: true, SSHOnly: true, Run: runAdminRunners})
36 register(Command{Path: []string{"admin", "repo", "list"}, 36 register(Command{Path: []string{"admin", "repo", "list"},
@@ -452,7 +452,17 @@ func runAdminRunners(c *Ctx, args []string) int {
452 if err != nil { 452 if err != nil {
453 return c.fail(protocol.ExitFailure, "%v", err) 453 return c.fail(protocol.ExitFailure, "%v", err)
454 } 454 }
455 return c.emit(runners, func(w io.Writer) { 455 queue, err := c.Store.QueueStats()
456 if err != nil {
457 return c.fail(protocol.ExitFailure, "%v", err)
458 }
459 if runners == nil {
460 runners = []store.Runner{}
461 }
462 d := map[string]any{"queue": queue, "runners": runners}
463 return c.emit(d, func(w io.Writer) {
464 fmt.Fprintf(w, "queue: %d pending; last 24h: %d claimed, wait avg %ds max %ds, %d reaped\n",
465 queue.Pending, queue.Claimed24h, queue.ClaimWaitAvgS, queue.ClaimWaitMaxS, queue.Reaped24h)
456 for _, r := range runners { 466 for _, r := range runners {
457 scope := r.Scope 467 scope := r.Scope
458 if scope == "" { 468 if scope == "" {
internal/store/builds.go +28
@@ -189,10 +189,38 @@ func (s *Store) ReapStaleBuilds() ([]Build, error) {
189 if err := s.FinishBuild(b.ID, "failure"); err != nil { 189 if err := s.FinishBuild(b.ID, "failure"); err != nil {
190 return nil, err 190 return nil, err
191 } 191 }
192 if _, err := s.DB.Exec(`UPDATE builds SET reaped_at = finished_at WHERE id = ?`, b.ID); err != nil {
193 return nil, err
194 }
192 } 195 }
193 return stale, nil 196 return stale, nil
194} 197}
195 198
199// QueueStats is the state of the build queue: what waits now, and over
200// the last day how long a build waited to be claimed and how many were
201// ended by the reaper rather than by a runner's report (#184).
202type QueueStats struct {
203 Pending int64 `json:"pending"`
204 Claimed24h int64 `json:"claimed_24h"`
205 ClaimWaitAvgS int64 `json:"claim_wait_avg_s"`
206 ClaimWaitMaxS int64 `json:"claim_wait_max_s"`
207 Reaped24h int64 `json:"reaped_24h"`
208}
209
210func (s *Store) QueueStats() (QueueStats, error) {
211 var q QueueStats
212 since := time.Now().UTC().Add(-24 * time.Hour).Format("2006-01-02T15:04:05Z")
213 err := s.DB.QueryRow(`SELECT
214 (SELECT COUNT(*) FROM builds WHERE status = 'pending'),
215 COUNT(*),
216 COALESCE(AVG(strftime('%s', started_at) - strftime('%s', created_at)), 0),
217 COALESCE(MAX(strftime('%s', started_at) - strftime('%s', created_at)), 0),
218 (SELECT COUNT(*) FROM builds WHERE reaped_at >= ?)
219 FROM builds WHERE started_at >= ?`, since, since).
220 Scan(&q.Pending, &q.Claimed24h, &q.ClaimWaitAvgS, &q.ClaimWaitMaxS, &q.Reaped24h)
221 return q, err
222}
223
196// AppendBuildLog adds a chunk to the build's log, dropping bytes past the cap. 224// AppendBuildLog adds a chunk to the build's log, dropping bytes past the cap.
197func (s *Store) AppendBuildLog(id int64, chunk []byte) error { 225func (s *Store) AppendBuildLog(id int64, chunk []byte) error {
198 res, err := s.DB.Exec(` 226 res, err := s.DB.Exec(`
internal/store/migrations/0049_build_reaped.down.sql added +1
@@ -0,0 +1 @@
1ALTER TABLE builds DROP COLUMN reaped_at;
internal/store/migrations/0049_build_reaped.up.sql added +3
@@ -0,0 +1,3 @@
1-- When the scheduler failed a build instead of its runner reporting it,
2-- so builds ended by the reaper can be counted (#184).
3ALTER TABLE builds ADD COLUMN reaped_at TEXT NOT NULL DEFAULT '';