add Zerolog to context

api/errors/errors.go

@@ -5,7 +5,7 @@ import (
 	"net/http"
 
 	"github.com/gin-gonic/gin"
-	"github.com/rs/zerolog/log"
+	"github.com/rs/zerolog"
 )
 
 var (
@@ -52,9 +52,8 @@ func WrapError(err error, apiError *apiError) error {
 func HandleErrorJSON(c *gin.Context, err error) {
 	var apiErr APIError
 
-	log.Error().Msg(err.Error())
-
 	if !errors.As(err, &apiErr) {
+		zerolog.Ctx(c.Request.Context()).Error().Err(err).Msg(err.Error())
 		apiErr = ErrInternalServerError
 	}
 

go.mod

@@ -16,6 +16,7 @@ require (
 	github.com/go-swagger/go-swagger v0.30.5
 	github.com/golang-jwt/jwt/v4 v4.5.0
 	github.com/golang/mock v1.6.0
+	github.com/rs/xid v1.5.0
 	github.com/rs/zerolog v1.32.0
 	github.com/spf13/pflag v1.0.5
 	github.com/stretchr/testify v1.8.4

go.sum

@@ -149,6 +149,7 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/rogpeppe/go-internal v1.11.0 h1:cWPaGQEPrBb5/AsnsZesgZZ9yb1OQ+GOISoDNXVBh4M=
 github.com/rogpeppe/go-internal v1.11.0/go.mod h1:ddIwULY96R17DhadqLgMfk9H9tvdUzkipdSkR5nkCZA=
+github.com/rs/xid v1.5.0 h1:mKX4bl4iPYJtEIxp6CYiUuLQ/8DYMoz0PUdtGgMFRVc=
 github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
 github.com/rs/zerolog v1.32.0 h1:keLypqrlIjaFsbmJOBdB/qvyF8KEtCWHwobLp5l/mQ0=
 github.com/rs/zerolog v1.32.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=

main.go

@@ -36,8 +36,8 @@ func main() {
 	fs := initializeFlagSet()
 	port := fs.StringP("port", "p", defaultPort(), "Port where API will be served")
 
-	log.Debug().Msgf("Port: %s\n", *port)
-	log.Debug().Msgf("Cluster: %s\n", env.ClusterName)
+	log.Debug().Msgf("Port: %s", *port)
+	log.Debug().Msgf("Cluster: %s", env.ClusterName)
 
 	parseFlagsFromArgs(fs)
 
@@ -59,15 +59,15 @@ func main() {
 	go func() {
 		log.Info().Msgf("API is serving on port %s", *port)
 		if err := srv.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) {
-			log.Fatal().Msgf("listen: %s\n", err)
+			log.Fatal().Msgf("listen: %s", err)
 		}
 	}()
 
 	if env.UseProfiler {
 		go func() {
 			log.Info().Msgf("Profiler endpoint is serving on port 7070")
 			if err := http.ListenAndServe("localhost:7070", nil); err != nil && !errors.Is(err, http.ErrServerClosed) {
-				log.Fatal().Msgf("listen: %s\n", err)
+				log.Fatal().Msgf("listen: %s", err)
 			}
 		}()
 	}

router/server.go

@@ -8,10 +8,10 @@ import (
 
 	"github.com/equinor/radix-vulnerability-scanner-api/api"
 	"github.com/equinor/radix-vulnerability-scanner-api/swaggerui"
-	"github.com/gin-gonic/gin"
-
 	_ "github.com/equinor/radix-vulnerability-scanner-api/swaggerui" // statik files
 	"github.com/gin-contrib/cors"
+	"github.com/gin-gonic/gin"
+	"github.com/rs/zerolog/log"
 )
 
 const (
@@ -21,7 +21,10 @@ const (
 
 // NewServer Constructor function
 func NewServer(clusterName, apiRootPath string, tokenValidator TokenValidator, controllers ...api.Controller) http.Handler {
-	rootRouter := gin.Default()
+	logger := log.Logger.With().Str("pkg", "gin").Logger()
+	rootRouter := gin.New()
+	rootRouter.Use(gin.Recovery())
+	rootRouter.Use(NewZerologHandler(logger))
 
 	rootRouter.RemoveExtraSlash = true
 

router/zerolog_middleware.go

@@ -0,0 +1,48 @@
+package router
+
+import (
+	"net/http"
+	"time"
+
+	"github.com/gin-gonic/gin"
+	"github.com/rs/xid"
+	"github.com/rs/zerolog"
+)
+
+// Inspired by https://stackoverflow.com/a/50567022/2103434
+
+type loggingResponseWriter struct {
+	http.ResponseWriter
+	statusCode int
+}
+
+func newLoggingResponseWriter(w http.ResponseWriter) *loggingResponseWriter {
+	return &loggingResponseWriter{w, http.StatusOK}
+}
+func (lrw *loggingResponseWriter) WriteHeader(code int) {
+	lrw.statusCode = code
+	lrw.ResponseWriter.WriteHeader(code)
+}
+
+// NewZerologHandler injects and logs requests.
+func NewZerologHandler(log zerolog.Logger) gin.HandlerFunc {
+	return func(c *gin.Context) {
+		logger := log.With().Logger()
+		logger.UpdateContext(func(c zerolog.Context) zerolog.Context {
+			return c.Str("trace-id", xid.New().String())
+		})
+		start := time.Now()
+
+		c.Request = c.Request.WithContext(logger.WithContext(c.Request.Context()))
+		c.Next()
+
+		logger.Info().
+			Str("user-agent", c.GetHeader("User-Agent")).
+			Str("remote-addr", c.RemoteIP()).
+			Str("request", c.Request.Method+" "+c.Request.URL.Path).
+			Str("query", c.Request.URL.RawQuery).
+			Dur("elapsed-ms", time.Since(start)).
+			Int("status", c.Writer.Status()).
+			Msg(http.StatusText(c.Writer.Status()))
+	}
+}