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. A cleanup still kills each child process as its test ends and
waits for it to exit. startRProxyProcess returns a stop function in place
of the process and its output.

Model: opus-5-5

SPEC.md

@@ -2326,7 +2326,8 @@ but for these headers:
   claims and are replaced. `X-Forwarded-For` names the peer, `X-Forwarded-Host`
   the host it asked for, and `X-Forwarded-Proto` plain `http`. Every other
   header whose name starts with `X-Forwarded-` is removed, and so are
-  `Forwarded` and `X-Real-IP`.
+  `Forwarded` and `X-Real-IP`. A name spelt with `_` for `-`, such as
+  `X_Forwarded_Ssl`, counts as the same name.
 - `X-Request-ID`, which carries the fresh id.
 - `X-Client-ASN` and `X-Client-Country`, which carry what `waf` answered. A
   header it did not give is left out. Any of the two the visitor sent is

internal/rproxy/client.go

@@ -105,17 +105,16 @@ func setForwardedHeaders(in, out *http.Request, peer netip.Addr, trusted bool) {
 		return
 	}
 
-	// ReverseProxy has removed Forwarded and the three set below. Go's server
-	// gives header names in canonical form, so the prefix matches the name in
-	// any letter case.
+	// An app behind CGI or FastCGI reads X_Forwarded_Ssl as X-Forwarded-Ssl, so
+	// a name is matched with each _ read as - and in any letter case.
 	for name := range out.Header {
-		if strings.HasPrefix(name, "X-Forwarded-") {
+		spelt := strings.ToLower(strings.ReplaceAll(name, "_", "-"))
+		if strings.HasPrefix(spelt, "x-forwarded-") ||
+			spelt == "forwarded" || spelt == "x-real-ip" {
 			delete(out.Header, name)
 		}
 	}
 
-	out.Header.Del("X-Real-IP")
-
 	out.Header.Set("X-Forwarded-For", forwardedFor)
 	out.Header.Set("X-Forwarded-Host", in.Host)
 	out.Header.Set("X-Forwarded-Proto", "http")

internal/rproxy/rproxy_test.go

@@ -561,6 +561,7 @@ func TestAPeerNotTrustedHasItsForwardedHeadersReplaced(t *testing.T) {
 		"X-Forwarded-Tls-Client-Cert-Info", "X-Real-Ip",
 		"X-Forwarded-Scheme", "X-Forwarded-Ssl", "X-Forwarded-Protocol",
 		"X-Forwarded-Path", "X-Forwarded-Client-Cert",
+		"X_Forwarded_Ssl", "X_Forwarded_Proto", "X_Real_IP",
 	}
 
 	standIn := startWAF(t, allow)
@@ -628,6 +629,7 @@ func TestATrustedProxysForwardedHeadersPassOn(t *testing.T) {
 		forwardedProtoHeader: "https",
 		"X-Real-Ip":          "198.51.100.1",
 		"X-Forwarded-Ssl":    "on",
+		"X_Forwarded_Ssl":    "on",
 	}
 
 	req := newRequest(t, http.MethodGet, addr, "/", http.NoBody)

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,10 @@ 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
-// process, and what rproxy writes.
-func startRProxyProcess(t *testing.T, env ...string) (string, *exec.Cmd, *output) {
+// settings in env, each as NAME=value. It returns where rproxy listens and a
+// function that sends rproxy SIGTERM and fails the test unless it exits with
+// status 0 within waitLimit.
+func startRProxyProcess(t *testing.T, env ...string) (string, func()) {
 	t.Helper()
 
 	binary, err := os.Executable()
@@ -517,11 +518,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(),
@@ -529,19 +527,25 @@ func startRProxyProcess(t *testing.T, env ...string) (string, *exec.Cmd, *output
 		"SWRP_LISTEN_ADDR="+localhost+":0")
 	cmd.Env = append(cmd.Env, env...)
 
-	err = cmd.Start()
-	if err != nil {
-		t.Fatalf("start: %v", err)
+	exited := startProcess(t, cmd)
+
+	addr, _ := out.lineBeforeExit(t, "starting", exited)["address"].(string)
+
+	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")
+		}
 	}
-
-	t.Cleanup(func() {
-		_ = cmd.Process.Kill()
-		_ = cmd.Wait()
-	})
-
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
-
-	return addr, cmd, out
 }
 
 func TestRProxyAsksAWAFThatSpeaksHTTP2OverHTTP1(t *testing.T) {
@@ -572,7 +576,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 +655,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 +754,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 +849,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 +872,5 @@ func TestMainRunsRProxy(t *testing.T) {
 		t.Errorf("health check answered %q (%v)", body, err)
 	}
 
-	err = cmd.Process.Signal(syscall.SIGTERM)
-	if err != nil {
-		t.Fatalf("signal: %v", err)
-	}
-
-	err = cmd.Wait()
-	if err != nil {
-		t.Errorf("exit: %v; output:\n%s", err, out.text())
-	}
+	stop()
 }

internal/sww/waf_test.go

@@ -38,6 +38,35 @@ func TestMain(m *testing.M) {
 	os.Exit(sww.Main(testVersion))
 }
 
+// startProcess starts cmd and returns a channel that gets its exit status. As
+// the test ends, cmd is killed and the test waits for it to exit.
+func startProcess(t *testing.T, cmd *exec.Cmd) <-chan int {
+	t.Helper()
+
+	err := cmd.Start()
+	if err != nil {
+		t.Fatalf("start: %v", err)
+	}
+
+	exited := make(chan int, 1)
+	waitReturned := make(chan struct{})
+
+	go func() {
+		_ = cmd.Wait()
+		exited <- cmd.ProcessState.ExitCode()
+
+		close(waitReturned)
+	}()
+
+	t.Cleanup(func() {
+		_ = cmd.Process.Kill()
+
+		<-waitReturned
+	})
+
+	return exited
+}
+
 func TestMainRunsWAF(t *testing.T) {
 	t.Parallel()
 
@@ -54,12 +83,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(),
@@ -70,17 +96,9 @@ func TestMainRunsWAF(t *testing.T) {
 		rulesDir+"="+t.TempDir(),
 		lookupSource+"=off")
 
-	err = cmd.Start()
-	if err != nil {
-		t.Fatalf("start: %v", err)
-	}
+	exited := startProcess(t, cmd)
 
-	t.Cleanup(func() {
-		_ = cmd.Process.Kill()
-		_ = cmd.Wait()
-	})
-
-	starting := out.line(t, "msg", "starting")
+	starting := out.lineBeforeExit(t, "starting", exited)
 	addr, _ := starting["address"].(string)
 	ask(t, addr, "/", http.StatusOK, waf.DispositionAllow)
 
@@ -90,9 +108,13 @@ func TestMainRunsWAF(t *testing.T) {
 		t.Fatalf("signal: %v", err)
 	}
 
-	err = cmd.Wait()
-	if err != nil {
-		t.Fatalf("exit: %v; output:\n%s", err, out.text())
+	select {
+	case status := <-exited:
+		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 +237,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()