refactor: reduce memory thrashing in log search (#314)

* feat: reduce memory thrashing in log search

Reuse collections instead of allocating new ones for each test.

go.sum

@@ -111,8 +111,6 @@ github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5t
 golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
 golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
 golang.org/x/crypto v0.0.0-20210921155107-089bfa567519/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc=
-golang.org/x/crypto v0.23.0 h1:dIJU/v2J8Mdglj/8rJ6UUOM3Zc9zLZxVZwwxMooUSAI=
-golang.org/x/crypto v0.23.0/go.mod h1:CKFgDieR+mRhux2Lsu27y0fO304Db0wZe70UKqHu0v8=
 golang.org/x/crypto v0.24.0 h1:mnl8DM0o513X8fdIkmyFE/5hTYxbwYOjDS/+rK6qpRI=
 golang.org/x/crypto v0.24.0/go.mod h1:Z1PMYSOR5nyMcyAVAIQSKCDwalqy85Aqn1x3Ws4L5DM=
 golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4=
@@ -121,8 +119,6 @@ golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLL
 golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg=
 golang.org/x/net v0.0.0-20220722155237-a158d28d115b/go.mod h1:XRhObCWvk6IyKnWLug+ECip1KBveYUHfp+8e9klMJ9c=
 golang.org/x/net v0.5.0/go.mod h1:DivGGAXEgPSlEBzxGzZI+ZLohi+xUj054jfeKui00ws=
-golang.org/x/net v0.25.0 h1:d/OCCoBEUq33pjydKrGQhw7IlUPI2Oylr+8qLx49kac=
-golang.org/x/net v0.25.0/go.mod h1:JkAGAh7GEvH74S6FOH42FLoXpXbE/aqXSrIQjXgsiwM=
 golang.org/x/net v0.26.0 h1:soB7SVo0PWrY4vPW/+ay0jKDNScG2X9wFeYlXIvJsOQ=
 golang.org/x/net v0.26.0/go.mod h1:5YKkiSynbBIh3p6iOc/vibscux0x38BZDkn8sCUPxHE=
 golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
@@ -140,8 +136,6 @@ golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.4.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.20.0 h1:Od9JTbYCk261bKm4M/mw7AklTlFYIa0bIp9BgSm1S8Y=
-golang.org/x/sys v0.20.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/sys v0.21.0 h1:rF+pYz3DAGSQAxAu1CbC7catZg4ebC4UIeIhKxBZvws=
 golang.org/x/sys v0.21.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
@@ -152,8 +146,6 @@ golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk=
 golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
 golang.org/x/text v0.3.7/go.mod h1:u+2+/6zg+i71rQMx5EYifcz6MCKuco9NR6JIITiCfzQ=
 golang.org/x/text v0.6.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8=
-golang.org/x/text v0.15.0 h1:h1V/4gjBv8v9cjcR6+AR5+/cIYK5N/WAgiv4xlsEtAk=
-golang.org/x/text v0.15.0/go.mod h1:18ZOQIKpY8NJVqYksKHtTdi31H5itFRjB5/qKTNYzSU=
 golang.org/x/text v0.16.0 h1:a94ExnEXNtEwYLGJSIUxnWoxoRz/ZcCsV63ROupILh4=
 golang.org/x/text v0.16.0/go.mod h1:GhwF1Be+LQoKShO3cGOHzqOgRrGaYc9AvblQOmPVHnI=
 golang.org/x/time v0.5.0 h1:o7cqy6amK/52YcAKIPlM3a+Fpj35zvRj2TP+e1xFSfk=

waflog/read.go

@@ -16,16 +16,19 @@ import (
 	"github.com/rs/zerolog/log"
 )
 
+const maxRuleIdsEstimate = 15
+
+var ruleIdsSet = make(map[uint]bool, maxRuleIdsEstimate)
+
 // TriggeredRules returns the IDs of all the rules found in the log for the current test
 func (ll *FTWLogLines) TriggeredRules() []uint {
-	if ll.triggeredRules != nil {
+	if ll.triggeredRulesInitialized {
 		return ll.triggeredRules
 	}
+	ll.triggeredRulesInitialized = true
 
 	lines := ll.getMarkedLines()
-
 	regex := regexp.MustCompile(`\[id "(\d+)"\]|"id":\s*"?(\d+)"?`)
-	ruleIds := []uint{}
 	for _, line := range lines {
 		log.Trace().Msgf("ftw/waflog: Looking for any rule in %s", line)
 		match := regex.FindAllSubmatch(line, -1)
@@ -42,13 +45,21 @@ func (ll *FTWLogLines) TriggeredRules() []uint {
 						log.Error().Caller().Msgf("Failed to parse uint from %s", submatch)
 						continue
 					}
-					ruleIds = append(ruleIds, uint(ruleId))
+					ruleIdsSet[uint(ruleId)] = true
 				}
 			}
 		}
 	}
+	ruleIds := make([]uint, 0, len(ruleIdsSet))
+	for ruleId := range ruleIdsSet {
+		ruleIds = append(ruleIds, ruleId)
+	}
 	ll.triggeredRules = ruleIds
-	return ruleIds
+	// Reset map for next use
+	for key := range ruleIdsSet {
+		delete(ruleIdsSet, key)
+	}
+	return ll.triggeredRules
 }
 
 // ContainsAllIds returns true if all of the specified rule IDs appear in the log for the current test.
@@ -106,20 +117,19 @@ func (ll *FTWLogLines) MatchesRegex(pattern string) bool {
 }
 
 func (ll *FTWLogLines) getMarkedLines() [][]byte {
-	if ll.markedLines != nil {
+	if ll.markedLinesInitialized {
 		return ll.markedLines
 	}
+	ll.markedLinesInitialized = true
 
 	if ll.startMarker == nil || ll.endMarker == nil {
 		log.Fatal().Msg("Both start and end marker must be set before the log can be inspected")
 	}
 
-	var found [][]byte
-
 	fi, err := ll.logFile.Stat()
 	if err != nil {
 		log.Error().Caller().Msgf("cannot read file's size")
-		return found
+		return ll.markedLines
 	}
 
 	// Lines in modsec logging can be quite large
@@ -149,11 +159,10 @@ func (ll *FTWLogLines) getMarkedLines() [][]byte {
 
 		saneCopy := make([]byte, len(line))
 		copy(saneCopy, line)
-		found = append(found, saneCopy)
+		ll.markedLines = append(ll.markedLines, saneCopy)
 	}
 
-	ll.markedLines = found
-	return found
+	return ll.markedLines
 }
 
 // CheckLogForMarker reads the log file and searches for a marker line.

waflog/read_test.go

@@ -114,7 +114,7 @@ func (s *readTestSuite) TestReadGetMarkedLines() {
 	s.Equal(len(foundLines), 3, "found unexpected number of log lines")
 
 	for index, line := range strings.Split(logLinesOnly, "\n") {
-		s.Equalf(foundLines[index], []byte(line), "log lines don't match: \n%s\n%s", line, string(foundLines[index]))
+		s.Equalf(string(foundLines[index]), line, "log lines don't match: \n%s\n%s", line, string(foundLines[index]))
 	}
 }
 

waflog/types.go

@@ -6,16 +6,19 @@ package waflog
 
 import (
 	"os"
+	"slices"
 )
 
 // FTWLogLines represents the filename to search for logs in a certain timespan
 type FTWLogLines struct {
-	logFile             *os.File
-	LogMarkerHeaderName []byte
-	startMarker         []byte
-	endMarker           []byte
-	triggeredRules      []uint
-	markedLines         [][]byte
+	logFile                   *os.File
+	LogMarkerHeaderName       []byte
+	startMarker               []byte
+	endMarker                 []byte
+	triggeredRules            []uint
+	markedLines               [][]byte
+	markedLinesInitialized    bool
+	triggeredRulesInitialized bool
 }
 
 func (ll *FTWLogLines) StartMarker() []byte {
@@ -29,6 +32,8 @@ func (ll *FTWLogLines) EndMarker() []byte {
 func (ll *FTWLogLines) reset() {
 	ll.startMarker = nil
 	ll.endMarker = nil
-	ll.triggeredRules = nil
-	ll.markedLines = nil
+	ll.triggeredRules = slices.Delete(ll.triggeredRules, 0, len(ll.triggeredRules))
+	ll.markedLines = slices.Delete(ll.markedLines, 0, len(ll.markedLines))
+	ll.markedLinesInitialized = false
+	ll.triggeredRulesInitialized = false
 }

waflog/waflog_test.go

@@ -70,7 +70,6 @@ func (s *waflogTestSuite) TestLogLinesReset() {
 	s.Equal("X-Tests", string(ll.LogMarkerHeaderName))
 	s.Nil(ll.startMarker)
 	s.Nil(ll.endMarker)
-	s.Nil(ll.triggeredRules)
-	s.Nil(ll.triggeredRules)
-	s.Nil(ll.markedLines)
+	s.Empty(ll.triggeredRules)
+	s.Empty(ll.markedLines)
 }