| 1 | package home |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "log" |
| 6 | "log/slog" |
| 7 | "net/http" |
| 8 | "net/http/httptest" |
| 9 | "net/url" |
| 10 | "regexp" |
| 11 | "strings" |
| 12 | "testing" |
| 13 | |
| 14 | "github.com/go-chi/chi/v5" |
| 15 | |
| 16 | "amadan.net/oficina/home/internal/home/logtest" |
| 17 | ) |
| 18 | |
| 19 | // TestNoContentInLogs is §12 gate 9 against the app's own surface: it |
| 20 | // drives every route the router declares, with canary-laden input, and |
| 21 | // asserts none of it reaches a log line. Spec §3.4: "no address, team |
| 22 | // name, or queue payload in any log line, error string, job status |
| 23 | // message or metric label." |
| 24 | // |
| 25 | // It passes trivially today — this skeleton logs nothing per request — |
| 26 | // and that is the point. §13 step 1 lists gate 9 beside the skeleton so |
| 27 | // the guard exists before the code it guards. |
| 28 | // |
| 29 | // # What has to stay true for this to keep biting |
| 30 | // |
| 31 | // Routes are enumerated from the router with chi.Walk rather than |
| 32 | // hand-listed, so a route added in step 2 is driven by this test without |
| 33 | // anyone remembering to add it. Three things are still on the author of |
| 34 | // step 2: |
| 35 | // |
| 36 | // - A handler must log through slog.Default() resolved AT CALL TIME, |
| 37 | // or be handed a logger the test can substitute. A logger captured |
| 38 | // into a struct at construction is not reached by SetDefault here. |
| 39 | // Rastrillo resolves slog.Default() at construction, which is why |
| 40 | // its own machinery is outside this gate. |
| 41 | // - A sink that is not slog is invisible. internal/guardstest forbids |
| 42 | // the ones that exist today; a new one needs a new rule there. |
| 43 | // - A route parameter constrained by a regex — {id:[0-9]+} — will not |
| 44 | // match the canary substituted into it, so its route 404s and its |
| 45 | // handler is never driven. There are none today. The day there is |
| 46 | // one, fillParams is where a satisfying value goes. |
| 47 | func TestNoContentInLogs(t *testing.T) { |
| 48 | rec := logtest.NewRecorder() |
| 49 | |
| 50 | // slog.SetDefault also calls log.SetOutput and log.SetFlags(0), and |
| 51 | // restoring a default-handler logger does NOT undo that — the branch |
| 52 | // is skipped. Left alone, every later test in this package would have |
| 53 | // its log output swallowed into a dead recorder. |
| 54 | prevLogger, prevWriter, prevFlags := slog.Default(), log.Writer(), log.Flags() |
| 55 | slog.SetDefault(slog.New(rec.Handler())) |
| 56 | t.Cleanup(func() { |
| 57 | slog.SetDefault(prevLogger) |
| 58 | log.SetOutput(prevWriter) |
| 59 | log.SetFlags(prevFlags) |
| 60 | }) |
| 61 | |
| 62 | app := newTestApp(t) |
| 63 | router := app.Router() |
| 64 | |
| 65 | routes, ok := router.(chi.Routes) |
| 66 | if !ok { |
| 67 | t.Fatalf("Router() is %T, which does not implement chi.Routes: "+ |
| 68 | "this test enumerates routes so new ones are covered automatically", router) |
| 69 | } |
| 70 | |
| 71 | // Each route is driven with the method it was DECLARED with, not |
| 72 | // just GET and POST. A route registered only as DELETE or PATCH |
| 73 | // answers 405 to both, so its handler never runs and whatever it |
| 74 | // logs is never seen. |
| 75 | type target struct{ method, path string } |
| 76 | var targets []target |
| 77 | seen := map[target]bool{} |
| 78 | // declared marks the (method, path) pairs the router actually |
| 79 | // registered, as opposed to the extra methods and synthetic paths |
| 80 | // driven alongside them. Only those are required to reach a handler. |
| 81 | declared := map[target]bool{} |
| 82 | add := func(method, path string, isDeclared bool) { |
| 83 | tg := target{method: method, path: path} |
| 84 | if isDeclared { |
| 85 | declared[tg] = true |
| 86 | } |
| 87 | if !seen[tg] { |
| 88 | seen[tg] = true |
| 89 | targets = append(targets, tg) |
| 90 | } |
| 91 | } |
| 92 | |
| 93 | err := chi.Walk(routes, func(method string, route string, _ http.Handler, _ ...func(http.Handler) http.Handler) error { |
| 94 | // chi route patterns can carry wildcards; make them fetchable. |
| 95 | // Parameters are filled with a canary so a handler that logs |
| 96 | // chi.URLParam logs content rather than the literal "{team}" — |
| 97 | // which is what it logged before, passing the gate. |
| 98 | path := fillParams(strings.ReplaceAll(route, "/*", "/x")) |
| 99 | add(method, path, true) |
| 100 | add(http.MethodGet, path, false) |
| 101 | add(http.MethodPost, path, false) |
| 102 | return nil |
| 103 | }) |
| 104 | if err != nil { |
| 105 | t.Fatalf("walk routes: %v", err) |
| 106 | } |
| 107 | if len(targets) == 0 { |
| 108 | t.Fatal("walked zero routes: the gate would pass by not looking") |
| 109 | } |
| 110 | // A path that matches nothing, plus a path segment carrying content. |
| 111 | for _, p := range []string{"/no-such-route", "/" + url.PathEscape(logtest.Canaries[1])} { |
| 112 | add(http.MethodGet, p, false) |
| 113 | add(http.MethodPost, p, false) |
| 114 | } |
| 115 | |
| 116 | for _, tg := range targets { |
| 117 | // Sign-in will be a POST with the address in the form body, so |
| 118 | // the body is driven, not just the URL. |
| 119 | body := strings.NewReader(url.Values{ |
| 120 | "address": {logtest.Canaries[0]}, |
| 121 | "team": {logtest.Canaries[1]}, |
| 122 | }.Encode()) |
| 123 | |
| 124 | req := httptest.NewRequest(tg.method, tg.path+"?q="+url.QueryEscape(logtest.Canaries[0]), body) |
| 125 | req.Host = credentialHost |
| 126 | if req.URL.Path == "/" { |
| 127 | req.Host = directoryHost |
| 128 | } |
| 129 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 130 | // csrf.Protect is mounted router-wide and short-circuits a |
| 131 | // state-changing request with no origin evidence — before chi |
| 132 | // matches, so the handler never runs and the gate scans |
| 133 | // nothing. Sending the app's own origin is what lets these |
| 134 | // routes dispatch at all. The rejected path is swept below, |
| 135 | // separately, because it is also a path that could log. |
| 136 | req.Header.Set("Origin", Origin) |
| 137 | // The headers most likely to be logged wholesale by a future |
| 138 | // request logger, each carrying content that must never appear. |
| 139 | req.Header.Set("Referer", "https://"+logtest.Canaries[1]+".example.invalid") |
| 140 | req.Header.Set("User-Agent", logtest.Canaries[0]) |
| 141 | req.Header.Set("X-Forwarded-For", logtest.Canaries[0]) |
| 142 | req.AddCookie(&http.Cookie{Name: "team", Value: logtest.Canaries[2]}) |
| 143 | |
| 144 | // Ask chi whether it DISPATCHED, rather than reading the status |
| 145 | // the handler chose. A handler that answers 404 itself — which |
| 146 | // is what a directory route does for an unknown team slug, and |
| 147 | // so the first real route step 2 adds — ran perfectly well and |
| 148 | // was scanned. Judging by status code would fail it with a |
| 149 | // diagnosis pointing at fillParams, which is the opposite of |
| 150 | // what happened. RoutePattern is empty only when nothing matched. |
| 151 | rctx := chi.NewRouteContext() |
| 152 | req = req.WithContext(context.WithValue(req.Context(), chi.RouteCtxKey, rctx)) |
| 153 | w := httptest.NewRecorder() |
| 154 | router.ServeHTTP(w, req) |
| 155 | |
| 156 | // A declared route that chi never dispatched ran no handler, so |
| 157 | // anything it logs went unscanned and the gate passed by not |
| 158 | // looking — the failure mode the zero-routes check above guards, |
| 159 | // one level down. The cause will be a regex-constrained |
| 160 | // parameter ({id:[0-9]+}) the canary does not satisfy, or the |
| 161 | // nested-brace shape {id:[0-9]{2}}, which fillParams mangles |
| 162 | // rather than fills. Both are silent today; this makes them loud. |
| 163 | if declared[tg] && rctx.RoutePattern() == "" { |
| 164 | t.Errorf("%s %s was declared but chi matched no route, so its handler never ran "+ |
| 165 | "and gate 9 did not scan it. If it has a constrained parameter, fillParams "+ |
| 166 | "needs a value that satisfies it.", tg.method, tg.path) |
| 167 | } |
| 168 | } |
| 169 | |
| 170 | // The CSRF rejection is its own code path, and it sees the same |
| 171 | // canary-bearing body, headers and cookie. A middleware that logged |
| 172 | // what it refused would leak exactly the address the form carried. |
| 173 | for _, tg := range targets { |
| 174 | if tg.method != http.MethodPost { |
| 175 | continue |
| 176 | } |
| 177 | body := strings.NewReader(url.Values{"address": {logtest.Canaries[0]}}.Encode()) |
| 178 | req := httptest.NewRequest(tg.method, tg.path, body) |
| 179 | req.Host = credentialHost |
| 180 | if req.URL.Path == "/" { |
| 181 | req.Host = directoryHost |
| 182 | } |
| 183 | req.Header.Set("Content-Type", "application/x-www-form-urlencoded") |
| 184 | req.Header.Set("Referer", "https://"+logtest.Canaries[1]+".example.invalid") |
| 185 | req.Header.Set("User-Agent", logtest.Canaries[0]) |
| 186 | // No Origin, and a Referer from somewhere else: refused. |
| 187 | router.ServeHTTP(httptest.NewRecorder(), req) |
| 188 | } |
| 189 | |
| 190 | rec.AssertNoContent(t) |
| 191 | } |
| 192 | |
| 193 | // chiParam matches one chi route parameter, {team} or {id:[0-9]+}. |
| 194 | var chiParam = regexp.MustCompile(`\{[^{}]*\}`) |
| 195 | |
| 196 | // fillParams substitutes a canary for every route parameter. |
| 197 | // |
| 198 | // Without it the test requests the pattern literally, so chi.URLParam |
| 199 | // returns "{team}" and a handler that logs the team slug from the path |
| 200 | // passes the gate — while in production it logs a real team name. A team |
| 201 | // slug in a path is the likeliest shape for the directory's own routes. |
| 202 | func fillParams(pattern string) string { |
| 203 | return chiParam.ReplaceAllLiteralString(pattern, url.PathEscape(logtest.Canaries[1])) |
| 204 | } |
| 205 | |
amadan