1package middleware
2
3import (
4 "fmt"
5 "io"
6 "net/http"
7 "net/http/httptest"
8 "testing"
9
10 "github.com/stretchr/testify/assert"
11 "github.com/stretchr/testify/require"
12
13 out "github.com/bnema/gordon/internal/boundaries/out"
14)
15
16// mockAccessLogWriter records written entries and optionally returns an error.
17type mockAccessLogWriter struct {
18 entries []out.AccessLogEntry
19 err error
20}
21
22func (m *mockAccessLogWriter) Write(entry out.AccessLogEntry) error {
23 m.entries = append(m.entries, entry)
24 return m.err
25}
26
27func TestAccessLogger_EmitsEntryPerRequest(t *testing.T) {
28 mock := &mockAccessLogWriter{}
29 log := testLogger()
30
31 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
32 w.WriteHeader(http.StatusOK)
33 _, _ = w.Write([]byte("hello"))
34 }))
35
36 req := httptest.NewRequest(http.MethodGet, "/some/path?foo=bar", nil)
37 req.RemoteAddr = "192.168.1.100:12345"
38 req.Header.Set("User-Agent", "test-agent")
39 req.Header.Set("Referer", "https://example.com")
40 req.RequestURI = "/some/path?foo=bar"
41 req.Host = "example.com"
42 req.Proto = "HTTP/1.1"
43 rw := httptest.NewRecorder()
44
45 handler.ServeHTTP(rw, req)
46
47 require.Len(t, mock.entries, 1)
48 e := mock.entries[0]
49 assert.Equal(t, http.MethodGet, e.Method)
50 assert.Equal(t, "/some/path", e.Path)
51 assert.Equal(t, "foo=bar", e.Query)
52 assert.Equal(t, "example.com", e.Host)
53 assert.Equal(t, http.StatusOK, e.Status)
54 assert.Equal(t, 5, e.BytesSent)
55 assert.Equal(t, "test-agent", e.UserAgent)
56 assert.Equal(t, "https://example.com", e.Referer)
57 assert.Equal(t, "HTTP/1.1", e.Proto)
58 assert.NotEmpty(t, e.RequestID)
59 assert.Equal(t, "192.168.1.100", e.ClientIP)
60}
61
62func TestAccessLogger_RedactsSensitiveQueryParams(t *testing.T) {
63 mock := &mockAccessLogWriter{}
64 log := testLogger()
65
66 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
67 w.WriteHeader(http.StatusOK)
68 }))
69 server := httptest.NewServer(handler)
70 defer server.Close()
71
72 resp, err := http.Get(server.URL + "/oauth/callback?code=secret-code&state=ok&token=secret-token&api_key=top-secret&session_id=session-secret")
73 require.NoError(t, err)
74 defer func() {
75 assert.NoError(t, resp.Body.Close())
76 }()
77 _, err = io.Copy(io.Discard, resp.Body)
78 require.NoError(t, err)
79
80 require.Len(t, mock.entries, 1)
81 assert.Equal(t, "code=[REDACTED]&state=ok&token=[REDACTED]&api_key=[REDACTED]&session_id=[REDACTED]", mock.entries[0].Query)
82}
83
84func TestAccessLogger_RedactsSensitiveReferers(t *testing.T) {
85 tests := []struct {
86 name string
87 referer string
88 want string
89 }{
90 {
91 name: "query params",
92 referer: "https://idp.example.com/callback?code=secret-code&state=ok&token=secret-token",
93 want: "https://idp.example.com/callback?code=[REDACTED]&state=ok&token=[REDACTED]",
94 },
95 {
96 name: "fragment removed",
97 referer: "https://idp.example.com/callback?state=ok#access_token=secret-token",
98 want: "https://idp.example.com/callback?state=ok",
99 },
100 {
101 name: "userinfo removed",
102 referer: "https://user:secret-password@idp.example.com/callback?code=secret-code",
103 want: "https://idp.example.com/callback?code=[REDACTED]",
104 },
105 {
106 name: "malformed query key redacted conservatively",
107 referer: "https://idp.example.com/callback?token%ZZ=secret-token&state=ok",
108 want: "https://idp.example.com/callback?token%ZZ=[REDACTED]&state=ok",
109 },
110 }
111
112 for _, tt := range tests {
113 t.Run(tt.name, func(t *testing.T) {
114 mock := &mockAccessLogWriter{}
115 log := testLogger()
116
117 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
118 w.WriteHeader(http.StatusOK)
119 }))
120
121 req := httptest.NewRequest(http.MethodGet, "/target", nil)
122 req.Header.Set("Referer", tt.referer)
123 rw := httptest.NewRecorder()
124
125 handler.ServeHTTP(rw, req)
126
127 require.Len(t, mock.entries, 1)
128 assert.Equal(t, tt.want, mock.entries[0].Referer)
129 assert.NotContains(t, mock.entries[0].Referer, "secret")
130 })
131 }
132}
133
134func TestAccessLogger_RequestIDReused(t *testing.T) {
135 mock := &mockAccessLogWriter{}
136 log := testLogger()
137
138 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
139 w.WriteHeader(http.StatusOK)
140 }))
141
142 req := httptest.NewRequest(http.MethodGet, "/", nil)
143 req.Header.Set("X-Request-ID", "fixed-id-123")
144 rw := httptest.NewRecorder()
145
146 handler.ServeHTTP(rw, req)
147
148 require.Len(t, mock.entries, 1)
149 assert.Equal(t, "fixed-id-123", mock.entries[0].RequestID)
150}
151
152func TestAccessLogger_ExcludeHealthCheckUA(t *testing.T) {
153 mock := &mockAccessLogWriter{}
154 log := testLogger()
155
156 handler := AccessLogger(mock, true, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
157 w.WriteHeader(http.StatusOK)
158 }))
159
160 req := httptest.NewRequest(http.MethodGet, "/health", nil)
161 req.Header.Set("User-Agent", "Gordon-HealthCheck/1.0")
162 rw := httptest.NewRecorder()
163
164 handler.ServeHTTP(rw, req)
165
166 assert.Empty(t, mock.entries, "health-check request should not be logged")
167}
168
169func TestAccessLogger_ExcludeLoopbackIP(t *testing.T) {
170 mock := &mockAccessLogWriter{}
171 log := testLogger()
172
173 handler := AccessLogger(mock, true, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
174 w.WriteHeader(http.StatusOK)
175 }))
176
177 req := httptest.NewRequest(http.MethodGet, "/health", nil)
178 req.RemoteAddr = "127.0.0.1:54321"
179 rw := httptest.NewRecorder()
180
181 handler.ServeHTTP(rw, req)
182
183 assert.Empty(t, mock.entries, "loopback request should not be logged")
184}
185
186func TestAccessLogger_NoExcludeWhenDisabled(t *testing.T) {
187 mock := &mockAccessLogWriter{}
188 log := testLogger()
189
190 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
191 w.WriteHeader(http.StatusOK)
192 }))
193
194 req := httptest.NewRequest(http.MethodGet, "/health", nil)
195 req.Header.Set("User-Agent", "Gordon-HealthCheck/1.0")
196 rw := httptest.NewRecorder()
197
198 handler.ServeHTTP(rw, req)
199
200 assert.Len(t, mock.entries, 1, "health-check request should be logged when excludeHealthChecks=false")
201}
202
203func TestAccessLogger_WriteFailureDoesNotAffectResponse(t *testing.T) {
204 mock := &mockAccessLogWriter{err: fmt.Errorf("disk full")}
205 log := testLogger()
206
207 handler := AccessLogger(mock, false, log, nil)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
208 w.WriteHeader(http.StatusOK)
209 _, _ = w.Write([]byte("ok"))
210 }))
211
212 req := httptest.NewRequest(http.MethodGet, "/", nil)
213 rw := httptest.NewRecorder()
214
215 // Should not panic or change the response.
216 handler.ServeHTTP(rw, req)
217
218 assert.Equal(t, http.StatusOK, rw.Code)
219 assert.Equal(t, "ok", rw.Body.String())
220}
221
222func TestAccessLogger_PanicRecoveryChain_Captures500(t *testing.T) {
223 mock := &mockAccessLogWriter{}
224 log := testLogger()
225
226 // Chain: AccessLogger (outer) → PanicRecovery → panicking handler
227 panicHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
228 panic("test panic")
229 })
230 chain := AccessLogger(mock, false, log, nil)(PanicRecovery(log)(panicHandler))
231
232 req := httptest.NewRequest(http.MethodGet, "/crash", nil)
233 rw := httptest.NewRecorder()
234
235 chain.ServeHTTP(rw, req)
236
237 // PanicRecovery should have written 500.
238 assert.Equal(t, http.StatusInternalServerError, rw.Code)
239
240 // AccessLogger must have captured the 500.
241 require.Len(t, mock.entries, 1)
242 assert.Equal(t, http.StatusInternalServerError, mock.entries[0].Status)
243}