| @@ -0,0 +1,1100 @@ |
| 1 | # build log --follow Implementation Plan |
| 2 | |
| 3 | > **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. |
| 4 | |
| 5 | **Goal:** `build log <owner/name> <n> --follow` streams a build's log until the build has an outcome, and the web build page streams the same command without JavaScript. |
| 6 | |
| 7 | **Architecture:** The store wakes waiters when a build's row changes and reads the log from a byte offset. The control command loops read → write → wait. The web handler renders `build.html` with a marker where the log goes, writes the part before it, dispatches the command with a writer that HTML-escapes and flushes, then writes the rest. |
| 8 | |
| 9 | **Tech Stack:** Go, SQLite (modernc), `golang.org/x/crypto/ssh`, `html/template`, `net/http`. |
| 10 | |
| 11 | **Spec:** `docs/specs/2026-09-23-build-log-follow-design.md` |
| 12 | |
| 13 | ## Global Constraints |
| 14 | |
| 15 | - Work in `/Users/cmc/git/krz/gitbay-follow` (branch `build-log-follow`). Never touch `/Users/cmc/git/krz/gitbay`. |
| 16 | - Every commit is signed (the repo signs by config; do not pass `--no-gpg-sign`). Messages reference `Ref #250`; the last commit says `Closes #250`. No attribution lines of any kind. |
| 17 | - Write files with the editor tool, not heredocs. |
| 18 | - Locally run: `go build ./...`, `go vet` on touched packages, unit tests of touched packages, and only the one e2e test being written. CI runs the rest. |
| 19 | - Comments: plain, factual, match the surrounding density. No before/after narration. |
| 20 | - Follow cap: 8 per account. Fallback re-read: 2 seconds. Settle after an outcome: 1 second. |
| 21 | - The outcome line on stderr is exactly `build <n> <status>`; exit 0 whatever the outcome. |
| 22 | - The web outcome line is exactly `<p class="notice" role="status">build finished: <status></p>`. |
| 23 | |
| 24 | --- |
| 25 | |
| 26 | ### Task 1: Store — wake followers and read from an offset |
| 27 | |
| 28 | **Files:** |
| 29 | - Modify: `internal/store/store.go` (the `Store` struct, ~line 22) |
| 30 | - Modify: `internal/store/builds.go` (`AppendBuildLog` ~228, `FinishBuild` ~248, `CancelBuild` ~393; new functions after `BuildLog` ~325) |
| 31 | - Test: `internal/store/builds_test.go` |
| 32 | |
| 33 | **Interfaces:** |
| 34 | - Produces: `func (s *Store) BuildLogWait(id int64) <-chan struct{}`; `func (s *Store) BuildLogFrom(id, offset int64) (status string, chunk []byte, err error)`; unexported `func (s *Store) wakeBuild(id int64)`. |
| 35 | |
| 36 | - [ ] **Step 1: Write the failing tests** — append to `internal/store/builds_test.go`: |
| 37 | |
| 38 | ```go |
| 39 | // A follower's channel closes on each kind of change to its build, and |
| 40 | // only its build. |
| 41 | func TestBuildLogWaitWakes(t *testing.T) { |
| 42 | s := open(t) |
| 43 | if err := s.MigrateUp(); err != nil { |
| 44 | t.Fatal(err) |
| 45 | } |
| 46 | uid, err := s.CreateUser("cmc", true) |
| 47 | if err != nil { |
| 48 | t.Fatal(err) |
| 49 | } |
| 50 | if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil { |
| 51 | t.Fatal(err) |
| 52 | } |
| 53 | newBuild := func() int64 { |
| 54 | t.Helper() |
| 55 | id, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, "", "", true) |
| 56 | if err != nil { |
| 57 | t.Fatal(err) |
| 58 | } |
| 59 | return id |
| 60 | } |
| 61 | closed := func(ch <-chan struct{}) bool { |
| 62 | select { |
| 63 | case <-ch: |
| 64 | return true |
| 65 | default: |
| 66 | return false |
| 67 | } |
| 68 | } |
| 69 | |
| 70 | a, b := newBuild(), newBuild() |
| 71 | wa, wb := s.BuildLogWait(a), s.BuildLogWait(b) |
| 72 | if err := s.AppendBuildLog(a, []byte("x")); err != nil { |
| 73 | t.Fatal(err) |
| 74 | } |
| 75 | if !closed(wa) { |
| 76 | t.Error("append did not wake its build") |
| 77 | } |
| 78 | if closed(wb) { |
| 79 | t.Error("append woke another build") |
| 80 | } |
| 81 | |
| 82 | mustClaim(t, s, 1) // claims a, the oldest |
| 83 | wa = s.BuildLogWait(a) |
| 84 | if err := s.FinishBuild(a, "success"); err != nil { |
| 85 | t.Fatal(err) |
| 86 | } |
| 87 | if !closed(wa) { |
| 88 | t.Error("finish did not wake") |
| 89 | } |
| 90 | |
| 91 | if err := s.CancelBuild(b); err != nil { |
| 92 | t.Fatal(err) |
| 93 | } |
| 94 | if !closed(wb) { |
| 95 | t.Error("cancel did not wake") |
| 96 | } |
| 97 | } |
| 98 | |
| 99 | // Offsets are bytes, not characters: || stores the log as text, and a |
| 100 | // multibyte character must not shift where the next read starts. |
| 101 | func TestBuildLogFrom(t *testing.T) { |
| 102 | s := open(t) |
| 103 | if err := s.MigrateUp(); err != nil { |
| 104 | t.Fatal(err) |
| 105 | } |
| 106 | uid, err := s.CreateUser("cmc", true) |
| 107 | if err != nil { |
| 108 | t.Fatal(err) |
| 109 | } |
| 110 | if _, err := s.CreateRepo("user", uid, "orgo", "public"); err != nil { |
| 111 | t.Fatal(err) |
| 112 | } |
| 113 | id, err := s.CreateBuild(1, "test", "abc123", "main", `["true"]`, "", "", true) |
| 114 | if err != nil { |
| 115 | t.Fatal(err) |
| 116 | } |
| 117 | first := "héllo — ok\n" |
| 118 | for _, c := range []string{first, "wörld\n"} { |
| 119 | if err := s.AppendBuildLog(id, []byte(c)); err != nil { |
| 120 | t.Fatal(err) |
| 121 | } |
| 122 | } |
| 123 | status, all, err := s.BuildLogFrom(id, 0) |
| 124 | if err != nil || status != "pending" || string(all) != first+"wörld\n" { |
| 125 | t.Fatalf("from 0: %q %q %v", status, all, err) |
| 126 | } |
| 127 | _, rest, err := s.BuildLogFrom(id, int64(len(first))) |
| 128 | if err != nil || string(rest) != "wörld\n" { |
| 129 | t.Fatalf("from %d: %q %v", len(first), rest, err) |
| 130 | } |
| 131 | _, none, err := s.BuildLogFrom(id, int64(len(all))) |
| 132 | if err != nil || len(none) != 0 { |
| 133 | t.Fatalf("from the end: %q %v", none, err) |
| 134 | } |
| 135 | if _, _, err := s.BuildLogFrom(9999, 0); err != ErrNotFound { |
| 136 | t.Fatalf("missing build: %v", err) |
| 137 | } |
| 138 | } |
| 139 | ``` |
| 140 | |
| 141 | - [ ] **Step 2: Run to see them fail** |
| 142 | |
| 143 | Run: `go test ./internal/store/ -run 'TestBuildLogWaitWakes|TestBuildLogFrom' -count=1` |
| 144 | Expected: build failure, `s.BuildLogWait undefined`. |
| 145 | |
| 146 | - [ ] **Step 3: Implement** |
| 147 | |
| 148 | In `internal/store/store.go`, add `"sync"` to the imports and the fields: |
| 149 | |
| 150 | ```go |
| 151 | type Store struct { |
| 152 | DB *sql.DB |
| 153 | |
| 154 | // logWait holds one channel per build someone is following, closed |
| 155 | // by the next change to that build's row (BuildLogWait). |
| 156 | logMu sync.Mutex |
| 157 | logWait map[int64]chan struct{} |
| 158 | } |
| 159 | ``` |
| 160 | |
| 161 | In `internal/store/builds.go`, after `BuildLog`: |
| 162 | |
| 163 | ```go |
| 164 | // BuildLogWait returns a channel closed by the next append to, finish of |
| 165 | // or cancel of the build. Take it before reading, so a change between the |
| 166 | // read and the wait still wakes the reader. Only this process's writes |
| 167 | // wake it. |
| 168 | func (s *Store) BuildLogWait(id int64) <-chan struct{} { |
| 169 | s.logMu.Lock() |
| 170 | defer s.logMu.Unlock() |
| 171 | if s.logWait == nil { |
| 172 | s.logWait = map[int64]chan struct{}{} |
| 173 | } |
| 174 | ch, ok := s.logWait[id] |
| 175 | if !ok { |
| 176 | ch = make(chan struct{}) |
| 177 | s.logWait[id] = ch |
| 178 | } |
| 179 | return ch |
| 180 | } |
| 181 | |
| 182 | func (s *Store) wakeBuild(id int64) { |
| 183 | s.logMu.Lock() |
| 184 | defer s.logMu.Unlock() |
| 185 | if ch, ok := s.logWait[id]; ok { |
| 186 | close(ch) |
| 187 | delete(s.logWait, id) |
| 188 | } |
| 189 | } |
| 190 | |
| 191 | // BuildLogFrom returns the build's status and its log past offset bytes, |
| 192 | // read together so a terminal status comes with every byte before it. |
| 193 | // The cast matters: || stores the log as text, and substr on text counts |
| 194 | // characters. |
| 195 | func (s *Store) BuildLogFrom(id, offset int64) (string, []byte, error) { |
| 196 | var status string |
| 197 | var chunk []byte |
| 198 | err := s.DB.QueryRow(`SELECT status, substr(CAST(log AS BLOB), ?) FROM builds WHERE id = ?`, |
| 199 | offset+1, id).Scan(&status, &chunk) |
| 200 | if errors.Is(err, sql.ErrNoRows) { |
| 201 | return "", nil, ErrNotFound |
| 202 | } |
| 203 | return status, chunk, err |
| 204 | } |
| 205 | ``` |
| 206 | |
| 207 | Wake after each successful write. In `AppendBuildLog`, replace the tail so both paths wake: |
| 208 | |
| 209 | ```go |
| 210 | if n, _ := res.RowsAffected(); n > 0 { |
| 211 | s.wakeBuild(id) |
| 212 | return nil |
| 213 | } |
| 214 | // Over the cap. The bounds match exactly once: appending the notice puts |
| 215 | // the log past the upper bound, so later chunks fall through silently. |
| 216 | _, err = s.DB.Exec(` |
| 217 | UPDATE builds SET log = log || ? |
| 218 | WHERE id = ? AND length(log) >= ? AND length(log) < ?`, |
| 219 | truncNotice, id, MaxBuildLog, MaxBuildLog+len(truncNotice)) |
| 220 | if err == nil { |
| 221 | s.wakeBuild(id) |
| 222 | } |
| 223 | return err |
| 224 | ``` |
| 225 | |
| 226 | In `FinishBuild`, before the final `return nil`: `s.wakeBuild(id)`. In `CancelBuild`, the same, before its final `return nil`. |
| 227 | |
| 228 | - [ ] **Step 4: Run the tests and vet** |
| 229 | |
| 230 | Run: `go test ./internal/store/ -count=1 && go vet ./internal/store/` |
| 231 | Expected: `ok`, vet silent (no copylocks: `Store` is only ever `&Store{...}` in `Open`). |
| 232 | |
| 233 | - [ ] **Step 5: Commit** |
| 234 | |
| 235 | ```bash |
| 236 | git add internal/store/store.go internal/store/builds.go internal/store/builds_test.go |
| 237 | git commit -m "store: wake build log followers, read the log from an offset |
| 238 | |
| 239 | Ref #250" |
| 240 | ``` |
| 241 | |
| 242 | --- |
| 243 | |
| 244 | ### Task 2: Control — `build log --follow` |
| 245 | |
| 246 | **Files:** |
| 247 | - Modify: `internal/control/control.go` (`Ctx`, ~line 21) |
| 248 | - Modify: `internal/control/build.go` (registration ~29, `runBuildLog` ~198) |
| 249 | - Create: `internal/control/buildfollow.go` |
| 250 | - Create: `internal/control/buildfollow_test.go` |
| 251 | - Modify: `cmd/gitbay/main.go:51` (help string) |
| 252 | |
| 253 | **Interfaces:** |
| 254 | - Consumes: `Store.BuildLogWait`, `Store.BuildLogFrom` (Task 1). |
| 255 | - Produces: `Ctx.Done <-chan struct{}`; the command `build log <owner/name> <n> [--follow]`; package vars `followSettle`, `followPoll` (tests shorten them); `maxFollows = 8`. |
| 256 | |
| 257 | - [ ] **Step 1: Write the failing tests** — `internal/control/buildfollow_test.go`: |
| 258 | |
| 259 | ```go |
| 260 | package control |
| 261 | |
| 262 | import ( |
| 263 | "bytes" |
| 264 | "strings" |
| 265 | "testing" |
| 266 | "time" |
| 267 | |
| 268 | "gitbay.org/gitbay/internal/protocol" |
| 269 | "gitbay.org/gitbay/internal/store" |
| 270 | ) |
| 271 | |
| 272 | // follow starts build log --follow on build 1 of repo and returns the |
| 273 | // buffers and a channel carrying the exit code. |
| 274 | func follow(t *testing.T, st *store.Store, uid int64, repo store.Repo, done <-chan struct{}) (*bytes.Buffer, *bytes.Buffer, chan int) { |
| 275 | t.Helper() |
| 276 | u, err := st.UserByID(uid) |
| 277 | if err != nil { |
| 278 | t.Fatal(err) |
| 279 | } |
| 280 | var out, errOut bytes.Buffer |
| 281 | c := &Ctx{User: u, Scope: "full", Store: st, Stdin: strings.NewReader(""), |
| 282 | Stdout: &out, Stderr: &errOut, Done: done} |
| 283 | res := make(chan int, 1) |
| 284 | go func() { res <- Dispatch(c, []string{"build", "log", repo.Path(), "1", "--follow"}) }() |
| 285 | return &out, &errOut, res |
| 286 | } |
| 287 | |
| 288 | func waitExit(t *testing.T, res chan int) int { |
| 289 | t.Helper() |
| 290 | select { |
| 291 | case code := <-res: |
| 292 | return code |
| 293 | case <-time.After(10 * time.Second): |
| 294 | t.Fatal("follow did not end") |
| 295 | return -1 |
| 296 | } |
| 297 | } |
| 298 | |
| 299 | func shortFollowTimers(t *testing.T) { |
| 300 | settle, poll := followSettle, followPoll |
| 301 | followSettle, followPoll = 200*time.Millisecond, 50*time.Millisecond |
| 302 | t.Cleanup(func() { followSettle, followPoll = settle, poll }) |
| 303 | } |
| 304 | |
| 305 | // The follow prints the stored log, then what arrives, and ends with the |
| 306 | // outcome on stderr once the build finishes. |
| 307 | func TestBuildLogFollow(t *testing.T) { |
| 308 | shortFollowTimers(t) |
| 309 | st, repo, uid := newQueueTestRepo(t) |
| 310 | id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true) |
| 311 | if err != nil { |
| 312 | t.Fatal(err) |
| 313 | } |
| 314 | st.AppendBuildLog(id, []byte("queued\n")) |
| 315 | out, errOut, res := follow(t, st, uid, repo, nil) |
| 316 | |
| 317 | if _, ok, err := st.ClaimBuild([]int64{repo.ID}, false); err != nil || !ok { |
| 318 | t.Fatalf("claim: %v %v", ok, err) |
| 319 | } |
| 320 | st.AppendBuildLog(id, []byte("step one\n")) |
| 321 | st.AppendBuildLog(id, []byte("step two\n")) |
| 322 | if err := st.FinishBuild(id, "success"); err != nil { |
| 323 | t.Fatal(err) |
| 324 | } |
| 325 | if code := waitExit(t, res); code != protocol.ExitOK { |
| 326 | t.Fatalf("exit %d: %s", code, errOut) |
| 327 | } |
| 328 | if got := out.String(); got != "queued\nstep one\nstep two\n" { |
| 329 | t.Errorf("stdout %q", got) |
| 330 | } |
| 331 | if got := strings.TrimSpace(errOut.String()); got != "build 1 success" { |
| 332 | t.Errorf("stderr %q", got) |
| 333 | } |
| 334 | } |
| 335 | |
| 336 | // A cancel ends the follow, and the line the cancel appends after the |
| 337 | // status change still arrives. |
| 338 | func TestBuildLogFollowCancel(t *testing.T) { |
| 339 | shortFollowTimers(t) |
| 340 | st, repo, uid := newQueueTestRepo(t) |
| 341 | id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true) |
| 342 | if err != nil { |
| 343 | t.Fatal(err) |
| 344 | } |
| 345 | out, errOut, res := follow(t, st, uid, repo, nil) |
| 346 | if err := st.CancelBuild(id); err != nil { |
| 347 | t.Fatal(err) |
| 348 | } |
| 349 | st.AppendBuildLog(id, []byte("cancelled by alice before a runner claimed it\n")) |
| 350 | if code := waitExit(t, res); code != protocol.ExitOK { |
| 351 | t.Fatalf("exit %d: %s", code, errOut) |
| 352 | } |
| 353 | if !strings.Contains(out.String(), "cancelled by alice") { |
| 354 | t.Errorf("the cancel line did not arrive: %q", out) |
| 355 | } |
| 356 | if got := strings.TrimSpace(errOut.String()); got != "build 1 cancelled" { |
| 357 | t.Errorf("stderr %q", got) |
| 358 | } |
| 359 | } |
| 360 | |
| 361 | // Closing Done ends a follow of a build that is still running. |
| 362 | func TestBuildLogFollowDone(t *testing.T) { |
| 363 | shortFollowTimers(t) |
| 364 | st, repo, uid := newQueueTestRepo(t) |
| 365 | if _, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true); err != nil { |
| 366 | t.Fatal(err) |
| 367 | } |
| 368 | done := make(chan struct{}) |
| 369 | _, _, res := follow(t, st, uid, repo, done) |
| 370 | close(done) |
| 371 | if code := waitExit(t, res); code != protocol.ExitFailure { |
| 372 | t.Fatalf("exit %d, want %d", code, protocol.ExitFailure) |
| 373 | } |
| 374 | } |
| 375 | |
| 376 | // An account holding maxFollows is refused another. |
| 377 | func TestBuildLogFollowCap(t *testing.T) { |
| 378 | st, repo, uid := newQueueTestRepo(t) |
| 379 | if _, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true); err != nil { |
| 380 | t.Fatal(err) |
| 381 | } |
| 382 | followMu.Lock() |
| 383 | follows[uid] = maxFollows |
| 384 | followMu.Unlock() |
| 385 | t.Cleanup(func() { |
| 386 | followMu.Lock() |
| 387 | delete(follows, uid) |
| 388 | followMu.Unlock() |
| 389 | }) |
| 390 | _, errOut, res := follow(t, st, uid, repo, nil) |
| 391 | if code := waitExit(t, res); code != protocol.ExitDenied { |
| 392 | t.Fatalf("exit %d, want %d", code, protocol.ExitDenied) |
| 393 | } |
| 394 | if !strings.Contains(errOut.String(), "8 follows are already open") { |
| 395 | t.Errorf("stderr %q", errOut) |
| 396 | } |
| 397 | } |
| 398 | ``` |
| 399 | |
| 400 | - [ ] **Step 2: Run to see them fail** |
| 401 | |
| 402 | Run: `go test ./internal/control/ -run 'TestBuildLogFollow' -count=1` |
| 403 | Expected: build failure, `unknown field Done` / `undefined: followSettle`. |
| 404 | |
| 405 | - [ ] **Step 3: Implement** |
| 406 | |
| 407 | `internal/control/control.go`, in `Ctx` after `Cmd`: |
| 408 | |
| 409 | ```go |
| 410 | // Done, when the surface has one, closes when nobody is reading any |
| 411 | // more: the SSH channel closed or the HTTP request ended. A command |
| 412 | // that runs until something happens (build log --follow) stops on it. |
| 413 | Done <-chan struct{} |
| 414 | ``` |
| 415 | |
| 416 | `internal/control/build.go` registration: |
| 417 | |
| 418 | ```go |
| 419 | register(Command{Path: []string{"build", "log"}, |
| 420 | Summary: "print a build's log, or follow it until the build ends", |
| 421 | Usage: "build log <owner/name> <n> [--follow]", ReadOnly: true, Run: runBuildLog}) |
| 422 | ``` |
| 423 | |
| 424 | `runBuildLog`: |
| 425 | |
| 426 | ```go |
| 427 | func runBuildLog(c *Ctx, args []string) int { |
| 428 | f, err := parseFlags(args, flagSpec{Bools: []string{"--follow"}, MaxPos: 2, Usage: c.Cmd.Usage}) |
| 429 | if err != nil { |
| 430 | return c.fail(protocol.ExitUsage, "%v", err) |
| 431 | } |
| 432 | _, b, code := buildRef(c, f.Pos) |
| 433 | if code >= 0 { |
| 434 | return code |
| 435 | } |
| 436 | if f.Has("--follow") { |
| 437 | return followBuildLog(c, b) |
| 438 | } |
| 439 | log, err := c.Store.BuildLog(b.ID) |
| 440 | if err != nil { |
| 441 | return c.fail(protocol.ExitFailure, "%v", err) |
| 442 | } |
| 443 | c.Stdout.Write(log) |
| 444 | return protocol.ExitOK |
| 445 | } |
| 446 | ``` |
| 447 | |
| 448 | Check how `runBuildList` (build.go ~125) reports a `parseFlags` error and match it exactly if it differs from the above. |
| 449 | |
| 450 | `internal/control/buildfollow.go`: |
| 451 | |
| 452 | ```go |
| 453 | package control |
| 454 | |
| 455 | import ( |
| 456 | "fmt" |
| 457 | "sync" |
| 458 | "time" |
| 459 | |
| 460 | "gitbay.org/gitbay/internal/protocol" |
| 461 | "gitbay.org/gitbay/internal/store" |
| 462 | ) |
| 463 | |
| 464 | // maxFollows is how many build log follows one account holds open at |
| 465 | // once. Signed-out web viewers are account 0 and share it. |
| 466 | const maxFollows = 8 |
| 467 | |
| 468 | var ( |
| 469 | // followPoll bounds a wait with no wake. A write from another process |
| 470 | // (gitbayd admin, or any session under gitbayd shell) wakes nobody; |
| 471 | // this is how its bytes still arrive. |
| 472 | followPoll = 2 * time.Second |
| 473 | // followSettle is how long a follow keeps reading after the build has |
| 474 | // an outcome: a cancel appends its line after the status changes, and |
| 475 | // a cancelled runner's stream runs on until its next check. |
| 476 | followSettle = time.Second |
| 477 | ) |
| 478 | |
| 479 | var ( |
| 480 | followMu sync.Mutex |
| 481 | follows = map[int64]int{} |
| 482 | ) |
| 483 | |
| 484 | func takeFollow(uid int64) bool { |
| 485 | followMu.Lock() |
| 486 | defer followMu.Unlock() |
| 487 | if follows[uid] >= maxFollows { |
| 488 | return false |
| 489 | } |
| 490 | follows[uid]++ |
| 491 | return true |
| 492 | } |
| 493 | |
| 494 | func dropFollow(uid int64) { |
| 495 | followMu.Lock() |
| 496 | defer followMu.Unlock() |
| 497 | if follows[uid]--; follows[uid] <= 0 { |
| 498 | delete(follows, uid) |
| 499 | } |
| 500 | } |
| 501 | |
| 502 | // followBuildLog writes the build's log as it grows and returns once the |
| 503 | // build has an outcome and its last bytes are written. The outcome goes |
| 504 | // to stderr, so stdout is the log byte for byte. |
| 505 | func followBuildLog(c *Ctx, b store.Build) int { |
| 506 | if !takeFollow(c.User.ID) { |
| 507 | return c.fail(protocol.ExitDenied, "%d follows are already open for this account; close one and retry", maxFollows) |
| 508 | } |
| 509 | defer dropFollow(c.User.ID) |
| 510 | |
| 511 | var off int64 |
| 512 | var settleBy time.Time |
| 513 | for { |
| 514 | wake := c.Store.BuildLogWait(b.ID) |
| 515 | status, chunk, err := c.Store.BuildLogFrom(b.ID, off) |
| 516 | if err != nil { |
| 517 | return c.fail(protocol.ExitFailure, "%v", err) |
| 518 | } |
| 519 | if len(chunk) > 0 { |
| 520 | if _, err := c.Stdout.Write(chunk); err != nil { |
| 521 | return protocol.ExitFailure |
| 522 | } |
| 523 | off += int64(len(chunk)) |
| 524 | } |
| 525 | wait := followPoll |
| 526 | if status != "pending" && status != "running" { |
| 527 | if settleBy.IsZero() { |
| 528 | settleBy = time.Now().Add(followSettle) |
| 529 | } |
| 530 | left := time.Until(settleBy) |
| 531 | if left <= 0 && len(chunk) == 0 { |
| 532 | fmt.Fprintf(c.Stderr, "build %d %s\n", b.Number, status) |
| 533 | return protocol.ExitOK |
| 534 | } |
| 535 | wait = min(wait, max(left, 0)) |
| 536 | } |
| 537 | t := time.NewTimer(wait) |
| 538 | select { |
| 539 | case <-wake: |
| 540 | case <-t.C: |
| 541 | case <-c.Done: |
| 542 | t.Stop() |
| 543 | return protocol.ExitFailure |
| 544 | } |
| 545 | t.Stop() |
| 546 | } |
| 547 | } |
| 548 | ``` |
| 549 | |
| 550 | Check the loop against the spec before moving on: once the status is terminal it keeps reading until `followSettle` has passed *and* a read came back empty, then prints the outcome. A deadline, not a `time.After` channel: a timer channel delivers once, and a second check of it would block. A nil `c.Done` never fires in the select, which is what a surface without one wants. `min`/`max` are Go 1.21 builtins; check `go.mod`'s go line is at least 1.21. |
| 551 | |
| 552 | `cmd/gitbay/main.go:51`: |
| 553 | |
| 554 | ```go |
| 555 | pass("log", "a build's log: <owner/name> <n> [--follow]", passOpts{server: []string{"build", "log"}, needsRepo: true}), |
| 556 | ``` |
| 557 | |
| 558 | - [ ] **Step 4: Run the tests, the race detector, and vet** |
| 559 | |
| 560 | Run: `go test ./internal/control/ -run 'TestBuildLog' -count=1 -race && go vet ./internal/control/ ./cmd/gitbay/ && go test ./cmd/gitbay/ -count=1` |
| 561 | Expected: `ok` for each. |
| 562 | |
| 563 | Then run the whole control package once, since `build log` is covered elsewhere too: `go test ./internal/control/ -count=1`. |
| 564 | |
| 565 | - [ ] **Step 5: Commit** |
| 566 | |
| 567 | ```bash |
| 568 | git add internal/control/control.go internal/control/build.go internal/control/buildfollow.go internal/control/buildfollow_test.go cmd/gitbay/main.go |
| 569 | git commit -m "build log --follow: stream a build's log until it ends |
| 570 | |
| 571 | Ref #250" |
| 572 | ``` |
| 573 | |
| 574 | --- |
| 575 | |
| 576 | ### Task 3: Surfaces pass Done — SSH channel close, HTTP request end |
| 577 | |
| 578 | **Files:** |
| 579 | - Modify: `internal/sshd/sshd.go` (`handleSession` ~230, `runExec` ~270, `Exec` ~305, the `control.Ctx` at ~335) |
| 580 | - Modify: `cmd/gitbayd/system.go:96` |
| 581 | - Modify: `internal/httpd/api.go` (~64), `internal/httpd/apiread.go` (~53) |
| 582 | |
| 583 | **Interfaces:** |
| 584 | - Consumes: `Ctx.Done` (Task 2). |
| 585 | - Produces: `sshd.Exec(cfg, st, user, scope, source, cmdline string, stdin io.Reader, stdout, stderr io.Writer, done <-chan struct{}) int`. |
| 586 | |
| 587 | - [ ] **Step 1: SSH.** In `handleSession`'s `"exec"` case, replace the two lines after `req.Reply(true, nil)`: |
| 588 | |
| 589 | ```go |
| 590 | req.Reply(true, nil) |
| 591 | // x/crypto closes reqs when the client closes the channel. That |
| 592 | // is how a follow learns nobody is reading: the CLI's shared |
| 593 | // connection outlives a Ctrl-C, the channel does not. |
| 594 | done := make(chan struct{}) |
| 595 | go func() { |
| 596 | for r := range reqs { |
| 597 | r.Reply(false, nil) |
| 598 | } |
| 599 | close(done) |
| 600 | }() |
| 601 | code := s.runExec(sconn, ch, payload.Command, done) |
| 602 | sendExit(ch, code) |
| 603 | return |
| 604 | ``` |
| 605 | |
| 606 | `runExec` gains `done <-chan struct{}` as its last parameter and passes it to `Exec`. `Exec` gains `done <-chan struct{}` as its last parameter and sets `Done: done` in the `control.Ctx` it builds. `cmd/gitbayd/system.go:96` passes `nil` (that process ends with its session). |
| 607 | |
| 608 | Find every other caller: `grep -rn 'sshd.Exec(\|\.runExec(' --include='*.go' .` and update them, test files included. |
| 609 | |
| 610 | - [ ] **Step 2: API.** In `internal/httpd/api.go` and `internal/httpd/apiread.go`, add `Done: r.Context().Done(),` to the `control.Ctx` literal. |
| 611 | |
| 612 | - [ ] **Step 3: Build, vet, test** |
| 613 | |
| 614 | Run: `go build ./... && go vet ./internal/sshd/ ./internal/httpd/ ./cmd/gitbayd/ && go test ./internal/sshd/ ./internal/httpd/ -count=1` |
| 615 | Expected: `ok`. |
| 616 | |
| 617 | - [ ] **Step 4: Commit** |
| 618 | |
| 619 | ```bash |
| 620 | git add internal/sshd/sshd.go cmd/gitbayd/system.go internal/httpd/api.go internal/httpd/apiread.go |
| 621 | git commit -m "sshd, api: end a command when its reader goes away |
| 622 | |
| 623 | Ref #250" |
| 624 | ``` |
| 625 | |
| 626 | --- |
| 627 | |
| 628 | ### Task 4: gzipWriter passes a flush through |
| 629 | |
| 630 | **Files:** |
| 631 | - Modify: `internal/httpd/compress.go` |
| 632 | - Test: `internal/httpd/compress_test.go` |
| 633 | |
| 634 | **Interfaces:** |
| 635 | - Produces: `(*gzipWriter).Flush()`, `(*gzipWriter).Unwrap() http.ResponseWriter`. |
| 636 | |
| 637 | - [ ] **Step 1: Write the failing test** — append to `internal/httpd/compress_test.go` (add missing imports: `bytes`, `compress/gzip`, `io`, `net/http`, `net/http/httptest`, `strings`): |
| 638 | |
| 639 | ```go |
| 640 | // A flush mid-response reaches the connection with what was written so |
| 641 | // far decodable, which is what lets a page stream through gzip. |
| 642 | func TestGzipWriterFlushes(t *testing.T) { |
| 643 | rec := httptest.NewRecorder() |
| 644 | h := compressed(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| 645 | w.Header().Set("Content-Type", "text/html; charset=utf-8") |
| 646 | io.WriteString(w, "<p>first</p>") |
| 647 | if err := http.NewResponseController(w).Flush(); err != nil { |
| 648 | t.Fatalf("flush: %v", err) |
| 649 | } |
| 650 | if !rec.Flushed { |
| 651 | t.Fatal("the flush did not reach the connection") |
| 652 | } |
| 653 | zr, err := gzip.NewReader(bytes.NewReader(rec.Body.Bytes())) |
| 654 | if err != nil { |
| 655 | t.Fatalf("gzip header: %v", err) |
| 656 | } |
| 657 | got, _ := io.ReadAll(zr) // no trailer yet: ends in ErrUnexpectedEOF |
| 658 | if !strings.Contains(string(got), "<p>first</p>") { |
| 659 | t.Fatalf("flushed body decodes to %q", got) |
| 660 | } |
| 661 | io.WriteString(w, "<p>second</p>") |
| 662 | })) |
| 663 | req := httptest.NewRequest("GET", "/", nil) |
| 664 | req.Header.Set("Accept-Encoding", "gzip") |
| 665 | h.ServeHTTP(rec, req) |
| 666 | } |
| 667 | ``` |
| 668 | |
| 669 | - [ ] **Step 2: Run to see it fail** |
| 670 | |
| 671 | Run: `go test ./internal/httpd/ -run TestGzipWriterFlushes -count=1` |
| 672 | Expected: FAIL, `flush: feature not supported`. |
| 673 | |
| 674 | - [ ] **Step 3: Implement** — in `internal/httpd/compress.go`, after `Close`: |
| 675 | |
| 676 | ```go |
| 677 | // Flush sends what the gzip stream holds, then flushes the connection, so |
| 678 | // a streamed page reaches the browser as it is written. |
| 679 | func (g *gzipWriter) Flush() { |
| 680 | if !g.decided { |
| 681 | g.decide(http.StatusOK) |
| 682 | } |
| 683 | if g.gz != nil { |
| 684 | g.gz.Flush() |
| 685 | } |
| 686 | http.NewResponseController(g.ResponseWriter).Flush() |
| 687 | } |
| 688 | |
| 689 | func (g *gzipWriter) Unwrap() http.ResponseWriter { return g.ResponseWriter } |
| 690 | ``` |
| 691 | |
| 692 | - [ ] **Step 4: Run** |
| 693 | |
| 694 | Run: `go test ./internal/httpd/ -count=1 && go vet ./internal/httpd/` |
| 695 | Expected: `ok`. |
| 696 | |
| 697 | - [ ] **Step 5: Commit** |
| 698 | |
| 699 | ```bash |
| 700 | git add internal/httpd/compress.go internal/httpd/compress_test.go |
| 701 | git commit -m "httpd: gzipWriter passes a flush through |
| 702 | |
| 703 | Ref #250" |
| 704 | ``` |
| 705 | |
| 706 | --- |
| 707 | |
| 708 | ### Task 5: The build page streams a live build |
| 709 | |
| 710 | **Files:** |
| 711 | - Modify: `internal/httpd/builds.go` (`build`, ~280) |
| 712 | - Modify: `internal/httpd/control.go` (new `runControlStream` after `runControlCode`) |
| 713 | - Modify: `internal/web/templates/build.html` |
| 714 | |
| 715 | **Interfaces:** |
| 716 | - Consumes: `build log --follow` (Task 2), `gzipWriter.Flush` (Task 4), `Ctx.Done`. |
| 717 | - Produces: `func (s *Server) runControlStream(u store.User, argv []string, out io.Writer, done <-chan struct{}) (msg string, code int)`; `type buildView`; `const liveLogMarker`. |
| 718 | |
| 719 | - [ ] **Step 1: Template.** Replace the last content line of `build.html`: |
| 720 | |
| 721 | ``` |
| 722 | {{if .Log}}<pre class="code buildlog" tabindex="0">{{.Log}}</pre>{{else}}<p class="empty-note">no log yet</p>{{end}} |
| 723 | ``` |
| 724 | |
| 725 | with: |
| 726 | |
| 727 | ``` |
| 728 | {{if .Live}}<p class="meta">Live: the log streams here until the build ends. If it stops without a “build finished” line, reload to pick it up again. <a href="?follow=0">Show it without updates</a></p> |
| 729 | <pre class="code buildlog" tabindex="0">{{.Log}}</pre> |
| 730 | {{else if .Log}}<pre class="code buildlog" tabindex="0">{{.Log}}</pre>{{else}}<p class="empty-note">no log yet</p>{{end}} |
| 731 | ``` |
| 732 | |
| 733 | - [ ] **Step 2: `runControlStream`** in `internal/httpd/control.go` after `runControlCode` (add `io` to imports): |
| 734 | |
| 735 | ```go |
| 736 | // runControlStream runs a command whose output is written as it is |
| 737 | // produced: stdout goes to out, and done ends the command when the |
| 738 | // request does. msg is stderr. |
| 739 | func (s *Server) runControlStream(u store.User, argv []string, out io.Writer, done <-chan struct{}) (msg string, code int) { |
| 740 | var stderr bytes.Buffer |
| 741 | ctx := &control.Ctx{ |
| 742 | User: u, |
| 743 | Source: "web", |
| 744 | Scope: "full", |
| 745 | Store: s.st, |
| 746 | Cfg: s.cfg, |
| 747 | Stdin: strings.NewReader(""), |
| 748 | Stdout: out, |
| 749 | Stderr: &stderr, |
| 750 | ViaAPI: true, |
| 751 | Done: done, |
| 752 | } |
| 753 | code = control.Dispatch(ctx, argv) |
| 754 | return strings.TrimSpace(stderr.String()), code |
| 755 | } |
| 756 | ``` |
| 757 | |
| 758 | - [ ] **Step 3: Handler.** In `internal/httpd/builds.go`, replace `build` from the `log, _, _ := s.runControl(...)` line to the end with: |
| 759 | |
| 760 | ```go |
| 761 | v := buildView{repoPage: p, Build: b, CanWrite: s.canWriteRepo(r, p.Repo), Notice: s.takeFlash(w, r)} |
| 762 | if (b.Status == "pending" || b.Status == "running") && r.URL.Query().Get("follow") != "0" { |
| 763 | s.streamBuild(w, r, v, viewer, n) |
| 764 | return |
| 765 | } |
| 766 | v.Log, _, _ = s.runControl(viewer, []string{"build", "log", p.Repo.Path(), n}) |
| 767 | s.render(w, "build.html", v) |
| 768 | } |
| 769 | |
| 770 | type buildView struct { |
| 771 | repoPage |
| 772 | Build control.BuildOut |
| 773 | Log string |
| 774 | Live bool |
| 775 | CanWrite bool |
| 776 | Notice string |
| 777 | } |
| 778 | |
| 779 | // liveLogMarker stands in for the log when build.html is rendered for a |
| 780 | // live build; streamBuild splits the page there and streams the log into |
| 781 | // the gap. Git refs, paths and job names cannot hold the control byte. |
| 782 | const liveLogMarker = "\x1elive-log\x1e" |
| 783 | |
| 784 | // streamBuild writes the build page with the log following the build: |
| 785 | // the page up to the log, then build log --follow escaped and flushed as |
| 786 | // it arrives, then the outcome and the rest of the page. |
| 787 | func (s *Server) streamBuild(w http.ResponseWriter, r *http.Request, v buildView, viewer store.User, n string) { |
| 788 | v.Live, v.Log = true, liveLogMarker |
| 789 | var buf bytes.Buffer |
| 790 | if err := web.Render(&buf, "build.html", v); err != nil { |
| 791 | http.Error(w, "template error: "+err.Error(), http.StatusInternalServerError) |
| 792 | return |
| 793 | } |
| 794 | head, tail, ok := strings.Cut(buf.String(), liveLogMarker) |
| 795 | if !ok || !strings.HasPrefix(tail, "</pre>") { |
| 796 | http.Error(w, "template error: build.html has no live log slot", http.StatusInternalServerError) |
| 797 | return |
| 798 | } |
| 799 | tail = strings.TrimPrefix(tail, "</pre>") |
| 800 | |
| 801 | h := w.Header() |
| 802 | h.Set("Content-Type", "text/html; charset=utf-8") |
| 803 | h.Set("Cache-Control", "no-store") |
| 804 | h.Set("X-Accel-Buffering", "no") |
| 805 | rc := http.NewResponseController(w) |
| 806 | io.WriteString(w, head) |
| 807 | rc.Flush() |
| 808 | |
| 809 | path := v.Repo.Path() |
| 810 | msg, code := s.runControlStream(viewer, []string{"build", "log", path, n, "--follow"}, |
| 811 | htmlStream{w: w, rc: rc}, r.Context().Done()) |
| 812 | if code == protocol.ExitDenied { |
| 813 | // The follow cap: the stored log once, and why it is not live. |
| 814 | log, _, _ := s.runControl(viewer, []string{"build", "log", path, n}) |
| 815 | template.HTMLEscape(w, []byte(log)) |
| 816 | } |
| 817 | io.WriteString(w, "</pre>") |
| 818 | switch { |
| 819 | case code == protocol.ExitOK: |
| 820 | var b control.BuildOut |
| 821 | if _, ok := s.runControlInto(viewer, []string{"build", "show", path, n}, &b); ok { |
| 822 | fmt.Fprintf(w, `<p class="notice" role="status">build finished: %s</p>`, template.HTMLEscapeString(b.Status)) |
| 823 | } |
| 824 | case code == protocol.ExitDenied: |
| 825 | fmt.Fprintf(w, `<p class="error" role="alert">%s</p>`, template.HTMLEscapeString(msg)) |
| 826 | } |
| 827 | io.WriteString(w, tail) |
| 828 | } |
| 829 | |
| 830 | // htmlStream escapes each chunk of a streamed log into the page and |
| 831 | // flushes it, so the browser draws it as it arrives. |
| 832 | type htmlStream struct { |
| 833 | w io.Writer |
| 834 | rc *http.ResponseController |
| 835 | } |
| 836 | |
| 837 | func (h htmlStream) Write(p []byte) (int, error) { |
| 838 | template.HTMLEscape(h.w, p) |
| 839 | if err := h.rc.Flush(); err != nil { |
| 840 | return 0, err |
| 841 | } |
| 842 | return len(p), nil |
| 843 | } |
| 844 | ``` |
| 845 | |
| 846 | Add the imports `builds.go` now needs (`bytes`, `fmt`, `html/template`, `io`, `strings`, `gitbay.org/gitbay/internal/protocol`, `gitbay.org/gitbay/internal/web`) — only those not already present. If `builds.go` already imports `text/template` or another `template`, alias accordingly. |
| 847 | |
| 848 | - [ ] **Step 4: Build, vet, unit tests** |
| 849 | |
| 850 | Run: `go build ./... && go vet ./internal/httpd/ ./internal/web/ && go test ./internal/httpd/ ./internal/web/ -count=1` |
| 851 | Expected: `ok`. (`TestMainWidthClass` needs nothing: no new template.) |
| 852 | |
| 853 | - [ ] **Step 5: Commit** |
| 854 | |
| 855 | ```bash |
| 856 | git add internal/httpd/builds.go internal/httpd/control.go internal/web/templates/build.html |
| 857 | git commit -m "web: the build page streams a live build's log |
| 858 | |
| 859 | Ref #250" |
| 860 | ``` |
| 861 | |
| 862 | --- |
| 863 | |
| 864 | ### Task 6: e2e — follow over ssh and on the page |
| 865 | |
| 866 | **Files:** |
| 867 | - Modify: `e2e/ssh_test.go` (extract `sshCmd` from `ssh`, ~line 164) |
| 868 | - Create: `e2e/buildfollow_test.go` |
| 869 | |
| 870 | **Interfaces:** |
| 871 | - Consumes: everything above; e2e helpers `startInstance`, `newKey`, `admin`, `ssh`, `gitEnv`, `sshURL`, `mustGit`, `httpPort`. |
| 872 | - Produces: `func (i *instance) sshCmd(key string, args ...string) *exec.Cmd`. |
| 873 | |
| 874 | - [ ] **Step 1: Extract `sshCmd`.** In `e2e/ssh_test.go`, split `ssh`: |
| 875 | |
| 876 | ```go |
| 877 | // sshCmd is the ssh invocation ssh runs, for a test that reads the output |
| 878 | // as it arrives. |
| 879 | func (i *instance) sshCmd(key string, args ...string) *exec.Cmd { |
| 880 | base := []string{ |
| 881 | "-p", fmt.Sprint(i.port), |
| 882 | "-i", key, |
| 883 | "-o", "IdentitiesOnly=yes", |
| 884 | "-o", "StrictHostKeyChecking=no", |
| 885 | "-o", "UserKnownHostsFile=" + filepath.Join(i.sshDir, "known_hosts"), |
| 886 | "-o", "BatchMode=yes", |
| 887 | "git@127.0.0.1", |
| 888 | } |
| 889 | return exec.Command("ssh", append(base, args...)...) |
| 890 | } |
| 891 | ``` |
| 892 | |
| 893 | and have `ssh` start with `cmd := i.sshCmd(key, args...)` in place of building `base` itself. |
| 894 | |
| 895 | - [ ] **Step 2: Write the test** — `e2e/buildfollow_test.go`: |
| 896 | |
| 897 | ```go |
| 898 | package e2e |
| 899 | |
| 900 | import ( |
| 901 | "encoding/json" |
| 902 | "fmt" |
| 903 | "io" |
| 904 | "net/http" |
| 905 | "os" |
| 906 | "path/filepath" |
| 907 | "strings" |
| 908 | "testing" |
| 909 | "time" |
| 910 | ) |
| 911 | |
| 912 | // streamReader collects what r delivers, so a test can wait for text to |
| 913 | // arrive while the writer is still going. |
| 914 | type streamReader struct { |
| 915 | ch chan []byte |
| 916 | buf strings.Builder |
| 917 | } |
| 918 | |
| 919 | func newStreamReader(r io.Reader) *streamReader { |
| 920 | s := &streamReader{ch: make(chan []byte, 16)} |
| 921 | go func() { |
| 922 | b := make([]byte, 4096) |
| 923 | for { |
| 924 | n, err := r.Read(b) |
| 925 | if n > 0 { |
| 926 | s.ch <- append([]byte(nil), b[:n]...) |
| 927 | } |
| 928 | if err != nil { |
| 929 | close(s.ch) |
| 930 | return |
| 931 | } |
| 932 | } |
| 933 | }() |
| 934 | return s |
| 935 | } |
| 936 | |
| 937 | func (s *streamReader) waitFor(t *testing.T, want string) string { |
| 938 | t.Helper() |
| 939 | deadline := time.After(20 * time.Second) |
| 940 | for !strings.Contains(s.buf.String(), want) { |
| 941 | select { |
| 942 | case b, ok := <-s.ch: |
| 943 | if !ok { |
| 944 | t.Fatalf("stream ended before %q:\n%s", want, s.buf.String()) |
| 945 | } |
| 946 | s.buf.Write(b) |
| 947 | case <-deadline: |
| 948 | t.Fatalf("no %q after 20s:\n%s", want, s.buf.String()) |
| 949 | } |
| 950 | } |
| 951 | return s.buf.String() |
| 952 | } |
| 953 | |
| 954 | // A running build is followed over ssh and on its page: output the runner |
| 955 | // sends arrives while the build runs, and both end with the outcome. |
| 956 | func TestBuildLogFollow(t *testing.T) { |
| 957 | t.Parallel() |
| 958 | inst := startInstance(t) |
| 959 | aliceKey := inst.newKey(t, "alice") |
| 960 | runnerKey := inst.newKey(t, "ci") |
| 961 | inst.admin(t, "admin", "user", "create", "alice", "--key", aliceKey+".pub") |
| 962 | inst.admin(t, "admin", "user", "create", "ci", "--key", runnerKey+".pub", "--admin") |
| 963 | if _, _, code := inst.ssh(t, aliceKey, "", "repo", "create", "alice/app"); code != 0 { |
| 964 | t.Fatal("repo create failed") |
| 965 | } |
| 966 | work := t.TempDir() |
| 967 | env := inst.gitEnv(aliceKey) |
| 968 | mustGit(t, work, env, "clone", inst.sshURL("alice/app"), "w") |
| 969 | dir := filepath.Join(work, "w") |
| 970 | os.MkdirAll(filepath.Join(dir, ".gitbay"), 0o755) |
| 971 | os.WriteFile(filepath.Join(dir, ".gitbay", "ci.yml"), []byte("jobs:\n unit:\n steps:\n - echo fine\n"), 0o644) |
| 972 | mustGit(t, dir, env, "checkout", "-q", "-b", "main") |
| 973 | mustGit(t, dir, env, "add", ".") |
| 974 | mustGit(t, dir, env, "commit", "-q", "-m", "ci") |
| 975 | mustGit(t, dir, env, "push", "-q", "origin", "main") |
| 976 | |
| 977 | // Claim build 1 by hand, so the test decides when output arrives. |
| 978 | out, errOut, code := inst.ssh(t, runnerKey, "", "runner", "next", "--json") |
| 979 | if code != 0 { |
| 980 | t.Fatalf("runner next: %s", errOut) |
| 981 | } |
| 982 | var claim struct { |
| 983 | Data struct { |
| 984 | ID int64 `json:"id"` |
| 985 | } `json:"data"` |
| 986 | } |
| 987 | if err := json.Unmarshal([]byte(out), &claim); err != nil || claim.Data.ID == 0 { |
| 988 | t.Fatalf("runner next output %q: %v", out, err) |
| 989 | } |
| 990 | id := fmt.Sprint(claim.Data.ID) |
| 991 | |
| 992 | cmd := inst.sshCmd(aliceKey, "build", "log", "alice/app", "1", "--follow") |
| 993 | stdout, err := cmd.StdoutPipe() |
| 994 | if err != nil { |
| 995 | t.Fatal(err) |
| 996 | } |
| 997 | var stderr strings.Builder |
| 998 | cmd.Stderr = &stderr |
| 999 | if err := cmd.Start(); err != nil { |
| 1000 | t.Fatal(err) |
| 1001 | } |
| 1002 | follow := newStreamReader(stdout) |
| 1003 | |
| 1004 | page, err := http.Get(fmt.Sprintf("http://127.0.0.1:%d/alice/app/builds/1", inst.httpPort)) |
| 1005 | if err != nil { |
| 1006 | t.Fatal(err) |
| 1007 | } |
| 1008 | defer page.Body.Close() |
| 1009 | web := newStreamReader(page.Body) |
| 1010 | web.waitFor(t, "Live: the log streams here") |
| 1011 | |
| 1012 | // A static render while the build runs returns at once. |
| 1013 | static := &http.Client{Timeout: 10 * time.Second} |
| 1014 | resp, err := static.Get(fmt.Sprintf("http://127.0.0.1:%d/alice/app/builds/1?follow=0", inst.httpPort)) |
| 1015 | if err != nil { |
| 1016 | t.Fatalf("?follow=0 did not return: %v", err) |
| 1017 | } |
| 1018 | body, _ := io.ReadAll(resp.Body) |
| 1019 | resp.Body.Close() |
| 1020 | if strings.Contains(string(body), "Live:") { |
| 1021 | t.Fatalf("?follow=0 rendered the live page:\n%s", body) |
| 1022 | } |
| 1023 | |
| 1024 | if _, errOut, code := inst.ssh(t, runnerKey, "hello from the runner <b>\n", "runner", "log", id); code != 0 { |
| 1025 | t.Fatalf("runner log: %s", errOut) |
| 1026 | } |
| 1027 | follow.waitFor(t, "hello from the runner <b>\n") |
| 1028 | web.waitFor(t, "hello from the runner <b>") |
| 1029 | |
| 1030 | if _, errOut, code := inst.ssh(t, runnerKey, "", "runner", "done", id, "success"); code != 0 { |
| 1031 | t.Fatalf("runner done: %s", errOut) |
| 1032 | } |
| 1033 | web.waitFor(t, `<p class="notice" role="status">build finished: success</p>`) |
| 1034 | web.waitFor(t, "</html>") |
| 1035 | if err := cmd.Wait(); err != nil { |
| 1036 | t.Fatalf("follow exited: %v\n%s", err, stderr.String()) |
| 1037 | } |
| 1038 | if got := strings.TrimSpace(stderr.String()); got != "build 1 success" { |
| 1039 | t.Errorf("follow stderr %q", got) |
| 1040 | } |
| 1041 | } |
| 1042 | ``` |
| 1043 | |
| 1044 | - [ ] **Step 3: Run it** |
| 1045 | |
| 1046 | Run: `go test ./e2e/ -run 'TestBuildLogFollow$' -count=1 -v 2>&1 | tail -20` |
| 1047 | Expected: `--- PASS: TestBuildLogFollow`. If `</html>` is not how the layout ends, use the last line `layout.html` renders. |
| 1048 | |
| 1049 | - [ ] **Step 4: Check the neighbours.** Run `go vet ./e2e/` and the tests that use `inst.ssh` heavily and build pages: `go test ./e2e/ -run 'TestBuildCancel$|TestControlPlaneOverBareSSH$' -count=1`. |
| 1050 | |
| 1051 | - [ ] **Step 5: Commit** |
| 1052 | |
| 1053 | ```bash |
| 1054 | git add e2e/ssh_test.go e2e/buildfollow_test.go |
| 1055 | git commit -m "e2e: follow a running build over ssh and on its page |
| 1056 | |
| 1057 | Ref #250" |
| 1058 | ``` |
| 1059 | |
| 1060 | --- |
| 1061 | |
| 1062 | ### Task 7: Docs |
| 1063 | |
| 1064 | **Files:** |
| 1065 | - Modify: `.gitbay/wiki/Parity.org` (build rows, ~line 212) |
| 1066 | - Modify: `.gitbay/wiki/CI.org` |
| 1067 | |
| 1068 | - [ ] **Step 1: Parity.** After `| build log | yes | yes | yes |` add (columns are cli, web, ios): |
| 1069 | |
| 1070 | ``` |
| 1071 | | build log follow (until it ends) | yes | yes | no | |
| 1072 | ``` |
| 1073 | |
| 1074 | - [ ] **Step 2: CI.org.** After the paragraph that begins "Scheduled jobs run on their cron", add: |
| 1075 | |
| 1076 | ``` |
| 1077 | A running build is followed with =build log <owner/name> <n> --follow=: |
| 1078 | the stored log, then output as the runner sends it, then the outcome |
| 1079 | as =build <n> <status>= on stderr once the build ends. The exit code is |
| 1080 | 0 whatever the outcome. The build page does the same without |
| 1081 | JavaScript while a build is queued or running; =?follow=0= renders it |
| 1082 | once. An account holds at most eight follows open, and signed-out |
| 1083 | viewers share one account's eight. Over the JSON API the command |
| 1084 | answers when the build ends, with the whole log. |
| 1085 | ``` |
| 1086 | |
| 1087 | - [ ] **Step 3: Commit** |
| 1088 | |
| 1089 | ```bash |
| 1090 | git add .gitbay/wiki/Parity.org .gitbay/wiki/CI.org |
| 1091 | git commit -m "wiki: build log --follow |
| 1092 | |
| 1093 | Closes #250" |
| 1094 | ``` |
| 1095 | |
| 1096 | --- |
| 1097 | |
| 1098 | ## Finish |
| 1099 | |
| 1100 | Push `build-log-follow`, open the MR with `gitbay mr create --source build-log-follow --target main --title "build log --follow, streamed to the build page" --file - < <body file>`, wait for CI, then `gitbay mr merge <n> --strategy ff` and delete the branch in both places. |