From 0ab14a0698152fa0ed2a3938962cd5044fb7f9f1 Mon Sep 17 00:00:00 2001 From: sneak Date: Tue, 10 Nov 2026 23:01:40 +0000 Subject: [PATCH] Discriminator tests: time the sixteen-thousand-cookie requests without wall time (closes #308) The two tests that send sixteen thousand cookies now ask discriminator in a synctest bubble. There only waiting moves the clock, so a busy host no longer fails them. The check that the Core Rule Set never read the request still covers the work that would take over a second. askDirectly now returns the whole answer, so these tests keep checking the disposition header. Model: opus-5-5 --- internal/discriminator/answertime_test.go | 76 ++++++++++++++--------- 1 file changed, 47 insertions(+), 29 deletions(-) diff --git a/internal/discriminator/answertime_test.go b/internal/discriminator/answertime_test.go index 684a8d6..eb3a783 100644 --- a/internal/discriminator/answertime_test.go +++ b/internal/discriminator/answertime_test.go @@ -67,23 +67,45 @@ func fillHeaders(req *http.Request, total int) { } } +// askWithSixteenThousandCookies hands a question about a request with sixteen +// thousand cookies to a discriminator with env in a synctest bubble. It returns +// the answer, how long the request waited, and the request's log line. In the +// bubble only waiting moves the clock, so a busy host cannot fail the test. The +// Core Rule Set reading every cookie is the work that takes over a second, and +// the log line shows whether it did. +func askWithSixteenThousandCookies( + t *testing.T, env map[string]string, +) (answer, time.Duration, logLine) { + t.Helper() + + var ( + got answer + took time.Duration + line logLine + ) + + synctest.Test(t, func(t *testing.T) { + server, out, _ := newDiscriminator(t, "", time.Now, env) + + got, took = askDirectly(t, server, func(req *http.Request) { + req.Header.Set(cookieHeader, strings.Repeat("a;", 16000)) + }) + line = out.requestLine(t) + }) + + return got, took, line +} + func TestSixteenThousandCookiesAreRefusedWellWithinTheTimeLimit(t *testing.T) { t.Parallel() - s := startDiscriminator(t, "", map[string]string{wafMode: block}) - req := s.question(siteA, client, "/") - req.Header.Set(cookieHeader, strings.Repeat("a;", 16000)) + got, took, line := askWithSixteenThousandCookies(t, map[string]string{wafMode: block}) - began := time.Now() - got := do(t, req) - - if took := time.Since(began); took >= answerTimeLimit/2 { + if took >= answerTimeLimit/2 { t.Errorf("answered after %s, want well within %s", took, answerTimeLimit) } wantDisposition(t, got, tooLarge, discriminator.DispositionDeny) - - line := s.out.requestLine(t) wantLine(t, line, tooLarge, requestlog.ActionRequestHeaderTooLarge) if line.DurationCoreRuleSetMS != nil { @@ -205,20 +227,15 @@ func TestClientInTheAllowNetsSkipsTheHeaderLimits(t *testing.T) { func TestObserveModeAllowsARequestOverTheHeaderLimitsUnread(t *testing.T) { t.Parallel() - s := startDiscriminator(t, "", map[string]string{mode: observe, wafMode: block}) - req := s.question(siteA, client, "/") - req.Header.Set(cookieHeader, strings.Repeat("a;", 16000)) + got, took, line := askWithSixteenThousandCookies(t, + map[string]string{mode: observe, wafMode: block}) - began := time.Now() - got := do(t, req) - - if took := time.Since(began); took >= answerTimeLimit/2 { + if took >= answerTimeLimit/2 { t.Errorf("answered after %s, want well within %s", took, answerTimeLimit) } wantDisposition(t, got, http.StatusOK, discriminator.DispositionAllow) - line := s.out.requestLine(t) if line.WouldAction != requestlog.ActionRequestHeaderTooLarge || line.DurationCoreRuleSetMS != nil { t.Errorf("would_action %q and duration_core_rule_set_ms %v, want %q and none", @@ -346,10 +363,10 @@ func newDiscriminatorInBubble( } // askDirectly hands a question about a request from client straight to server, -// as change leaves it, and returns the answer's status and how long it took. +// as change leaves it, and returns the answer and how long it took. func askDirectly( t *testing.T, server *discriminator.Server, change func(*http.Request), -) (int, time.Duration) { +) (answer, time.Duration) { t.Helper() req := httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/", http.NoBody) @@ -362,8 +379,9 @@ func askDirectly( began := time.Now() server.Handler.ServeHTTP(recorder, req) + took := time.Since(began) - return recorder.Code, time.Since(began) + return readAnswer(recorder.Result()), took } // banClient bans client at now. @@ -456,13 +474,13 @@ func TestARefusedRequestDoesNotWaitForASlowGeoJS(t *testing.T) { server, out := newDiscriminatorInBubble(t, tc.env) tc.prepare(t, server, time.Now()) - status, took := askDirectly(t, server, func(req *http.Request) { + got, took := askDirectly(t, server, func(req *http.Request) { req.Header.Set(cookieHeader, tc.cookie) }) - if status != tc.status || took != 0 { + if got.status != tc.status || took != 0 { t.Errorf("answered %d after %s, want %d at once; output:\n%s", - status, took, tc.status, out.text()) + got.status, took, tc.status, out.text()) } wantLine(t, out.requestLine(t), tc.status, tc.action) @@ -513,11 +531,11 @@ func TestAQuestionWaitsForASlowGeoJSOnlyAsLongAsTheDefaultSays(t *testing.T) { server, out := newDiscriminatorInBubble(t, tc.env) tc.prepare(t, server, time.Now()) - status, took := askDirectly(t, server, func(*http.Request) {}) + got, took := askDirectly(t, server, func(*http.Request) {}) - if status != tc.status || took != defaultLookupWait { + if got.status != tc.status || took != defaultLookupWait { t.Errorf("answered %d after %s, want %d after %s; output:\n%s", - status, took, tc.status, defaultLookupWait, out.text()) + got.status, took, tc.status, defaultLookupWait, out.text()) } wantLine(t, out.requestLine(t), tc.status, tc.action) @@ -561,15 +579,15 @@ func TestDiscriminatorAnswersWithinTheTimeLimitWhileEveryOutsideSourceHangs( go server.Lists.Run(t.Context()) - status, took := askDirectly(t, server, func(req *http.Request) { + got, took := askDirectly(t, server, func(req *http.Request) { req.Header.Set("User-Agent", "test") req.Header.Set("Accept", "*/*") req.Host = siteA }) - if status != http.StatusOK || took >= answerTimeLimit { + if got.status != http.StatusOK || took >= answerTimeLimit { t.Errorf("answered %d after %s, want %d within %s; output:\n%s", - status, took, http.StatusOK, answerTimeLimit, out.text()) + got.status, took, http.StatusOK, answerTimeLimit, out.text()) } // Each outside source was asked, and none has answered. The stand-in for