e2e/runnerstop_test.go

  1package e2e
  2
  3import (
  4	"bytes"
  5	"encoding/json"
  6	"fmt"
  7	"os"
  8	"os/exec"
  9	"path/filepath"
 10	"regexp"
 11	"strings"
 12	"syscall"
 13	"testing"
 14	"time"
 15)
 16
 17// The runner drains on SIGTERM: the build in flight runs to its end and
 18// is reported, and nothing more is claimed (#179). The drain shipped
 19// broken once because only the process was tested and never the unit:
 20// systemd's default KillMode signals every process in the cgroup, the
 21// step and the log session included, so the runner drained a build
 22// whose steps were already dead. deploy/gitbay-runner.override.conf
 23// sets KillMode=mixed for that reason, and the systemd test below runs
 24// the runner as a real transient unit under both modes (#184).
 25
 26// stopFixture starts an instance with one repository whose single job
 27// sleeps long enough to be stopped mid-step, and returns the admin key
 28// that both pushes and runs the runner.
 29func stopFixture(t *testing.T) (*instance, string) {
 30	t.Helper()
 31	inst := startInstance(t)
 32	inst.runner = buildRunner(t)
 33	key := inst.newKey(t, "alice")
 34	inst.admin(t, "admin", "user", "create", "alice", "--key", key+".pub", "--admin")
 35	if _, errOut, code := inst.ssh(t, key, "", "repo", "create", "alice/app"); code != 0 {
 36		t.Fatalf("repo create: %s", errOut)
 37	}
 38	work := t.TempDir()
 39	env := inst.gitEnv(key)
 40	mustGit(t, work, env, "clone", inst.sshURL("alice/app"), "w")
 41	dir := filepath.Join(work, "w")
 42	os.MkdirAll(filepath.Join(dir, ".gitbay"), 0o755)
 43	os.WriteFile(filepath.Join(dir, ".gitbay", "ci.yml"),
 44		[]byte("jobs:\n  slow:\n    steps:\n      - sleep 4; echo drained\n"), 0o644)
 45	mustGit(t, dir, env, "checkout", "-q", "-b", "main")
 46	mustGit(t, dir, env, "add", ".")
 47	mustGit(t, dir, env, "commit", "-q", "-m", "ci")
 48	mustGit(t, dir, env, "push", "-q", "origin", "main")
 49	return inst, key
 50}
 51
 52// runnerArgs is the command line the runner tests use, minus the binary.
 53func (i *instance) runnerArgs(t *testing.T, key string) []string {
 54	opts := fmt.Sprintf("-p %d -i %s -o IdentitiesOnly=yes -o StrictHostKeyChecking=no -o UserKnownHostsFile=%s -o BatchMode=yes",
 55		i.port, key, filepath.Join(i.sshDir, "known_hosts"))
 56	return []string{
 57		"-poll", "200ms",
 58		"-isolation", "none",
 59		"-remote", "git@127.0.0.1",
 60		"-ssh-opts", opts,
 61		"-clone-base", fmt.Sprintf("ssh://git@127.0.0.1:%d", i.port),
 62		"-workdir", t.TempDir(),
 63	}
 64}
 65
 66func (i *instance) buildStatus(t *testing.T, key string) string {
 67	t.Helper()
 68	out, _, _ := i.ssh(t, key, "", "build", "list", "alice/app", "--json")
 69	var env struct {
 70		Data []struct {
 71			Status string `json:"status"`
 72		} `json:"data"`
 73	}
 74	json.Unmarshal([]byte(out), &env)
 75	if len(env.Data) == 0 {
 76		return ""
 77	}
 78	return env.Data[0].Status
 79}
 80
 81func TestRunnerDrainsOnSIGTERM(t *testing.T) {
 82	t.Parallel()
 83	inst, key := stopFixture(t)
 84	cmd := exec.Command(inst.runner, inst.runnerArgs(t, key)...)
 85	cmd.Env = append(os.Environ(), "XDG_CONFIG_HOME="+t.TempDir(), "GIT_CONFIG_NOSYSTEM=1", "GIT_CONFIG_GLOBAL=/dev/null")
 86	var buf bytes.Buffer
 87	cmd.Stdout, cmd.Stderr = &buf, &buf
 88	if err := cmd.Start(); err != nil {
 89		t.Fatal(err)
 90	}
 91	defer func() { cmd.Process.Kill(); cmd.Wait() }()
 92
 93	waitFor(t, "the build to be claimed", func() bool { return inst.buildStatus(t, key) == "running" })
 94	// The step is asleep. Signal the runner alone, as KillMode=mixed does.
 95	if err := cmd.Process.Signal(syscall.SIGTERM); err != nil {
 96		t.Fatal(err)
 97	}
 98	exited := make(chan error, 1)
 99	go func() { exited <- cmd.Wait() }()
100	select {
101	case err := <-exited:
102		if err != nil {
103			t.Fatalf("runner exited %v after SIGTERM; output:\n%s", err, buf.String())
104		}
105	case <-time.After(30 * time.Second):
106		t.Fatalf("runner did not exit within 30s of SIGTERM; output:\n%s", buf.String())
107	}
108	if !strings.Contains(buf.String(), "draining") {
109		t.Fatalf("runner did not announce the drain:\n%s", buf.String())
110	}
111	if st := inst.buildStatus(t, key); st != "success" {
112		t.Fatalf("build after drain is %q, want success; runner output:\n%s", st, buf.String())
113	}
114	if out, _, _ := inst.ssh(t, key, "", "build", "log", "alice/app", "1"); !strings.Contains(out, "drained") {
115		t.Fatalf("step did not run to its end:\n%s", out)
116	}
117}
118
119// The drop-in the runner runs under. Read here so a change to it fails a
120// test rather than the next production stop.
121func runnerDropIn(t *testing.T) string {
122	t.Helper()
123	b, err := os.ReadFile(filepath.Join("..", "deploy", "gitbay-runner.override.conf"))
124	if err != nil {
125		t.Fatal(err)
126	}
127	return string(b)
128}
129
130func dropInValue(conf, key string) string {
131	m := regexp.MustCompile(`(?m)^`+key+`=(.*)$`).FindAllStringSubmatch(conf, -1)
132	if len(m) == 0 {
133		return ""
134	}
135	return strings.TrimSpace(m[len(m)-1][1]) // the last assignment wins, as in systemd
136}
137
138// The unit must let the drain happen: the stop signal reaches the runner
139// alone, and the stop timeout outlasts a build plus the report retries.
140func TestRunnerDropInLetsTheDrainHappen(t *testing.T) {
141	t.Parallel()
142	conf := runnerDropIn(t)
143	if mode := dropInValue(conf, "KillMode"); mode != "mixed" {
144		t.Fatalf("KillMode=%q, want mixed: control-group signals the step and the log session with the runner", mode)
145	}
146	stop, err := time.ParseDuration(strings.ReplaceAll(dropInValue(conf, "TimeoutStopSec"), "min", "m"))
147	if err != nil {
148		t.Fatalf("TimeoutStopSec: %v", err)
149	}
150	m := regexp.MustCompile(`-timeout (\S+)`).FindStringSubmatch(dropInValue(conf, "ExecStart"))
151	if m == nil {
152		t.Fatal("ExecStart has no -timeout")
153	}
154	build, err := time.ParseDuration(m[1])
155	if err != nil {
156		t.Fatalf("-timeout: %v", err)
157	}
158	// Half a minute of report retries after the build's own limit (#179).
159	if stop < build+30*time.Second {
160		t.Fatalf("TimeoutStopSec %v cannot outlast a %v build and its report retries", stop, build)
161	}
162}
163
164// haveUserSystemd reports whether transient user units can be started
165// here: a Linux host with a systemd user manager for this account.
166func haveUserSystemd(t *testing.T) bool {
167	t.Helper()
168	if _, err := exec.LookPath("systemd-run"); err != nil {
169		return false
170	}
171	return exec.Command("systemd-run", "--user", "--quiet", "--wait", "--collect", "true").Run() == nil
172}
173
174// The runner as a transient unit, stopped by systemd. Under the drop-in's
175// KillMode the build in flight is reported a success; under systemd's
176// default it is not, which is the failure that shipped once.
177func TestRunnerDrainUnderSystemd(t *testing.T) {
178	t.Parallel()
179	if !haveUserSystemd(t) {
180		t.Skip("no systemd user manager")
181	}
182	mode := dropInValue(runnerDropIn(t), "KillMode")
183	for _, tc := range []struct {
184		mode    string
185		drained bool
186	}{
187		{mode, true},
188		{"control-group", false},
189	} {
190		t.Run(tc.mode, func(t *testing.T) {
191			inst, key := stopFixture(t)
192			unit := fmt.Sprintf("gitbay-runner-test-%d-%s", os.Getpid(), tc.mode)
193			args := append([]string{"--user", "--quiet", "--collect", "--unit", unit,
194				"-p", "KillMode=" + tc.mode, "-p", "TimeoutStopSec=60",
195				"--setenv=GIT_CONFIG_NOSYSTEM=1", "--setenv=GIT_CONFIG_GLOBAL=/dev/null",
196				inst.runner}, inst.runnerArgs(t, key)...)
197			if out, err := exec.Command("systemd-run", args...).CombinedOutput(); err != nil {
198				t.Fatalf("systemd-run: %v\n%s", err, out)
199			}
200			defer exec.Command("systemctl", "--user", "kill", "-s", "SIGKILL", unit).Run()
201
202			waitFor(t, "the build to be claimed", func() bool { return inst.buildStatus(t, key) == "running" })
203			// systemctl stop returns when the unit is down: after the
204			// drain, or after the cgroup was signalled and emptied.
205			stop := exec.Command("systemctl", "--user", "stop", unit)
206			if out, err := stop.CombinedOutput(); err != nil {
207				t.Fatalf("systemctl stop: %v\n%s", err, out)
208			}
209			if tc.drained {
210				if st := inst.buildStatus(t, key); st != "success" {
211					t.Fatalf("KillMode=%s: build after stop is %q, want success", tc.mode, st)
212				}
213				return
214			}
215			// The step was signalled with the runner, so it cannot have
216			// finished: the runner reports a failure, or died before
217			// reporting and left the build running for the reaper.
218			if st := inst.buildStatus(t, key); st == "success" {
219				t.Fatalf("KillMode=%s: build reported success, so the stop test cannot tell the modes apart", tc.mode)
220			}
221		})
222	}
223}