From c7f46224d91c2b6d291cb6bd4ea09f4b7eaa4d41 Mon Sep 17 00:00:00 2001
From: Jason Ertel <jason.ertel@securityonionsolutions.com>
Date: Wed, 13 Mar 2024 17:11:16 -0400
Subject: [PATCH] add more logging

---
 agent/modules/suriquery/suriquery.go | 42 ++++++++++++++++++----------
 1 file changed, 28 insertions(+), 14 deletions(-)

diff --git a/agent/modules/suriquery/suriquery.go b/agent/modules/suriquery/suriquery.go
index 3e2ddabb..d10dbae6 100644
--- a/agent/modules/suriquery/suriquery.go
+++ b/agent/modules/suriquery/suriquery.go
@@ -65,7 +65,7 @@ func (suri *SuriQuery) Init(cfg module.ModuleConfig) error {
 	suri.dataLagMs = module.GetIntDefault(cfg, "dataLagMs", DEFAULT_DATA_LAG_MS)
 	suri.pcapMaxCount = module.GetIntDefault(cfg, "pcapMaxCount", DEFAULT_PCAP_MAX_COUNT)
 	if suri.agent == nil {
-		err = errors.New("Unable to invoke JobMgr.AddJobProcessor due to nil agent")
+		err = errors.New("unable to invoke JobMgr.AddJobProcessor due to nil agent")
 	} else {
 		suri.agent.JobMgr.AddJobProcessor(suri)
 	}
@@ -111,7 +111,7 @@ func (suri *SuriQuery) ProcessJob(job *model.Job, reader io.ReadCloser) (io.Read
 			"jobBeginDate":           job.Filter.BeginTime,
 			"jobEndDate":             job.Filter.EndTime,
 		}).Info("Skipping suri processor due to date range conflict")
-		err = errors.New("No data available for the requested dates")
+		err = errors.New("no data available for the requested dates")
 	} else {
 		log.WithFields(log.Fields{
 			"jobId": job.Id,
@@ -175,9 +175,12 @@ func (suri *SuriQuery) decompress(path string) (string, error) {
 }
 
 func (suri *SuriQuery) streamPacketsInPcaps(paths []string, filter *model.Filter) (io.ReadCloser, int, error) {
-	allPackets := make([]gopacket.Packet, 0, 0)
+	allPackets := make([]gopacket.Packet, 0)
 
 	for _, path := range paths {
+		log.WithFields(log.Fields{
+			"pcapPath": path,
+		}).Debug("Analyzing Suricata PCAP file")
 		decompressedPath, derr := suri.decompress(path)
 		if derr != nil {
 			log.WithError(derr).WithField("pcapPath", path).Error("Failed to decompress PCAP file")
@@ -188,12 +191,16 @@ func (suri *SuriQuery) streamPacketsInPcaps(paths []string, filter *model.Filter
 		if perr != nil {
 			log.WithError(perr).WithField("pcapPath", decompressedPath).Error("Failed to parse PCAP file")
 		}
-		if packets != nil && len(packets) > 0 {
+		if len(packets) > 0 {
 			log.WithFields(log.Fields{
 				"pcapPath":    decompressedPath,
 				"packetCount": len(packets),
-			}).Debug("found matching packets")
+			}).Info("Found matching Suricata packets")
 			allPackets = append(allPackets, packets...)
+		} else {
+			log.WithFields(log.Fields{
+				"pcapPath": decompressedPath,
+			}).Info("No matching Suricata packets found")
 		}
 
 		if path != decompressedPath {
@@ -208,7 +215,7 @@ func (suri *SuriQuery) streamPacketsInPcaps(paths []string, filter *model.Filter
 		return a.Metadata().Timestamp.Compare(b.Metadata().Timestamp)
 	})
 
-	log.WithField("matchedCount", len(allPackets)).Debug("Finished filtering eligible packets")
+	log.WithField("matchedCount", len(allPackets)).Info("Finished filtering and sorting matching packets")
 
 	return packet.ToStream(allPackets)
 }
@@ -220,8 +227,8 @@ func (suri *SuriQuery) getPcapCreateTime(filepath string) (time.Time, error) {
 	if !strings.HasPrefix(filename, SURI_PCAP_PREFIX) {
 		err = errors.New("unsupported pcap file")
 	} else {
-		secondsStr := strings.TrimRight(filename, SURI_LZ4_SUFFIX)
-		secondsStr = strings.TrimLeft(secondsStr, SURI_PCAP_PREFIX)
+		secondsStr := strings.TrimSuffix(filename, SURI_LZ4_SUFFIX)
+		secondsStr = strings.TrimPrefix(secondsStr, SURI_PCAP_PREFIX)
 		var seconds int64
 		seconds, err = strconv.ParseInt(secondsStr, 10, 64)
 		if err == nil {
@@ -232,7 +239,7 @@ func (suri *SuriQuery) getPcapCreateTime(filepath string) (time.Time, error) {
 }
 
 func (suri *SuriQuery) findFilesInTimeRange(start time.Time, stop time.Time) []string {
-	eligibleFiles := make([]string, 0, 0)
+	eligibleFiles := make([]string, 0)
 	err := filepath.Walk(suri.pcapInputPath, func(filepath string, fileinfo os.FileInfo, err error) error {
 		if err != nil {
 			return nil
@@ -249,20 +256,27 @@ func (suri *SuriQuery) findFilesInTimeRange(start time.Time, stop time.Time) []s
 		}
 
 		modTime := fileinfo.ModTime()
-		log.WithFields(log.Fields{
-			"pcapPath":   filepath,
-			"createTime": createTime,
-			"modTime":    modTime,
-		}).Debug("Reviewing eligibility for PCAP file")
 
+		eligible := false
 		// file was created before the time range but has still open when time range started.
 		if (createTime.Before(start) && modTime.After(start)) ||
 			// file was created and finished in between time range start and stop times
 			(createTime.After(start) && createTime.Before(modTime) && modTime.Before(stop)) ||
 			// file was created before the end of the time range but was still being written to after the time range stop time
 			(createTime.Before(stop) && modTime.After(stop)) {
+
 			eligibleFiles = append(eligibleFiles, filepath)
+			eligible = true
 		}
+		log.WithFields(log.Fields{
+			"pcapPath":   filepath,
+			"createTime": createTime,
+			"modTime":    modTime,
+			"startTime":  start,
+			"stopTime":   stop,
+			"eligible":   eligible,
+		}).Debug("Checked eligibility of Suricata PCAP file")
+
 		return nil
 	})
 	if err != nil {