Introduce structured logging

Dockerfile

@@ -1,5 +1,5 @@
 # Build the manager binary
-FROM golang:1.20.8-alpine3.18 as builder
+FROM golang:1.21.4-alpine3.18 as builder
 
 COPY . /go/src/github.com/uselagoon/lagoon/services/insights-handler/
 WORKDIR /go/src/github.com/uselagoon/lagoon/services/insights-handler/

Makefile

@@ -5,6 +5,6 @@ gettrivy:
 
 .PHONY: runlocal
 runlocal:
-	go run main.go --problems-from-sbom=true --rabbitmq-username=guest  --rabbitmq-password=guest --lagoon-api-host=http://localhost:8888/graphql   --jwt-token-signing-key=secret   --access-key-id=minio     --secret-access-key=minio123 --disable-s3-upload=true
+	go run main.go --problems-from-sbom=true --rabbitmq-username=guest  --rabbitmq-password=guest --lagoon-api-host=http://localhost:8888/graphql   --jwt-token-signing-key=secret   --access-key-id=minio     --secret-access-key=minio123 --disable-s3-upload=true --debug=true
 
 

go.mod

@@ -1,6 +1,6 @@
 module github.com/uselagoon/lagoon/services/insights-handler
 
-go 1.18
+go 1.21
 
 require (
 	github.com/Khan/genqlient v0.3.0

internal/handler/imageInspectParserFilter.go

@@ -3,7 +3,7 @@ package handler
 import (
 	"encoding/json"
 	"fmt"
-	"log"
+	"log/slog"
 	"strings"
 
 	"github.com/Khan/genqlient/graphql"
@@ -24,19 +24,19 @@ type ImageData struct {
 }
 
 func processImageInspectInsightsData(h *Messaging, insights InsightsData, v string, apiClient graphql.Client, resource ResourceDestination) ([]LagoonFact, string, error) {
+	source := fmt.Sprintf("insights:image:%s", resource.Service)
+	logger := slog.With("Project", resource.Project, "Environment", resource.Environment, "Source", source)
 	if insights.InsightsType == Image {
 		decoded, err := decodeGzipString(v)
 		if err != nil {
-			fmt.Errorf(err.Error())
+			return nil, "", err
 		}
 
 		_, environment, apiErr := determineResourceFromLagoonAPI(apiClient, resource)
 		if apiErr != nil {
 			return nil, "", apiErr
 		}
 
-		source := fmt.Sprintf("insights:image:%s", resource.Service)
-
 		marshallDecoded, err := json.Marshal(decoded)
 		var imageInspect ImageData
 
@@ -45,12 +45,11 @@ func processImageInspectInsightsData(h *Messaging, insights InsightsData, v stri
 			return nil, "", err
 		}
 
-		facts, err := processFactsFromImageInspect(imageInspect, environment.Id, source)
+		facts, err := processFactsFromImageInspect(logger, imageInspect, environment.Id, source)
 		if err != nil {
 			return nil, "", err
 		}
-		log.Printf("Successfully decoded image-inspect, for '%s:%s', from '%s'", resource.Project, resource.Environment, source)
-
+		logger.Info("Successfully decoded image-inspect")
 		facts, err = KeyFactsFilter(facts)
 		if err != nil {
 			return nil, "", err
@@ -61,7 +60,8 @@ func processImageInspectInsightsData(h *Messaging, insights InsightsData, v stri
 	return []LagoonFact{}, "", nil
 }
 
-func processFactsFromImageInspect(imageInspectData ImageData, id int, source string) ([]LagoonFact, error) {
+func processFactsFromImageInspect(logger *slog.Logger, imageInspectData ImageData, id int, source string) ([]LagoonFact, error) {
+
 	var factsInput []LagoonFact
 
 	var filteredFacts []EnvironmentVariable
@@ -95,9 +95,9 @@ func processFactsFromImageInspect(imageInspectData ImageData, id int, source str
 			KeyFact:     false,
 			Type:        FactTypeText,
 		}
-		if EnableDebug {
-			log.Println("[DEBUG] processing fact name " + f.Key)
-		}
+
+		logger.Debug("Processing fact", "name", f.Key, "value", f.Value)
+
 		fact, _ = ProcessLagoonFactAgainstRegisteredFilters(fact, f)
 		factsInput = append(factsInput, fact)
 	}

internal/handler/insightsFactsParserFilter.go

@@ -4,7 +4,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"io/ioutil"
-	"log"
+	"log/slog"
 	"strings"
 
 	"github.com/Khan/genqlient/graphql"
@@ -16,19 +16,19 @@ type FactsPayload struct {
 
 // Processes facts from insights payloads that come from reconcilled kubernetes payloads (e.g. include labels/annotations and compressed/encoded data)
 func processFactsInsightsData(h *Messaging, insights InsightsData, v string, apiClient graphql.Client, resource ResourceDestination) ([]LagoonFact, string, error) {
+	source := fmt.Sprintf("insights:facts:%s", resource.Service)
+	logger := slog.With("Project", resource.Project, "Environment", resource.Environment, "Source", source)
 	if insights.LagoonType == Facts && insights.InsightsType == Raw {
 		r := strings.NewReader(v)
 
 		// Decode base64
 		//dec := base64.NewDecoder(base64.StdEncoding, r)
 		res, err := ioutil.ReadAll(r)
 		if err != nil {
-			fmt.Println("err: ", err)
+			slog.Error("Error reading insights data", "Error", err)
 		}
 
-		source := fmt.Sprintf("insights:facts:%s", resource.Service)
-
-		facts := processFactsFromJSON(res, source)
+		facts := processFactsFromJSON(logger, res, source)
 		facts, err = KeyFactsFilter(facts)
 		if err != nil {
 			return nil, "", err
@@ -38,20 +38,21 @@ func processFactsInsightsData(h *Messaging, insights InsightsData, v string, api
 			return nil, "", fmt.Errorf("no facts to process")
 		}
 
-		log.Printf("Successfully processed %d fact(s), for '%s:%s', from source '%s'", len(facts), resource.Project, resource.Environment, source)
+		//log.Printf("Successfully processed %d fact(s), for '%s:%s', from source '%s'", len(facts), resource.Project, resource.Environment, source)
+		logger.Info("Successfully processed facts", "number", len(facts))
 
 		return facts, source, nil
 	}
 	return nil, "", nil
 }
 
-func processFactsFromJSON(facts []byte, source string) []LagoonFact {
+func processFactsFromJSON(logger *slog.Logger, facts []byte, source string) []LagoonFact {
 	var factsInput []LagoonFact
 
 	var factsPayload FactsPayload
 	err := json.Unmarshal(facts, &factsPayload)
 	if err != nil {
-		fmt.Println(err.Error())
+		logger.Error(err.Error())
 		panic("Can't unmarshal facts")
 	}
 
@@ -80,9 +81,7 @@ func processFactsFromJSON(facts []byte, source string) []LagoonFact {
 			KeyFact:     f.KeyFact,
 			Type:        FactTypeText,
 		}
-		if EnableDebug {
-			log.Println("[DEBUG] processing fact name " + f.Name)
-		}
+		logger.Debug("Processing fact", "name", f.Name, "value", f.Value)
 		fact, _ = ProcessLagoonFactAgainstRegisteredFilters(fact, f)
 		factsInput = append(factsInput, fact)
 	}

internal/handler/insightsParserFilter.go

@@ -6,7 +6,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"io/ioutil"
-	"log"
+	"log/slog"
 	"net/http"
 	"strings"
 
@@ -15,6 +15,10 @@ import (
 )
 
 func processSbomInsightsData(h *Messaging, insights InsightsData, v string, apiClient graphql.Client, resource ResourceDestination) ([]LagoonFact, string, error) {
+
+	source := fmt.Sprintf("insights:sbom:%s", resource.Service)
+	logger := slog.With("Project", resource.Project, "Environment", resource.Environment, "Source", source)
+
 	if insights.InsightsType != Sbom {
 		return []LagoonFact{}, "", nil
 	}
@@ -59,7 +63,6 @@ func processSbomInsightsData(h *Messaging, insights InsightsData, v string, apiC
 	if apiErr != nil {
 		return nil, "", apiErr
 	}
-	source := fmt.Sprintf("insights:sbom:%s", resource.Service)
 
 	// we process the SBOM here
 
@@ -68,7 +71,7 @@ func processSbomInsightsData(h *Messaging, insights InsightsData, v string, apiC
 		if err != nil {
 			return nil, "", fmt.Errorf("trivy server not alive: %v", err.Error())
 		} else {
-			fmt.Println("trivy is alive")
+			logger.Debug("Trivy is reachable")
 		}
 		if isAlive {
 			err = SbomToProblems(apiClient, h.TrivyServerEndpoint, "/tmp/", environment.Id, resource.Service, *bom)
@@ -79,7 +82,7 @@ func processSbomInsightsData(h *Messaging, insights InsightsData, v string, apiC
 	}
 
 	// Process SBOM into facts
-	facts := processFactsFromSBOM(bom.Components, environment.Id, source)
+	facts := processFactsFromSBOM(logger, bom.Components, environment.Id, source)
 
 	facts, err = KeyFactsFilter(facts)
 	if err != nil {
@@ -90,12 +93,17 @@ func processSbomInsightsData(h *Messaging, insights InsightsData, v string, apiC
 		return nil, "", fmt.Errorf("no facts to process")
 	}
 
-	log.Printf("Successfully decoded SBOM of image %s with %s, found %d for '%s:%s'", bom.Metadata.Component.Name, (*bom.Metadata.Tools)[0].Name, len(*bom.Components), resource.Project, resource.Environment)
+	//log.Printf("Successfully decoded SBOM of image %s with %s, found %d for '%s:%s'", bom.Metadata.Component.Name, (*bom.Metadata.Tools)[0].Name, len(*bom.Components), resource.Project, resource.Environment)
+	logger.Info("Successfully decoded SBOM",
+		"image", bom.Metadata.Component.Name,
+		"fieldName", (*bom.Metadata.Tools)[0].Name,
+		"Length", len(*bom.Components),
+	)
 
 	return facts, source, nil
 }
 
-func processFactsFromSBOM(facts *[]cdx.Component, environmentId int, source string) []LagoonFact {
+func processFactsFromSBOM(logger *slog.Logger, facts *[]cdx.Component, environmentId int, source string) []LagoonFact {
 	var factsInput []LagoonFact
 	if len(*facts) == 0 {
 		return factsInput
@@ -122,9 +130,13 @@ func processFactsFromSBOM(facts *[]cdx.Component, environmentId int, source stri
 			KeyFact:     false,
 			Type:        FactTypeText,
 		}
-		if EnableDebug {
-			log.Println("[DEBUG] processing fact name " + f.Name)
-		}
+		//if EnableDebug {
+		//	log.Println("[DEBUG] processing fact name " + f.Name)
+		//}
+		logger.Debug("Processing fact",
+			"Name", f.Name,
+			"Value", f.Version,
+		)
 		fact, _ = ProcessLagoonFactAgainstRegisteredFilters(fact, f)
 		factsInput = append(factsInput, fact)
 	}