From 044cd49220c682821d2526458d522d9b6cac9173 Mon Sep 17 00:00:00 2001 From: jantari Date: Mon, 10 Apr 2023 23:13:24 +0200 Subject: [PATCH 1/5] start implementing structured logging with zerolog --- controllers/packages.go | 23 ++++++++++----------- go.mod | 6 ++++-- go.sum | 22 +++++++++++++++++--- logging/logging.go | 45 +++++++++++++++++++++++++++++++++++++++++ main.go | 25 ++++++++++++++--------- manifests.go | 39 +++++++++++++++++------------------ 6 files changed, 113 insertions(+), 47 deletions(-) create mode 100644 logging/logging.go diff --git a/controllers/packages.go b/controllers/packages.go index 99695eb..25ffdf5 100644 --- a/controllers/packages.go +++ b/controllers/packages.go @@ -1,11 +1,11 @@ package controllers import ( - "fmt" "log" "github.com/gin-gonic/gin" + "rewinged/logging" "rewinged/models" ) @@ -14,13 +14,12 @@ func GetPackages(c *gin.Context) { Data: models.Manifests.GetAllPackageIdentifiers(), } - fmt.Println(response) + logging.Logger.Debug().Msgf("%v", response) c.JSON(200, response) } func GetPackage(c *gin.Context) { - fmt.Println("/packageManifests: Someone tried to GET package '", c.Param("package_identifier"), "'") - fmt.Println("with query params:", c.Request.URL.Query()) + logging.Logger.Debug().Msgf("/packageManifests: Someone tried to GET package '%v' with query params: %v", c.Param("package_identifier"), c.Request.URL.Query()) response := models.API_ManifestSingleResponse_1_1_0 { RequiredQueryParameters: []string{}, @@ -30,7 +29,7 @@ func GetPackage(c *gin.Context) { var pkg []models.API_ManifestVersionInterface = models.Manifests.GetAllVersions(c.Param("package_identifier")) if len(pkg) > 0 { - fmt.Println("the package was found!") + logging.Logger.Debug().Msgf("the package was found") response.Data = &models.API_Manifest_1_1_0{ PackageIdentifier: c.Param("package_identifier"), @@ -39,7 +38,7 @@ func GetPackage(c *gin.Context) { c.JSON(200, response) } else { - fmt.Println("the package was NOT found!") + logging.Logger.Debug().Msgf("the package was not found") c.JSON(404, models.API_WingetApiError{ ErrorCode: 404, ErrorMessage: "The specified package was not found.", @@ -50,7 +49,7 @@ func GetPackage(c *gin.Context) { func SearchForPackage(c *gin.Context) { var post models.API_ManifestSearchRequest_1_1_0 if err := c.BindJSON(&post); err == nil { - fmt.Printf("%+v\n", post) + logging.Logger.Debug().Msgf("%+v", post) response := &models.API_ManifestSearchResult[models.API_ManifestSearchVersion_1_1_0]{ RequiredPackageMatchFields: []string{}, Data: []models.API_ManifestSearchResponse[models.API_ManifestSearchVersion_1_1_0] {}, @@ -62,18 +61,18 @@ func SearchForPackage(c *gin.Context) { var results map[string][]models.API_ManifestVersionInterface if post.Query.KeyWord != "" { - fmt.Println("someone searched the repo for:", post.Query.KeyWord) + logging.Logger.Debug().Msgf("someone searched the repo for: %v", post.Query.KeyWord) results = models.Manifests.GetByKeyword(post.Query.KeyWord) } else if (post.Inclusions != nil && len(post.Inclusions) > 0) || (post.Filters != nil && len(post.Filters) > 0) { - fmt.Println("advanced search with inclusions[] and/or filters[]") + logging.Logger.Debug().Msg("advanced search with inclusions[] and/or filters[]") results = models.Manifests.GetByMatchFilter(post.Inclusions, post.Filters) } - fmt.Println("... with", len(results), "results:") + logging.Logger.Debug().Msgf("with %v results", len(results)) if len(results) > 0 { for packageId, packageVersions := range results { - fmt.Println(" package", packageId, "with", len(packageVersions), "versions.") + logging.Logger.Debug().Msgf("package %v with %v versions", packageId, len(packageVersions)) var versions []models.API_ManifestSearchVersion_1_1_0 for _, version := range packageVersions { @@ -92,7 +91,7 @@ func SearchForPackage(c *gin.Context) { Versions: versions, }) } - fmt.Printf("%+v\n", response) + logging.Logger.Debug().Msgf("%+v", response) c.JSON(200, response) } else { // winget REST-API specification calls for a 204 return code if no results were found diff --git a/go.mod b/go.mod index 2673ea9..c74ebbc 100644 --- a/go.mod +++ b/go.mod @@ -6,6 +6,7 @@ require ( github.com/gin-gonic/gin v1.7.7 github.com/peterbourgon/ff/v3 v3.3.0 github.com/rjeczalik/notify v0.9.2 + github.com/rs/zerolog v1.29.0 gopkg.in/yaml.v3 v3.0.1 ) @@ -17,11 +18,12 @@ require ( github.com/golang/protobuf v1.3.3 // indirect github.com/json-iterator/go v1.1.9 // indirect github.com/leodido/go-urn v1.2.0 // indirect - github.com/mattn/go-isatty v0.0.12 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect + github.com/mattn/go-isatty v0.0.18 // indirect github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421 // indirect github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742 // indirect github.com/ugorji/go/codec v1.1.7 // indirect golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9 // indirect - golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41 // indirect + golang.org/x/sys v0.7.0 // indirect gopkg.in/yaml.v2 v2.4.0 // indirect ) diff --git a/go.sum b/go.sum index b01a70f..3021e0d 100644 --- a/go.sum +++ b/go.sum @@ -1,3 +1,4 @@ +github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -13,6 +14,7 @@ github.com/go-playground/universal-translator v0.17.0 h1:icxd5fm+REJzpZx7ZfpaD87 github.com/go-playground/universal-translator v0.17.0/go.mod h1:UkSxE5sNxxRwHyU+Scu5vgOQjsIJAF8j9muTVoKLVtA= github.com/go-playground/validator/v10 v10.4.1 h1:pH2c5ADXtd66mxoE0Zm9SUhxE20r7aM3F26W0hOn+GE= github.com/go-playground/validator/v10 v10.4.1/go.mod h1:nlOn6nFhuKACm19sB/8EGNn9GlaMV7XkbRSipzJ0Ii4= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/golang/protobuf v1.3.3 h1:gyjaxf+svBWX08ZjK86iN9geUJF0H6gp2IRKX6Nf6/I= github.com/golang/protobuf v1.3.3/go.mod h1:vzj43D7+SQXF/4pzW/hwtAqwc6iTitCiVSaWz5lYuqw= github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= @@ -20,18 +22,28 @@ github.com/json-iterator/go v1.1.9 h1:9yzud/Ht36ygwatGx56VwCZtlI/2AD15T1X2sjSuGn github.com/json-iterator/go v1.1.9/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/uOdHXbAo4= github.com/leodido/go-urn v1.2.0 h1:hpXL4XnriNwQ/ABnpepYM/1vCLWNDfUNts8dX3xTG6Y= github.com/leodido/go-urn v1.2.0/go.mod h1:+8+nEpDfqqsY+g338gtMEUOtuK+4dEMhiQEgxpxOKII= -github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.18 h1:DOKFKCQ7FNG2L1rbrmstDN4QVRdS89Nkh85u68Uwp98= +github.com/mattn/go-isatty v0.0.18/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421 h1:ZqeYNhU3OHLH3mGKHDcjJRFFRrJa6eAM5H+CtDdOsPc= github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742 h1:Esafd1046DLDQ0W1YjYsBW+p8U2u7vzgW2SQVmlNazg= github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0= github.com/peterbourgon/ff/v3 v3.3.0 h1:PaKe7GW8orVFh8Unb5jNHS+JZBwWUMa2se0HM6/BI24= github.com/peterbourgon/ff/v3 v3.3.0/go.mod h1:zjJVUhx+twciwfDl0zBcFzl4dW8axCRyXE/eKY9RztQ= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rjeczalik/notify v0.9.2 h1:MiTWrPj55mNDHEiIX5YUSKefw/+lCQVoAFmD6oQm5w8= github.com/rjeczalik/notify v0.9.2/go.mod h1:aErll2f0sUX9PXZnVNyeiObbmTlk5jnMoCa4QEjJeqM= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.29.0 h1:Zes4hju04hjbvkVkOhdl2HpZa+0PmVwigmo8XoORE5w= +github.com/rs/zerolog v1.29.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0 h1:2E4SXV/wtOkTonXsotYi4li6zVWxYlZuYNCXe9XRJyk= @@ -47,8 +59,12 @@ golang.org/x/sys v0.0.0-20180926160741-c2ed4eda69e7/go.mod h1:STP8DvDyc/dI5b8T5h golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41 h1:ohgcoMbSofXygzo6AD2I1kz3BFmW1QArPYTtwEM3UXc= -golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.7.0 h1:3jlCCIQZPdOYu1h8BkNvLz8Kgwtae2cagcG/VamtZRU= +golang.org/x/sys v0.7.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= diff --git a/logging/logging.go b/logging/logging.go new file mode 100644 index 0000000..d2a7032 --- /dev/null +++ b/logging/logging.go @@ -0,0 +1,45 @@ +package logging + +import ( + "fmt" + + "os" + "time" + "strings" + + // Structured logging + "github.com/rs/zerolog" +) + +var Logger zerolog.Logger + +func InitLogger(level string, releaseMode bool) { + zerolog.TimeFieldFormat = time.RFC3339 + // Use colorful non-JSON log output during development builds + if releaseMode { + Logger = zerolog.New(os.Stderr).With().Timestamp().Logger() + } else { + Logger = zerolog.New( + zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: "15:04:05", FormatLevel: func(i interface{}) string { + return strings.ToUpper(fmt.Sprintf("%-5s", i)) + }}, + ).With().Timestamp().Logger() + } + + switch strings.ToLower(level) { + case "error": + zerolog.SetGlobalLevel(zerolog.ErrorLevel) + case "warn": + zerolog.SetGlobalLevel(zerolog.WarnLevel) + case "info": + zerolog.SetGlobalLevel(zerolog.InfoLevel) + case "debug": + zerolog.SetGlobalLevel(zerolog.DebugLevel) + case "trace": + zerolog.SetGlobalLevel(zerolog.TraceLevel) + case "disable": + zerolog.SetGlobalLevel(zerolog.Disabled) + default: + Logger.Fatal().Msgf("error parsing commandline arguments: invalid value \"%v\" for flag -logLevel: pass one of: disable, error, warn, info, debug, trace", level) + } +} diff --git a/main.go b/main.go index 9e5548d..3aa49b6 100644 --- a/main.go +++ b/main.go @@ -4,7 +4,6 @@ package main import ( "fmt" - "log" "os" "flag" "sync" @@ -12,11 +11,13 @@ import ( "strings" "path/filepath" + // Configuration "github.com/peterbourgon/ff/v3" "github.com/gin-gonic/gin" "github.com/rjeczalik/notify" // for live-reload of manifests + "rewinged/logging" "rewinged/models" "rewinged/controllers" ) @@ -40,6 +41,7 @@ func main() { tlsCertificatePtr = fs.String("httpsCertificateFile", "./cert.pem", "The webserver certificate to use if HTTPS is enabled") tlsPrivateKeyPtr = fs.String("httpsPrivateKeyFile", "./private.key", "The private key file to use if HTTPS is enabled") listenAddrPtr = fs.String("listen", "localhost:8080", "The address and port for the REST API to listen on") + logLevelPtr = fs.String("logLevel", "info", "Set log verbosity: disable, error, warn, info, debug or trace") _ = fs.String("configFile", "", "Path to a json configuration file (optional)") ) @@ -65,7 +67,9 @@ func main() { os.Exit(0) } - fmt.Println("Searching for manifests...") + logging.InitLogger(*logLevelPtr, releaseMode == "true") + + logging.Logger.Debug().Msg("searching for manifests") // Start up 10 worker goroutines that can parse in manifest-files from one directory each for w := 1; w <= 6; w++ { go ingestManifestsWorker() @@ -78,9 +82,9 @@ func main() { // if manifests is just a reference-copy of manifests2 then it wouldn't be I think? // But *currently* since live-reload isn't implemented yet, manifests2 won't be written // to after this point so it's safe for now - TODO: only access manifests2 in a thread-safe way - fmt.Println("Found", models.Manifests.GetManifestCount(), "package manifests.") + logging.Logger.Info().Msgf("found %v package manifests", models.Manifests.GetManifestCount()) - fmt.Println("Watching manifestPath for changes ...") + logging.Logger.Info().Msg("watching manifestPath for changes") // Make the channel buffered to try and not miss events. Notify will drop // an event if the receiver is not able to keep up the sending pace. fileEventsBuffer := 100 @@ -91,7 +95,7 @@ func main() { // correlate filenames to packages anyway so there's no way to know which // package is affected by the event. if err := notify.Watch(*packagePathPtr + "/...", fileEventsChannel, notify.Create, notify.Write); err != nil { - log.Fatal(err) + logging.Logger.Fatal().AnErr("string", err) } defer notify.Stop(fileEventsChannel) @@ -104,7 +108,8 @@ func main() { // period of time, thus necessitating further full rescans for len(fileEventsChannel) == fileEventsBuffer { // If the channel is ever full we are missing events as the notify package drops them at this point - log.Println("\x1b[31mfileEventsChannel full - we're missing events - will perform full manifest rescan\x1b[0m") + //log.Println("\x1b[31mfileEventsChannel full - we're missing events - will perform full manifest rescan\x1b[0m") + logging.Logger.Info().Msg("fileEventsChannel full - we're missing events - will perform full manifest rescan") // Wait out the thundering herd - events have been lost anyway time.Sleep(5 * time.Second) // Drop all events to clear the channel, this also enables new events to stream in again @@ -116,7 +121,7 @@ func main() { } ei := <- fileEventsChannel - log.Printf("Received event (type %T):\n\t%+v\n", ei, ei) + logging.Logger.Debug().Msgf("Received event (type %T):\n\t%+v\n", ei, ei) wg.Add(1) jobs <- filepath.Dir(ei.Path()) } @@ -132,14 +137,14 @@ func main() { router.POST("/manifestSearch", controllers.SearchForPackage) router.GET("/packageManifests/:package_identifier", controllers.GetPackage) - fmt.Println("Starting server on", *listenAddrPtr) + logging.Logger.Info().Msgf("starting server on %v", *listenAddrPtr) if *tlsEnablePtr { if err := router.RunTLS(*listenAddrPtr, *tlsCertificatePtr, *tlsPrivateKeyPtr); err != nil { - log.Fatal("error could not start webserver:", err) + logging.Logger.Fatal().Err(err).Msg("could not start webserver") } } else { if err := router.Run(*listenAddrPtr); err != nil { - log.Fatal("error could not start webserver:", err) + logging.Logger.Fatal().Err(err).Msg("could not start webserver") } } } diff --git a/manifests.go b/manifests.go index dc772c2..b516036 100644 --- a/manifests.go +++ b/manifests.go @@ -1,14 +1,13 @@ package main import ( - "fmt" - "log" "os" "errors" "strings" "gopkg.in/yaml.v3" + "rewinged/logging" "rewinged/models" ) @@ -16,7 +15,7 @@ func ingestManifestsWorker() error { for path := range jobs { files, err := os.ReadDir(path) if err != nil { - log.Println("ingestManifestsWorker error", err) + logging.Logger.Error().Err(err).Msg("ingestManifestsWorker error") wg.Done() continue } @@ -29,7 +28,7 @@ func ingestManifestsWorker() error { if caseInsensitiveHasSuffix(file.Name(), ".yml") || caseInsensitiveHasSuffix(file.Name(), ".yaml") { var basemanifest, err = parseFileAsBaseManifest(path + "/" + file.Name()) if err != nil { - log.Printf("error unmarshaling YAML file '%v' as BaseManifest: %v, SKIPPING\n", path + "/" + file.Name(), err) + logging.Logger.Error().Msgf("error unmarshaling YAML file '%v' as BaseManifest: %v, SKIPPING", path + "/" + file.Name(), err) continue } @@ -39,7 +38,7 @@ func ingestManifestsWorker() error { basemanifest.ManifestType != "" && basemanifest.ManifestVersion != "" { if basemanifest.ManifestType == "singleton" { var manifest = parseFileAsSingletonManifest(path + "/" + file.Name()) - fmt.Println(" Found singleton manifest for package", basemanifest.PackageIdentifier) + logging.Logger.Debug().Msgf("Found singleton manifest for package %v", basemanifest.PackageIdentifier) models.Manifests.Set(manifest.GetPackageIdentifier(), basemanifest.PackageVersion, manifest.GetVersions()[0]) } else { typeAndPath := models.ManifestTypeAndPath{ @@ -55,10 +54,10 @@ func ingestManifestsWorker() error { if len(nonSingletonsMap) > 0 { for key, value := range nonSingletonsMap { - fmt.Println(" Found multi-file manifests for package", key.PackageIdentifier) + logging.Logger.Debug().Msgf("found multi-file manifests for package %v", key.PackageIdentifier) var mergedManifest, err = parseMultiFileManifest(key, value...) if err != nil { - log.Println("Could not parse the manifest files for this package", key.PackageIdentifier, err) + logging.Logger.Error().AnErr("error", err).Msgf("Could not parse the manifest files for this package %v", key.PackageIdentifier) } else { for _, version := range mergedManifest.GetVersions() { // Replace the existing PkgId + PkgVersion entry with this one @@ -80,7 +79,7 @@ func ingestManifestsWorker() error { func getManifests (path string) { files, err := os.ReadDir(path) if err != nil { - log.Println(err) + logging.Logger.Error().AnErr("error", err) } // wg.Add() before goroutine, see staticcheck check SA2000 and also @@ -92,7 +91,7 @@ func getManifests (path string) { for _, file := range files { if file.IsDir() { - fmt.Printf("Searching directory: %s\n", path + "/" + file.Name()) + logging.Logger.Trace().Msgf("searching directory %s", path + "/" + file.Name()) getManifests(path + "/" + file.Name()) } @@ -112,7 +111,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . for _, file := range files { yamlFile, err := os.ReadFile(file.FilePath) if err != nil { - log.Printf("yamlFile.Get err #%v ", err) + logging.Logger.Error().Err(err).Msg("yamlFile.Get err") continue } switch file.ManifestType { @@ -125,12 +124,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { version = &models.Manifest_VersionManifest_1_4_0{} } else { - log.Println("Unsupported VersionManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Msgf("Unsupported VersionManifest version %v %v", multifilemanifest.ManifestVersion, file) continue } err = yaml.Unmarshal(yamlFile, version) if err != nil { - log.Printf("error unmarshalling version-manifest %v\n", err) + logging.Logger.Error().Err(err).Msg("error unmarshalling version-manifest") } versions = append(versions, version) case "installer": @@ -142,12 +141,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { installer = &models.Manifest_InstallerManifest_1_4_0{} } else { - log.Println("Unsupported InstallerManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Msgf("Unsupported InstallerManifest version %v %v", multifilemanifest.ManifestVersion, file) continue } err = yaml.Unmarshal(yamlFile, installer) if err != nil { - log.Printf("error unmarshalling installer-manifest %v\n", err) + logging.Logger.Error().Err(err).Msg("error unmarshalling installer-manifest") } installers = append(installers, installer) case "locale": @@ -159,12 +158,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { locale = &models.Manifest_LocaleManifest_1_4_0{} } else { - log.Println("Unsupported LocaleManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Msgf("Unsupported LocaleManifest version", multifilemanifest.ManifestVersion, file) continue } err = yaml.Unmarshal(yamlFile, locale) if err != nil { - log.Printf("error unmarshalling locale-manifest %v\n", err) + logging.Logger.Error().Err(err).Msg("error unmarshalling locale-manifest") } locales = append(locales, locale) case "defaultLocale": @@ -175,12 +174,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { defaultlocale = &models.Manifest_DefaultLocaleManifest_1_4_0{} } else { - log.Println("Unsupported DefaultLocaleManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Msgf("Unsupported DefaultLocaleManifest version", multifilemanifest.ManifestVersion, file) continue } err = yaml.Unmarshal(yamlFile, defaultlocale) if err != nil { - log.Printf("error unmarshalling defaultlocale-manifest %v\n", err) + logging.Logger.Error().Err(err).Msg("error unmarshalling defaultlocale-manifest") } default: } @@ -299,13 +298,13 @@ func parseFileAsBaseManifest (path string) (*models.BaseManifest, error) { func parseFileAsSingletonManifest (path string) models.API_ManifestInterface { yamlFile, err := os.ReadFile(path) if err != nil { - log.Printf("error opening yaml file %v\n", err) + logging.Logger.Error().Err(err).Msg("error opening yaml file") } singleton := &models.Manifest_SingletonManifest_1_1_0{} err = yaml.Unmarshal(yamlFile, singleton) if err != nil { - log.Printf("error unmarshalling singleton %v\n", err) + logging.Logger.Error().Err(err).Msg("error unmarshalling singleton") } manifest := singletonToStandardManifest(singleton) From ef24bcee558407b4a885bf152c47ecaffc57662f Mon Sep 17 00:00:00 2001 From: jantari Date: Fri, 14 Apr 2023 00:39:44 +0200 Subject: [PATCH 2/5] moved all remaining log, fmt and gin output to zerolog json --- controllers/packages.go | 4 +--- logging/logging.go | 44 +++++++++++++++++++++++++++++++++++++++++ main.go | 4 +++- models/internal.go | 5 +++-- 4 files changed, 51 insertions(+), 6 deletions(-) diff --git a/controllers/packages.go b/controllers/packages.go index 25ffdf5..86dc2cb 100644 --- a/controllers/packages.go +++ b/controllers/packages.go @@ -1,8 +1,6 @@ package controllers import ( - "log" - "github.com/gin-gonic/gin" "rewinged/logging" @@ -98,7 +96,7 @@ func SearchForPackage(c *gin.Context) { c.JSON(204, response) } } else { - log.Println("error deserializing json post body %v\n", err) + logging.Logger.Error().Err(err).Msg("error deserializing json post body") } } diff --git a/logging/logging.go b/logging/logging.go index d2a7032..398de15 100644 --- a/logging/logging.go +++ b/logging/logging.go @@ -9,6 +9,7 @@ import ( // Structured logging "github.com/rs/zerolog" + "github.com/gin-gonic/gin" ) var Logger zerolog.Logger @@ -43,3 +44,46 @@ func InitLogger(level string, releaseMode bool) { Logger.Fatal().Msgf("error parsing commandline arguments: invalid value \"%v\" for flag -logLevel: pass one of: disable, error, warn, info, debug, trace", level) } } + +// https://learninggolang.com/it5-gin-structured-logging.html +func GinLogger() gin.HandlerFunc { + return func(c *gin.Context) { + path := c.Request.URL.Path + raw := c.Request.URL.RawQuery + + // Process request + c.Next() + + // Fill the params + param := gin.LogFormatterParams{} + + param.TimeStamp = time.Now() // Stop timer + + param.ClientIP = c.ClientIP() + param.Method = c.Request.Method + param.StatusCode = c.Writer.Status() + param.ErrorMessage = c.Errors.ByType(gin.ErrorTypePrivate).String() + //param.Latency = duration + param.BodySize = c.Writer.Size() + if raw != "" { + path = path + "?" + raw + } + param.Path = path + + // Log using the params + var logEvent *zerolog.Event + if c.Writer.Status() >= 500 { + logEvent = Logger.Error() + } else { + logEvent = Logger.Info() + } + + logEvent.Str("client_id", param.ClientIP). + Str("method", param.Method). + Int("status_code", param.StatusCode). + Int("body_size", param.BodySize). + Str("path", param.Path). + //Str("latency", param.Latency.String()). + Msg(param.ErrorMessage) + } +} diff --git a/main.go b/main.go index 3aa49b6..3378527 100644 --- a/main.go +++ b/main.go @@ -130,8 +130,10 @@ func main() { if releaseMode == "true" { gin.SetMode(gin.ReleaseMode) } - router := gin.Default() + router := gin.New() router.SetTrustedProxies(nil) + router.Use(logging.GinLogger()) + router.Use(gin.Recovery()) router.GET("/information", controllers.GetInformation) router.GET("/packages", controllers.GetPackages) router.POST("/manifestSearch", controllers.SearchForPackage) diff --git a/models/internal.go b/models/internal.go index ab4d929..6213850 100644 --- a/models/internal.go +++ b/models/internal.go @@ -1,10 +1,11 @@ package models import ( - "fmt" "sync" "strings" "reflect" + + "rewinged/logging" ) // This is used when discovering manifest @@ -310,7 +311,7 @@ func (ms *ManifestsStore) GetByMatchFilter ( // All filters and inclusions have passed for this manifest, add it to the returned map if anyInclusionMatched { - fmt.Println("Adding to the results map:", packageIdentifier, "version", packageVersion.GetPackageVersion()) + logging.Logger.Debug().Msgf("adding to the results map: %v version %v", packageIdentifier, packageVersion.GetPackageVersion()) manifestResultsMap[packageIdentifier] = append(manifestResultsMap[packageIdentifier], packageVersion) } } From 117100242fffcbb19d03b227bc686262b65d1067 Mon Sep 17 00:00:00 2001 From: jantari Date: Mon, 8 May 2023 21:42:34 +0200 Subject: [PATCH 3/5] use Err() over AnErr() when adding error fields to logs --- main.go | 2 +- manifests.go | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/main.go b/main.go index 3378527..268fb90 100644 --- a/main.go +++ b/main.go @@ -95,7 +95,7 @@ func main() { // correlate filenames to packages anyway so there's no way to know which // package is affected by the event. if err := notify.Watch(*packagePathPtr + "/...", fileEventsChannel, notify.Create, notify.Write); err != nil { - logging.Logger.Fatal().AnErr("string", err) + logging.Logger.Fatal().Err(err) } defer notify.Stop(fileEventsChannel) diff --git a/manifests.go b/manifests.go index b516036..a913352 100644 --- a/manifests.go +++ b/manifests.go @@ -57,7 +57,7 @@ func ingestManifestsWorker() error { logging.Logger.Debug().Msgf("found multi-file manifests for package %v", key.PackageIdentifier) var mergedManifest, err = parseMultiFileManifest(key, value...) if err != nil { - logging.Logger.Error().AnErr("error", err).Msgf("Could not parse the manifest files for this package %v", key.PackageIdentifier) + logging.Logger.Error().Err(err).Msgf("Could not parse the manifest files for this package %v", key.PackageIdentifier) } else { for _, version := range mergedManifest.GetVersions() { // Replace the existing PkgId + PkgVersion entry with this one @@ -79,7 +79,7 @@ func ingestManifestsWorker() error { func getManifests (path string) { files, err := os.ReadDir(path) if err != nil { - logging.Logger.Error().AnErr("error", err) + logging.Logger.Error().Err(err) } // wg.Add() before goroutine, see staticcheck check SA2000 and also From ea163aebe601450072ff7bc6d1c059a71cf93e66 Mon Sep 17 00:00:00 2001 From: jantari Date: Mon, 15 May 2023 03:30:55 +0200 Subject: [PATCH 4/5] improve logs from manifest file ingest --- manifests.go | 24 ++++++++++++------------ 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/manifests.go b/manifests.go index a913352..e4b9c5f 100644 --- a/manifests.go +++ b/manifests.go @@ -28,7 +28,7 @@ func ingestManifestsWorker() error { if caseInsensitiveHasSuffix(file.Name(), ".yml") || caseInsensitiveHasSuffix(file.Name(), ".yaml") { var basemanifest, err = parseFileAsBaseManifest(path + "/" + file.Name()) if err != nil { - logging.Logger.Error().Msgf("error unmarshaling YAML file '%v' as BaseManifest: %v, SKIPPING", path + "/" + file.Name(), err) + logging.Logger.Error().Err(err).Str("file", path + "/" + file.Name()).Msgf("cannot unmarshal YAML file as BaseManifest") continue } @@ -54,10 +54,10 @@ func ingestManifestsWorker() error { if len(nonSingletonsMap) > 0 { for key, value := range nonSingletonsMap { - logging.Logger.Debug().Msgf("found multi-file manifests for package %v", key.PackageIdentifier) + logging.Logger.Debug().Str("package", key.PackageIdentifier).Msgf("found multi-file manifests") var mergedManifest, err = parseMultiFileManifest(key, value...) if err != nil { - logging.Logger.Error().Err(err).Msgf("Could not parse the manifest files for this package %v", key.PackageIdentifier) + logging.Logger.Error().Err(err).Str("package", key.PackageIdentifier).Msgf("Could not parse all manifest files for this package") } else { for _, version := range mergedManifest.GetVersions() { // Replace the existing PkgId + PkgVersion entry with this one @@ -111,7 +111,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . for _, file := range files { yamlFile, err := os.ReadFile(file.FilePath) if err != nil { - logging.Logger.Error().Err(err).Msg("yamlFile.Get err") + logging.Logger.Error().Str("file", file.FilePath).Err(err).Msg("cannot read file") continue } switch file.ManifestType { @@ -124,12 +124,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { version = &models.Manifest_VersionManifest_1_4_0{} } else { - logging.Logger.Error().Msgf("Unsupported VersionManifest version %v %v", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported VersionManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, version) if err != nil { - logging.Logger.Error().Err(err).Msg("error unmarshalling version-manifest") + logging.Logger.Error().Err(err).Msg("cannot unmarshal version-manifest") } versions = append(versions, version) case "installer": @@ -141,12 +141,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { installer = &models.Manifest_InstallerManifest_1_4_0{} } else { - logging.Logger.Error().Msgf("Unsupported InstallerManifest version %v %v", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported InstallerManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, installer) if err != nil { - logging.Logger.Error().Err(err).Msg("error unmarshalling installer-manifest") + logging.Logger.Error().Err(err).Msg("cannot unmarshal installer-manifest") } installers = append(installers, installer) case "locale": @@ -158,12 +158,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { locale = &models.Manifest_LocaleManifest_1_4_0{} } else { - logging.Logger.Error().Msgf("Unsupported LocaleManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported LocaleManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, locale) if err != nil { - logging.Logger.Error().Err(err).Msg("error unmarshalling locale-manifest") + logging.Logger.Error().Err(err).Msg("cannot unmarshal locale-manifest") } locales = append(locales, locale) case "defaultLocale": @@ -174,12 +174,12 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { defaultlocale = &models.Manifest_DefaultLocaleManifest_1_4_0{} } else { - logging.Logger.Error().Msgf("Unsupported DefaultLocaleManifest version", multifilemanifest.ManifestVersion, file) + logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported DefaultLocaleManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, defaultlocale) if err != nil { - logging.Logger.Error().Err(err).Msg("error unmarshalling defaultlocale-manifest") + logging.Logger.Error().Err(err).Msg("cannot unmarshal defaultlocale-manifest") } default: } From f2852e7948494b8bfd10babecd2f3044c8cb6140 Mon Sep 17 00:00:00 2001 From: jantari Date: Mon, 15 May 2023 16:13:16 +0200 Subject: [PATCH 5/5] start all log messages in lowercase, add some log fields --- main.go | 2 +- manifests.go | 18 +++++++++--------- 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/main.go b/main.go index 268fb90..9d92bcf 100644 --- a/main.go +++ b/main.go @@ -121,7 +121,7 @@ func main() { } ei := <- fileEventsChannel - logging.Logger.Debug().Msgf("Received event (type %T):\n\t%+v\n", ei, ei) + logging.Logger.Debug().Msgf("received event (type %T):\n\t%+v\n", ei, ei) wg.Add(1) jobs <- filepath.Dir(ei.Path()) } diff --git a/manifests.go b/manifests.go index e4b9c5f..b958bd5 100644 --- a/manifests.go +++ b/manifests.go @@ -38,7 +38,7 @@ func ingestManifestsWorker() error { basemanifest.ManifestType != "" && basemanifest.ManifestVersion != "" { if basemanifest.ManifestType == "singleton" { var manifest = parseFileAsSingletonManifest(path + "/" + file.Name()) - logging.Logger.Debug().Msgf("Found singleton manifest for package %v", basemanifest.PackageIdentifier) + logging.Logger.Debug().Str("package", basemanifest.PackageIdentifier).Str("packageversion", basemanifest.PackageVersion).Msgf("found singleton manifest") models.Manifests.Set(manifest.GetPackageIdentifier(), basemanifest.PackageVersion, manifest.GetVersions()[0]) } else { typeAndPath := models.ManifestTypeAndPath{ @@ -54,10 +54,10 @@ func ingestManifestsWorker() error { if len(nonSingletonsMap) > 0 { for key, value := range nonSingletonsMap { - logging.Logger.Debug().Str("package", key.PackageIdentifier).Msgf("found multi-file manifests") + logging.Logger.Debug().Str("package", key.PackageIdentifier).Str("packageversion", key.PackageVersion).Msgf("found multi-file manifest") var mergedManifest, err = parseMultiFileManifest(key, value...) if err != nil { - logging.Logger.Error().Err(err).Str("package", key.PackageIdentifier).Msgf("Could not parse all manifest files for this package") + logging.Logger.Error().Err(err).Str("package", key.PackageIdentifier).Str("packageversion", key.PackageVersion).Msgf("could not parse all manifest files for this package") } else { for _, version := range mergedManifest.GetVersions() { // Replace the existing PkgId + PkgVersion entry with this one @@ -124,7 +124,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { version = &models.Manifest_VersionManifest_1_4_0{} } else { - logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported VersionManifest version %v", multifilemanifest.ManifestVersion) + logging.Logger.Error().Str("file", file.FilePath).Msgf("unsupported VersionManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, version) @@ -141,7 +141,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { installer = &models.Manifest_InstallerManifest_1_4_0{} } else { - logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported InstallerManifest version %v", multifilemanifest.ManifestVersion) + logging.Logger.Error().Str("file", file.FilePath).Msgf("unsupported InstallerManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, installer) @@ -158,7 +158,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { locale = &models.Manifest_LocaleManifest_1_4_0{} } else { - logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported LocaleManifest version %v", multifilemanifest.ManifestVersion) + logging.Logger.Error().Str("file", file.FilePath).Msgf("unsupported LocaleManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, locale) @@ -174,7 +174,7 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . } else if multifilemanifest.ManifestVersion == "1.4.0" { defaultlocale = &models.Manifest_DefaultLocaleManifest_1_4_0{} } else { - logging.Logger.Error().Str("file", file.FilePath).Msgf("Unsupported DefaultLocaleManifest version %v", multifilemanifest.ManifestVersion) + logging.Logger.Error().Str("file", file.FilePath).Msgf("unsupported DefaultLocaleManifest version %v", multifilemanifest.ManifestVersion) continue } err = yaml.Unmarshal(yamlFile, defaultlocale) @@ -187,10 +187,10 @@ func parseMultiFileManifest (multifilemanifest models.MultiFileManifest, files . // It's possible there were no installer or locale manifests or parsing them failed if len(installers) == 0 { - return nil, errors.New(multifilemanifest.PackageVersion + " package manifests did not contain any (valid) installers") + return nil, errors.New("no (valid) installer manifest") } if len(versions) == 0 { - return nil, errors.New("package manifests did not contain any (valid) locales") + return nil, errors.New("no (valid) locale manifest") } // This transforms the manifest data into the format the API will return.