internal/control/buildfollow_test.go

  1package control
  2
  3import (
  4	"bytes"
  5	"strings"
  6	"sync"
  7	"testing"
  8	"time"
  9
 10	"gitbay.org/gitbay/internal/protocol"
 11	"gitbay.org/gitbay/internal/store"
 12)
 13
 14// syncBuffer is a bytes.Buffer guarded by a mutex, safe for a test to poll
 15// while the follow goroutine is still writing to it.
 16type syncBuffer struct {
 17	mu  sync.Mutex
 18	buf bytes.Buffer
 19}
 20
 21func (b *syncBuffer) Write(p []byte) (int, error) {
 22	b.mu.Lock()
 23	defer b.mu.Unlock()
 24	return b.buf.Write(p)
 25}
 26
 27func (b *syncBuffer) String() string {
 28	b.mu.Lock()
 29	defer b.mu.Unlock()
 30	return b.buf.String()
 31}
 32
 33// follow starts build log --follow on build 1 of repo and returns the
 34// buffers and a channel carrying the exit code.
 35func follow(t *testing.T, st *store.Store, uid int64, repo store.Repo, done <-chan struct{}) (*syncBuffer, *syncBuffer, chan int) {
 36	t.Helper()
 37	return followStopping(t, st, uid, repo, done, nil)
 38}
 39
 40// followStopping is follow on a surface that is being restarted when
 41// stopping closes.
 42func followStopping(t *testing.T, st *store.Store, uid int64, repo store.Repo, done, stopping <-chan struct{}) (*syncBuffer, *syncBuffer, chan int) {
 43	t.Helper()
 44	u, err := st.UserByID(uid)
 45	if err != nil {
 46		t.Fatal(err)
 47	}
 48	var out, errOut syncBuffer
 49	c := &Ctx{User: u, Scope: "full", Store: st, Stdin: strings.NewReader(""),
 50		Stdout: &out, Stderr: &errOut, Done: done, Stopping: stopping}
 51	res := make(chan int, 1)
 52	go func() { res <- Dispatch(c, []string{"build", "log", repo.Path(), "1", "--follow"}) }()
 53	return &out, &errOut, res
 54}
 55
 56// waitOutput waits until the follower has written want, which is how a
 57// test knows the follow is past its first read.
 58func waitOutput(t *testing.T, out *syncBuffer, want string) {
 59	t.Helper()
 60	deadline := time.After(2 * time.Second)
 61	for !strings.Contains(out.String(), want) {
 62		select {
 63		case <-deadline:
 64			t.Fatalf("follow never wrote %q", want)
 65		case <-time.After(10 * time.Millisecond):
 66		}
 67	}
 68}
 69
 70func waitExit(t *testing.T, res chan int) int {
 71	t.Helper()
 72	select {
 73	case code := <-res:
 74		return code
 75	case <-time.After(10 * time.Second):
 76		t.Fatal("follow did not end")
 77		return -1
 78	}
 79}
 80
 81func shortFollowTimers(t *testing.T) {
 82	settle, poll, queued, coalesce := followSettle, followPoll, followQueued, followCoalesce
 83	followSettle, followPoll, followCoalesce = 200*time.Millisecond, 50*time.Millisecond, 10*time.Millisecond
 84	t.Cleanup(func() { followSettle, followPoll, followQueued, followCoalesce = settle, poll, queued, coalesce })
 85}
 86
 87// The follow prints the stored log, then what arrives, and ends with the
 88// outcome on stderr once the build finishes.
 89func TestBuildLogFollow(t *testing.T) {
 90	shortFollowTimers(t)
 91	st, repo, uid := newQueueTestRepo(t)
 92	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
 93	if err != nil {
 94		t.Fatal(err)
 95	}
 96	st.AppendBuildLog(id, []byte("queued\n"))
 97	out, errOut, res := follow(t, st, uid, repo, nil)
 98
 99	if _, ok, err := st.ClaimBuild([]int64{repo.ID}, false); err != nil || !ok {
100		t.Fatalf("claim: %v %v", ok, err)
101	}
102	st.AppendBuildLog(id, []byte("step one\n"))
103	st.AppendBuildLog(id, []byte("step two\n"))
104	if err := st.FinishBuild(id, "success"); err != nil {
105		t.Fatal(err)
106	}
107	if code := waitExit(t, res); code != protocol.ExitOK {
108		t.Fatalf("exit %d: %s", code, errOut)
109	}
110	if got := out.String(); got != "queued\nstep one\nstep two\n" {
111		t.Errorf("stdout %q", got)
112	}
113	if got := strings.TrimSpace(errOut.String()); got != "build 1 success" {
114		t.Errorf("stderr %q", got)
115	}
116}
117
118// A cancel ends the follow, and the line the cancel appends after the
119// status change still arrives.
120func TestBuildLogFollowCancel(t *testing.T) {
121	shortFollowTimers(t)
122	st, repo, uid := newQueueTestRepo(t)
123	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
124	if err != nil {
125		t.Fatal(err)
126	}
127	out, errOut, res := follow(t, st, uid, repo, nil)
128	if err := st.CancelBuild(id); err != nil {
129		t.Fatal(err)
130	}
131	st.AppendBuildLog(id, []byte("cancelled by alice before a runner claimed it\n"))
132	if code := waitExit(t, res); code != protocol.ExitOK {
133		t.Fatalf("exit %d: %s", code, errOut)
134	}
135	if !strings.Contains(out.String(), "cancelled by alice") {
136		t.Errorf("the cancel line did not arrive: %q", out)
137	}
138	if got := strings.TrimSpace(errOut.String()); got != "build 1 cancelled" {
139		t.Errorf("stderr %q", got)
140	}
141}
142
143// Closing Done ends a follow of a build that is still running, even while
144// it is blocked waiting for the next change: the build gets a line, the
145// follower is confirmed to have read it (so it is back in its wait), then
146// Done closes.
147func TestBuildLogFollowDone(t *testing.T) {
148	shortFollowTimers(t)
149	st, repo, uid := newQueueTestRepo(t)
150	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
151	if err != nil {
152		t.Fatal(err)
153	}
154	st.AppendBuildLog(id, []byte("step one\n"))
155	done := make(chan struct{})
156	out, errOut, res := follow(t, st, uid, repo, done)
157
158	waitOutput(t, out, "step one")
159	close(done)
160	if code := waitExit(t, res); code != protocol.ExitFailure {
161		t.Fatalf("exit %d, want %d", code, protocol.ExitFailure)
162	}
163	if errOut.String() != "" {
164		t.Errorf("a follow whose reader left wrote %q", errOut)
165	}
166}
167
168// A restart ends a follow and says so, so the reader knows to follow
169// again.
170func TestBuildLogFollowRestart(t *testing.T) {
171	shortFollowTimers(t)
172	st, repo, uid := newQueueTestRepo(t)
173	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
174	if err != nil {
175		t.Fatal(err)
176	}
177	st.AppendBuildLog(id, []byte("step one\n"))
178	stopping := make(chan struct{})
179	out, errOut, res := followStopping(t, st, uid, repo, stopping, stopping)
180	waitOutput(t, out, "step one")
181	close(stopping)
182	if code := waitExit(t, res); code != protocol.ExitFailure {
183		t.Fatalf("exit %d, want %d", code, protocol.ExitFailure)
184	}
185	if got := strings.TrimSpace(errOut.String()); got != "gitbay is restarting; follow the build again in a moment" {
186		t.Errorf("stderr %q", got)
187	}
188}
189
190// A follower whose account is disabled mid-follow is ended, even on a
191// public repository.
192func TestBuildLogFollowDisabled(t *testing.T) {
193	shortFollowTimers(t)
194	st, repo, _ := newQueueTestRepo(t)
195	bob, err := st.CreateUser("bob", false)
196	if err != nil {
197		t.Fatal(err)
198	}
199	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
200	if err != nil {
201		t.Fatal(err)
202	}
203	st.AppendBuildLog(id, []byte("step one\n"))
204	out, errOut, res := follow(t, st, bob, repo, nil)
205	waitOutput(t, out, "step one")
206	if err := st.SetUserDisabled(bob, true); err != nil {
207		t.Fatal(err)
208	}
209	if code := waitExit(t, res); code != protocol.ExitNotFound {
210		t.Fatalf("exit %d, want %d: %s", code, protocol.ExitNotFound, errOut)
211	}
212}
213
214// A build that stays pending ends its own follow: nothing reaps a queued
215// build, so the follow must give up on its own.
216func TestBuildLogFollowQueued(t *testing.T) {
217	shortFollowTimers(t)
218	followQueued = 150 * time.Millisecond
219	st, repo, uid := newQueueTestRepo(t)
220	if _, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true); err != nil {
221		t.Fatal(err)
222	}
223	_, errOut, res := follow(t, st, uid, repo, nil)
224	if code := waitExit(t, res); code != protocol.ExitFailure {
225		t.Fatalf("exit %d, want %d: %s", code, protocol.ExitFailure, errOut)
226	}
227	if !strings.Contains(errOut.String(), "still queued") {
228		t.Errorf("stderr %q", errOut)
229	}
230}
231
232// A follower who loses read access mid-follow is ended with the answer
233// a new request would get: the repository is not found.
234func TestBuildLogFollowLosesAccess(t *testing.T) {
235	shortFollowTimers(t)
236	st, repo, _ := newQueueTestRepo(t)
237	bob, err := st.CreateUser("bob", false)
238	if err != nil {
239		t.Fatal(err)
240	}
241	id, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true)
242	if err != nil {
243		t.Fatal(err)
244	}
245	st.AppendBuildLog(id, []byte("step one\n"))
246	out, errOut, res := follow(t, st, bob, repo, nil)
247	waitOutput(t, out, "step one")
248	if err := st.SetRepoVisibility(repo.ID, "private"); err != nil {
249		t.Fatal(err)
250	}
251	if code := waitExit(t, res); code != protocol.ExitNotFound {
252		t.Fatalf("exit %d, want %d: %s", code, protocol.ExitNotFound, errOut)
253	}
254	if !strings.Contains(errOut.String(), "repository "+repo.Path()+" not found") {
255		t.Errorf("stderr %q", errOut)
256	}
257}
258
259// An account holding maxFollows is refused another.
260func TestBuildLogFollowCap(t *testing.T) {
261	st, repo, uid := newQueueTestRepo(t)
262	if _, err := st.CreateBuild(repo.ID, "unit", "abc", "main", `["true"]`, "", "", true); err != nil {
263		t.Fatal(err)
264	}
265	followMu.Lock()
266	follows[uid] = maxFollows
267	followMu.Unlock()
268	t.Cleanup(func() {
269		followMu.Lock()
270		delete(follows, uid)
271		followMu.Unlock()
272	})
273	_, errOut, res := follow(t, st, uid, repo, nil)
274	if code := waitExit(t, res); code != protocol.ExitDenied {
275		t.Fatalf("exit %d, want %d", code, protocol.ExitDenied)
276	}
277	if !strings.Contains(errOut.String(), "8 follows are already open") {
278		t.Errorf("stderr %q", errOut)
279	}
280}