@@ -3,6 +3,7 @@ package logging
3
3
import (
4
4
"encoding/json"
5
5
"math/rand"
6
+ "os"
6
7
"strings"
7
8
"testing"
8
9
"time"
@@ -11,10 +12,12 @@ import (
11
12
"github.com/stretchr/testify/require"
12
13
)
13
14
14
- func SetupLogger (batchChannel chan * [][]byte , maxBatchSize int , maxLogAge time.Duration ) * batchLogger {
15
+ func SetupLogger (batchChannel chan * [][]byte , maxBatchSize int , maxLogAge time.Duration , redactRequests bool , redactResponses bool ) * batchLogger {
15
16
batchLogger := NewBatchLogger (BatchLoggerOptions {
16
- MaxBatchSize : maxBatchSize ,
17
- MaxLogAge : maxLogAge ,
17
+ MaxBatchSize : maxBatchSize ,
18
+ MaxLogAge : maxLogAge ,
19
+ RedactJSONRequestBodies : redactRequests ,
20
+ RedactJSONResponseBodies : redactResponses ,
18
21
})
19
22
20
23
// Replace the batchHandler with a custom one to throw the batches into a queue that we can receive from for testing
@@ -29,7 +32,7 @@ func TestOldLogIsSentImmediately(t *testing.T) {
29
32
const MaxLogAge = time .Minute
30
33
31
34
batchChannel := make (chan * [][]byte , 2 )
32
- batchLogger := SetupLogger (batchChannel , 1024 * 512 , MaxLogAge )
35
+ batchLogger := SetupLogger (batchChannel , 1024 * 512 , MaxLogAge , false , false )
33
36
34
37
// Create a test log entry & enqueue it
35
38
testLogEntry := LogEntry {
@@ -58,7 +61,7 @@ func TestBatchesDoNotExceedMaxSize(t *testing.T) {
58
61
59
62
// Buffer our batchChannel with TestLogEntryCount spaces (worst case, each entry ends up in its own batch)
60
63
batchChannel := make (chan * [][]byte , TestLogEntryCount )
61
- batchLogger := SetupLogger (batchChannel , MaxBatchSize , time .Second )
64
+ batchLogger := SetupLogger (batchChannel , MaxBatchSize , time .Second , false , false )
62
65
63
66
// Create a bunch of test entries
64
67
testLogEntries := []* LogEntry {}
@@ -124,7 +127,7 @@ func TestOldLogTriggersBatch(t *testing.T) {
124
127
const MaxLogAge = time .Minute
125
128
126
129
batchChannel := make (chan * [][]byte , 2 )
127
- batchLogger := SetupLogger (batchChannel , 1024 * 512 , MaxLogAge )
130
+ batchLogger := SetupLogger (batchChannel , 1024 * 512 , MaxLogAge , false , false )
128
131
129
132
// Create ExpectedLogEntryCount-1 test log entries (the last one will trigger a batch)
130
133
testLogEntries := []* LogEntry {}
@@ -172,3 +175,149 @@ func TestOldLogTriggersBatch(t *testing.T) {
172
175
// Assert that the batch has all the same byte slices as the expected batch
173
176
require .ElementsMatch (t , expectedBatch , * batch )
174
177
}
178
+
179
+ func TestRedaction (t * testing.T ) {
180
+ testCases := []struct {
181
+ enableRequestRedaction bool
182
+ enableResponseRedaction bool
183
+ }{
184
+ {false , false },
185
+ {false , true },
186
+ {true , false },
187
+ {true , true },
188
+ }
189
+ for _ , testCase := range testCases {
190
+ const MaxLogAge = time .Minute
191
+
192
+ batchChannel := make (chan * [][]byte , 2 )
193
+ batchLogger := SetupLogger (batchChannel , 1024 * 512 , MaxLogAge , testCase .enableRequestRedaction , testCase .enableResponseRedaction )
194
+
195
+ const testRequestBody = "{\" foo\" :\" bar\" }"
196
+ const expectedRedactedRequestBody = "{\" foo\" :\" \" }"
197
+ const testResponseBody = "{\" baz\" :\" qux\" }"
198
+ const expectedRedactedResponseBody = "{\" baz\" :\" \" }"
199
+
200
+ // Create a test log entry & enqueue it
201
+ testLogEntry := LogEntry {
202
+ Request : Request {
203
+ Body : testRequestBody ,
204
+ },
205
+ Response : Response {
206
+ Body : testResponseBody ,
207
+ },
208
+ DateCreated : time .Now ().UnixMilli () - MaxLogAge .Milliseconds ()* 2 ,
209
+ }
210
+
211
+ // Enqueue the test log entry
212
+ batchLogger .Enqueue (& testLogEntry )
213
+
214
+ // There should then be a batch in the channel for us to receive
215
+ batch := <- batchChannel
216
+
217
+ // Channel should be empty now, as it should only have had one batch in it
218
+ assert .Equal (t , 0 , len (batchChannel ))
219
+
220
+ // Assert the batch had one log entry in it
221
+ require .Equal (t , 1 , len (* batch ))
222
+
223
+ // Unmarshal the log and assert its request/response bodies were redacted as expected
224
+ var logEntry LogEntry
225
+ err := json .Unmarshal ((* batch )[0 ], & logEntry )
226
+ require .Nil (t , err )
227
+ if testCase .enableRequestRedaction {
228
+ assert .Equal (t , expectedRedactedRequestBody , logEntry .Request .Body )
229
+ } else {
230
+ assert .Equal (t , testRequestBody , logEntry .Request .Body )
231
+ }
232
+ if testCase .enableResponseRedaction {
233
+ assert .Equal (t , expectedRedactedResponseBody , logEntry .Response .Body )
234
+ } else {
235
+ assert .Equal (t , testResponseBody , logEntry .Response .Body )
236
+ }
237
+ }
238
+ }
239
+
240
+ func BenchmarkRedactFiretailJSLibPackageLockJson1536B (b * testing.B ) {
241
+ benchmarkRedactJson (b , "testdata/package-lock-firetail-js-lib-1536B.json" )
242
+ }
243
+
244
+ func BenchmarkRedactFiretailJSLibPackageLockJson278KiB (b * testing.B ) {
245
+ benchmarkRedactJson (b , "testdata/package-lock-firetail-js-lib-478KiB.json" )
246
+ }
247
+
248
+ func benchmarkRedactJson (b * testing.B , testFile string ) {
249
+ testJson , err := os .ReadFile (testFile )
250
+ if err != nil {
251
+ b .Error (err .Error ())
252
+ }
253
+ b .ResetTimer ()
254
+ b .StopTimer ()
255
+ for n := 0 ; n < b .N ; n ++ {
256
+ // redactJson mutates the input, so we need to copy it each time
257
+ testJsonCopy := make ([]byte , len (testJson ))
258
+ copy (testJsonCopy , testJson )
259
+ b .StartTimer ()
260
+ _ , err = redactJson (testJsonCopy )
261
+ b .StopTimer ()
262
+ if err != nil {
263
+ b .Error (err .Error ())
264
+ }
265
+ }
266
+ }
267
+
268
+ func TestRedactJson (t * testing.T ) {
269
+ testCases := []struct {
270
+ testJson string
271
+ expectedJson string
272
+ }{
273
+ {"\" foo\" " , "\" \" " },
274
+ {"3.14159" , "0" },
275
+ {"true" , "true" },
276
+ {"false" , "true" },
277
+ {"null" , "null" },
278
+ {"{}" , "{}" },
279
+ {"[]" , "[]" },
280
+ // Objects with values of different types
281
+ {"{\" foo\" :\" bar\" }" , "{\" foo\" :\" \" }" },
282
+ {"{\" foo\" :3.14159}" , "{\" foo\" :0}" },
283
+ {"{\" foo\" :true}" , "{\" foo\" :true}" },
284
+ {"{\" foo\" :false}" , "{\" foo\" :true}" },
285
+ {"{\" foo\" :null}" , "{\" foo\" :null}" },
286
+ // Lists with values of different types
287
+ {"[\" foo\" ]" , "[\" \" ]" },
288
+ {"[3.14159]" , "[0]" },
289
+ {"[false]" , "[true]" },
290
+ {"[true]" , "[true]" },
291
+ {"[null]" , "[null]" },
292
+ // Lists with two values of the same type
293
+ {"[\" foo\" ,\" bar\" ]" , "[\" \" ,\" \" ]" },
294
+ {"[3.14159,2.71828]" , "[0,0]" },
295
+ {"[false,false]" , "[true,true]" },
296
+ {"[false,true]" , "[true,true]" },
297
+ {"[true,false]" , "[true,true]" },
298
+ {"[true,true]" , "[true,true]" },
299
+ {"[null,null]" , "[null,null]" },
300
+ // Lists with three values of the same type
301
+ {"[\" foo\" ,\" bar\" ,\" baz\" ]" , "[\" \" ,\" \" ,\" \" ]" },
302
+ {"[3.14159,2.71828,1.61803]" , "[0,0,0]" },
303
+ {"[false,false,false]" , "[true,true,true]" },
304
+ {"[false,false,true]" , "[true,true,true]" },
305
+ {"[false,true,false]" , "[true,true,true]" },
306
+ {"[false,true,true]" , "[true,true,true]" },
307
+ {"[true,false,false]" , "[true,true,true]" },
308
+ {"[true,false,true]" , "[true,true,true]" },
309
+ {"[true,true,false]" , "[true,true,true]" },
310
+ {"[true,true,true]" , "[true,true,true]" },
311
+ {"[null,null,null]" , "[null,null,null]" },
312
+ // Lists with mixed types
313
+ {"[\" foo\" ,3.14159,true,false,null]" , "[\" \" ,0,true,true,null]" },
314
+ // Some more complex examples
315
+ {"{\" foo\" :[\" bar\" ,3.14159,true,false,null]}" , "{\" foo\" :[\" \" ,0,true,true,null]}" },
316
+ {"[{\" foo\" :\" bar\" },{\" baz\" :3.14159},{\" qux\" :true},{\" quux\" :false},{\" corge\" :null}]" , "[{\" foo\" :\" \" },{\" baz\" :0},{\" qux\" :true},{\" quux\" :true},{\" corge\" :null}]" },
317
+ }
318
+ for _ , testCase := range testCases {
319
+ result , err := redactJson ([]byte (testCase .testJson ))
320
+ require .Nil (t , err )
321
+ assert .Equal (t , testCase .expectedJson , string (result ))
322
+ }
323
+ }
0 commit comments