sww tests: wait for every starting line as long as the start takes (closes #331)

Each test in internal/sww that waits for the starting line now waits until
the line is written or sww exits, so a slow Core Rule Set compile on a
loaded host no longer fails it. The two tests that run sww as a child
process get its exit status from a goroutine that waits on it, and no
longer kill it after 30 seconds; the waits after SIGTERM still end after
waitLimit. startRProxyProcess returns a stop function in place of the
process and its output.

Model: opus-5-5

internal/sww/healthcheck_test.go

@@ -41,7 +41,7 @@ func TestHealthCheckInWAFsContainer(t *testing.T) {
 		exited <- run(ctx, settings, out)
 	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 	_, port, _ := net.SplitHostPort(addr)
 
 	// The container's settings: an address to listen on with an empty

internal/sww/rproxy_test.go

@@ -71,6 +71,8 @@ func startRProxy(t *testing.T, backend, appURL string) (string, *output) {
 		}, out)
 	}()
 
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
+
 	t.Cleanup(func() {
 		stop()
 
@@ -86,8 +88,6 @@ func startRProxy(t *testing.T, backend, appURL string) (string, *output) {
 		out.line(t, "msg", "stopped")
 	})
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
-
 	return "http://" + addr, out
 }
 
@@ -105,7 +105,7 @@ func startWAF(t *testing.T, env map[string]string) (string, *output, func()) {
 		exited <- run(ctx, env, out)
 	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 
 	return addr, out, func() {
 		stop()
@@ -507,9 +507,9 @@ func TestAStatusWAFDoesNotTakeIsReportedAs599(t *testing.T) {
 }
 
 // startRProxyProcess runs `sww rproxy` in a process of its own, with the
-// settings in env, each as NAME=value. It returns where rproxy listens, the
+// settings in env, each as NAME=value. It returns where rproxy listens, and
-// process, and what rproxy writes.
+// what stops it as SIGTERM does, which checks that it stopped in order.
-func startRProxyProcess(t *testing.T, env ...string) (string, *exec.Cmd, *output) {
+func startRProxyProcess(t *testing.T, env ...string) (string, func()) {
 	t.Helper()
 
 	binary, err := os.Executable()
@@ -517,11 +517,8 @@ func startRProxyProcess(t *testing.T, env ...string) (string, *exec.Cmd, *output
 		t.Fatalf("find the test binary: %v", err)
 	}
 
-	ctx, cancel := context.WithTimeout(t.Context(), 3*waitLimit)
-	t.Cleanup(cancel)
-
 	out := &output{}
-	cmd := exec.CommandContext(ctx, binary) //nolint:gosec // this test binary
+	cmd := exec.CommandContext(t.Context(), binary) //nolint:gosec // this test binary
 	cmd.Stdout = out
 
 	cmd.Env = append(os.Environ(),
@@ -534,14 +531,30 @@ func startRProxyProcess(t *testing.T, env ...string) (string, *exec.Cmd, *output
 		t.Fatalf("start: %v", err)
 	}
 
-	t.Cleanup(func() {
+	exited := make(chan int, 1)
-		_ = cmd.Process.Kill()
+
+	go func() {
 		_ = cmd.Wait()
-	})
+		exited <- cmd.ProcessState.ExitCode()
+	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 
-	return addr, cmd, out
+	return addr, func() {
+		err := cmd.Process.Signal(syscall.SIGTERM)
+		if err != nil {
+			t.Fatalf("signal: %v", err)
+		}
+
+		select {
+		case status := <-exited:
+			if status != 0 {
+				t.Errorf("exit status %d, want 0; output:\n%s", status, out.text())
+			}
+		case <-time.After(waitLimit):
+			t.Error("still running after being told to stop")
+		}
+	}
 }
 
 func TestRProxyAsksAWAFThatSpeaksHTTP2OverHTTP1(t *testing.T) {
@@ -572,7 +585,7 @@ func TestRProxyAsksAWAFThatSpeaksHTTP2OverHTTP1(t *testing.T) {
 		t.Fatalf("write the certificate: %v", err)
 	}
 
-	addr, _, _ := startRProxyProcess(t,
+	addr, _ := startRProxyProcess(t,
 		wafBackend+"="+backend.URL,
 		"SWRP_UPSTREAM_URL="+startApp(t),
 		"SSL_CERT_FILE="+certificates)
@@ -651,7 +664,7 @@ func TestRProxyStoppingWaitsForAReportBeingSent(t *testing.T) {
 		exited <- runRProxy(ctx, env, out)
 	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 
 	wantStatus(t, "http://"+addr+"/", placed, http.StatusOK)
 
@@ -750,7 +763,7 @@ func TestRProxyStoppingCutsOffARequestAfterFiveSeconds(t *testing.T) {
 		exited <- runRProxy(ctx, env, out)
 	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 	conn := sendAndKeepOpen(t, addr, "GET / HTTP/1.1\r\nHost: site.example\r\n\r\n")
 
 	select {
@@ -845,7 +858,7 @@ func TestMainRunsRProxy(t *testing.T) {
 	t.Parallel()
 
 	// Nothing listens there; the health check does not ask.
-	addr, cmd, out := startRProxyProcess(t, wafBackend+"=http://127.0.0.1:9")
+	addr, stop := startRProxyProcess(t, wafBackend+"=http://127.0.0.1:9")
 
 	req, err := http.NewRequestWithContext(t.Context(), http.MethodGet,
 		"http://"+addr+waf.HealthPath, http.NoBody)
@@ -868,13 +881,5 @@ func TestMainRunsRProxy(t *testing.T) {
 		t.Errorf("health check answered %q (%v)", body, err)
 	}
 
-	err = cmd.Process.Signal(syscall.SIGTERM)
+	stop()
-	if err != nil {
-		t.Fatalf("signal: %v", err)
-	}
-
-	err = cmd.Wait()
-	if err != nil {
-		t.Errorf("exit: %v; output:\n%s", err, out.text())
-	}
 }

internal/sww/waf_test.go

@@ -54,12 +54,9 @@ func TestMainRunsWAF(t *testing.T) {
 		t.Fatalf("find the test binary: %v", err)
 	}
 
-	ctx, cancel := context.WithTimeout(t.Context(), 3*waitLimit)
-	defer cancel()
-
 	dir := t.TempDir()
 	out := &output{}
-	cmd := exec.CommandContext(ctx, binary) //nolint:gosec // this test binary
+	cmd := exec.CommandContext(t.Context(), binary) //nolint:gosec // this test binary
 	cmd.Stdout = out
 
 	cmd.Env = append(os.Environ(),
@@ -75,12 +72,14 @@ func TestMainRunsWAF(t *testing.T) {
 		t.Fatalf("start: %v", err)
 	}
 
-	t.Cleanup(func() {
+	exited := make(chan int, 1)
-		_ = cmd.Process.Kill()
-		_ = cmd.Wait()
-	})
 
-	starting := out.line(t, "msg", "starting")
+	go func() {
+		_ = cmd.Wait()
+		exited <- cmd.ProcessState.ExitCode()
+	}()
+
+	starting := out.lineBeforeExit(t, "starting", exited)
 	addr, _ := starting["address"].(string)
 	ask(t, addr, "/", http.StatusOK, waf.DispositionAllow)
 
@@ -90,9 +89,13 @@ func TestMainRunsWAF(t *testing.T) {
 		t.Fatalf("signal: %v", err)
 	}
 
-	err = cmd.Wait()
+	select {
-	if err != nil {
+	case status := <-exited:
-		t.Fatalf("exit: %v; output:\n%s", err, out.text())
+		if status != 0 {
+			t.Fatalf("exit status %d, want 0; output:\n%s", status, out.text())
+		}
+	case <-time.After(waitLimit):
+		t.Fatal("still running after being told to stop")
 	}
 
 	wantUTC(t, "the process line", starting["time"])
@@ -215,7 +218,7 @@ func runWAF(t *testing.T, env map[string]string, use func(addr string)) {
 		exited <- run(ctx, env, out)
 	}()
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
 	use(addr)
 	stop()