refactor logger (#9)

* refactor logger

config/config.go

@@ -3,7 +3,7 @@ package config
 import (
 	"fmt"
 
-	log "github.com/sirupsen/logrus"
+	log "github.com/huweihuang/golib/logger/zap"
 	"github.com/spf13/viper"
 )
 
@@ -65,7 +65,7 @@ func InitConfigObjectByPath(configPath string, configObject interface{}) error {
 		if err != nil {
 			return fmt.Errorf("failed to unmarshal, err: %v", err)
 		}
-		log.WithField("config", configObject).Debug("init config")
+		log.Logger().With("config", configObject).Debug("init config")
 	}
 	return nil
 }

gin/middlewares/logger.go

@@ -3,52 +3,69 @@ package middlerwares
 import (
 	"time"
 
-	log "github.com/huweihuang/golib/logger/logrus"
-
 	"github.com/gin-gonic/gin"
 	"github.com/sirupsen/logrus"
+	"go.uber.org/zap"
+
+	log "github.com/huweihuang/golib/logger/zap"
 )
 
 func Logger() gin.HandlerFunc {
-	return LogMiddleware(log.Log())
+	return ZapMiddleware(log.Logger())
 }
 
-func LogMiddleware(logger *logrus.Logger) gin.HandlerFunc {
+func ZapMiddleware(logger *zap.SugaredLogger) gin.HandlerFunc {
 	return func(c *gin.Context) {
-		// Start timer
-		start := time.Now()
-		path := c.Request.URL.Path
-		query := c.Request.URL.RawQuery
-
-		// Process request
-		c.Next()
-
-		// Stop timer
-		end := time.Now()
-		latency := end.Sub(start)
-
-		statusCode := c.Writer.Status()
-
-		fields := logrus.Fields{
-			"path":    path,
-			"query":   query,
-			"latency": formatLatency(latency),
-			"ip":      c.ClientIP(),
-			"method":  c.Request.Method,
-			"code":    statusCode,
-			"req_id":  c.GetString("req_id"),
+		httpFields, statusCode := GetHttpFields(c)
+
+		if statusCode >= 500 {
+			logger.With(httpFields).Error()
+		} else if statusCode >= 400 {
+			logger.With(httpFields).Warn()
+		} else {
+			logger.With(httpFields).Info()
 		}
+	}
+}
+
+func LogrusMiddleware(logger *logrus.Logger) gin.HandlerFunc {
+	return func(c *gin.Context) {
+		httpFields, statusCode := GetHttpFields(c)
 
 		if statusCode >= 500 {
-			logger.WithFields(fields).Error()
+			logger.WithFields(httpFields).Error()
 		} else if statusCode >= 400 {
-			logger.WithFields(fields).Warn()
+			logger.WithFields(httpFields).Warn()
 		} else {
-			logger.WithFields(fields).Info()
+			logger.WithFields(httpFields).Info()
 		}
 	}
 }
 
+func GetHttpFields(c *gin.Context) (httpFields map[string]interface{}, status int) {
+	// Start timer
+	start := time.Now()
+	// Process request
+	c.Next()
+	// Stop timer
+	end := time.Now()
+	latency := end.Sub(start)
+
+	statusCode := c.Writer.Status()
+
+	httpFields = map[string]interface{}{
+		"path":        c.Request.URL.Path,
+		"query":       c.Request.URL.RawQuery,
+		"latency":     formatLatency(latency),
+		"ip":          c.ClientIP(),
+		"method":      c.Request.Method,
+		"status_code": statusCode,
+		"req_id":      c.GetString("req_id"),
+	}
+
+	return httpFields, statusCode
+}
+
 // formatLatency convert to milliseconds
 func formatLatency(latency time.Duration) int {
 	return int(latency.Seconds() * 1000)

gin/middlewares/middleware.go

@@ -5,7 +5,7 @@ import (
 	"net/http"
 
 	"github.com/gin-gonic/gin"
-	log "github.com/huweihuang/golib/logger/logrus"
+	log "github.com/huweihuang/golib/logger/zap"
 	"k8s.io/apimachinery/pkg/util/validation/field"
 
 	"github.com/huweihuang/golib/gin/types"
@@ -18,7 +18,7 @@ func SucceedWrapper(c *gin.Context, msg string, data interface{}) {
 		Message: fmt.Sprintf("%s succeed", msg),
 		Data:    data,
 	}
-	log.Log().WithField("resp", resp).Info(msg)
+	log.Logger().With("resp", resp).Info(msg)
 	c.JSON(http.StatusOK, resp)
 }
 
@@ -29,7 +29,7 @@ func ErrorWrapper(c *gin.Context, msg string, err error) {
 		Message: fmt.Sprintf("%s failed", msg),
 		Data:    map[string]interface{}{"error": err.Error()},
 	}
-	log.Log().WithField("resp", resp).Error(msg)
+	log.Logger().With("resp", resp).Error(msg)
 	c.AbortWithStatusJSON(http.StatusInternalServerError, resp)
 }
 
@@ -40,7 +40,7 @@ func NotFoundWrapper(c *gin.Context, msg string, data interface{}) {
 		Message: fmt.Sprintf("%s not found", msg),
 		Data:    data,
 	}
-	log.Log().WithField("resp", resp).Error(msg)
+	log.Logger().With("resp", resp).Error(msg)
 	c.AbortWithStatusJSON(http.StatusNotFound, resp)
 }
 
@@ -51,7 +51,7 @@ func BadRequestWrapper(c *gin.Context, err error) {
 		Message: "invalid request",
 		Data:    map[string]interface{}{"error": err.Error()},
 	}
-	log.Log().WithField("resp", resp).Error("invalid request")
+	log.Logger().With("resp", resp).Error("invalid request")
 	c.AbortWithStatusJSON(http.StatusBadRequest, resp)
 }
 
@@ -62,18 +62,20 @@ func ValidateBadRequestWrapper(c *gin.Context, errs field.ErrorList) {
 		Message: "invalid request",
 		Data:    map[string]interface{}{"error": errs},
 	}
-	log.Log().WithField("resp", resp).Error("invalid request")
+	log.Logger().With("resp", resp).Error("invalid request")
 	c.AbortWithStatusJSON(http.StatusBadRequest, resp)
 }
 
-func ParseRequest(c *gin.Context, request interface{}) {
+func ParseRequest(c *gin.Context, request interface{}) error {
 	if err := c.BindJSON(request); err != nil {
 		resp := types.Response{
 			Code:    http.StatusBadRequest,
 			Message: "invalid request body",
 			Data:    map[string]interface{}{"error": err},
 		}
-		log.Log().WithField("err", err).Warn("invalid request body")
+		log.Logger().With("err", err).Warn("invalid request body")
 		c.AbortWithStatusJSON(http.StatusBadRequest, resp)
+		return err
 	}
+	return nil
 }

go.mod

@@ -12,6 +12,7 @@ require (
 	github.com/sirupsen/logrus v1.9.3
 	github.com/spf13/pflag v1.0.5
 	github.com/spf13/viper v1.16.0
+	go.uber.org/atomic v1.9.0
 	go.uber.org/zap v1.26.0
 	gopkg.in/natefinch/lumberjack.v2 v2.2.1
 	gopkg.in/yaml.v2 v2.4.0

go.sum

@@ -284,6 +284,8 @@ go.opencensus.io v0.22.2/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw=
 go.opencensus.io v0.22.3/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw=
 go.opencensus.io v0.22.4/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw=
 go.opencensus.io v0.22.5/go.mod h1:5pWMHQbX5EPX2/62yrJeAkowc+lfs/XD7Uxpq3pI6kk=
+go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE=
+go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
 go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk=
 go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
 go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=

httplib/httplib.go

@@ -7,14 +7,13 @@ import (
 	"io/ioutil"
 	"net/http"
 
-	log "github.com/huweihuang/golib/logger/logrus"
-	"github.com/sirupsen/logrus"
+	log "github.com/huweihuang/golib/logger/zap"
 )
 
 func CallURL(method, url, path string, header map[string]string, request interface{}, response interface{}) (
 	statusCode int, body []byte, err error) {
 
-	log.Log().WithFields(logrus.Fields{
+	log.Logger().With(map[string]interface{}{
 		"method":  method,
 		"url":     url,
 		"path":    path,

logger/example/logrus/log/info.log

@@ -1 +1 @@
-info.log.20231015
+info.log.20231111

logger/example/logrus/log/info.log.20231111

@@ -0,0 +1 @@
+{"field1":"field1","file":"logrus_test.go:50","func":"TestLog","level":"info","msg":"test field, info","time":"2023-11-11 16:38:12"}

logger/example/logrus/log/logrus.log

@@ -1 +1 @@
-logrus.log.20231015
+logrus.log.20231111

logger/example/logrus/log/logrus.log.20231111

@@ -0,0 +1,12 @@
+time=2023-11-11 16:38:06 level=debug msg=test debugf, debugf func=TestLogrus file=logrus_test.go:16
+time=2023-11-11 16:38:06 level=info msg=test infof, infof func=TestLogrus file=logrus_test.go:17
+time=2023-11-11 16:38:06 level=warning msg=test warnf, warnf func=TestLogrus file=logrus_test.go:18
+time=2023-11-11 16:38:06 level=error msg=test errorf, errorf func=TestLogrus file=logrus_test.go:19
+time=2023-11-11 16:38:06 level=debug msg=test field, debug func=TestLogrus file=logrus_test.go:22 field1=debug
+time=2023-11-11 16:38:06 level=info msg=test field, info func=TestLogrus file=logrus_test.go:23 field1=info
+time=2023-11-11 16:38:06 level=warning msg=test field, warn func=TestLogrus file=logrus_test.go:24 field1=warn
+time=2023-11-11 16:38:06 level=error msg=test field, error func=TestLogrus file=logrus_test.go:25 field1=error
+time=2023-11-11 16:38:06 level=debug msg=test fields, debug func=TestLogrus file=logrus_test.go:31 fields1=fields1_value fields2=fields2_value
+time=2023-11-11 16:38:06 level=info msg=test fields, info func=TestLogrus file=logrus_test.go:36 fields1=fields1_value fields2=fields2_value
+time=2023-11-11 16:38:06 level=warning msg=test fields, warn func=TestLogrus file=logrus_test.go:41 fields1=fields1_value fields2=fields2_value
+time=2023-11-11 16:38:06 level=error msg=test fields, error func=TestLogrus file=logrus_test.go:46 fields1=fields1_value fields2=fields2_value

logger/example/logrus/logrus_test.go

@@ -13,39 +13,39 @@ func TestLogrus(t *testing.T) {
 	log.InitLogger("./log/logrus.log", "debug", "text", false)
 
 	// Printf
-	log.Logger.Debugf("test debugf, %s", "debugf")
-	log.Logger.Infof("test infof, %s", "infof")
-	log.Logger.Warnf("test warnf, %s", "warnf")
-	log.Logger.Errorf("test errorf, %s", "errorf")
+	log.Logger().Debugf("test debugf, %s", "debugf")
+	log.Logger().Infof("test infof, %s", "infof")
+	log.Logger().Warnf("test warnf, %s", "warnf")
+	log.Logger().Errorf("test errorf, %s", "errorf")
 
 	// WithField
-	log.Logger.WithField("field1", "debug").Debug("test field, debug")
-	log.Logger.WithField("field1", "info").Info("test field, info")
-	log.Logger.WithField("field1", "warn").Warn("test field, warn")
-	log.Logger.WithField("field1", "error").Error("test field, error")
+	log.Logger().WithField("field1", "debug").Debug("test field, debug")
+	log.Logger().WithField("field1", "info").Info("test field, info")
+	log.Logger().WithField("field1", "warn").Warn("test field, warn")
+	log.Logger().WithField("field1", "error").Error("test field, error")
 
 	// WithFields
-	log.Logger.WithFields(logrus.Fields{
+	log.Logger().WithFields(logrus.Fields{
 		"fields1": "fields1_value",
 		"fields2": "fields2_value",
 	}).Debug("test fields, debug")
 
-	log.Logger.WithFields(logrus.Fields{
+	log.Logger().WithFields(logrus.Fields{
 		"fields1": "fields1_value",
 		"fields2": "fields2_value",
 	}).Info("test fields, info")
 
-	log.Logger.WithFields(logrus.Fields{
+	log.Logger().WithFields(logrus.Fields{
 		"fields1": "fields1_value",
 		"fields2": "fields2_value",
 	}).Warn("test fields, warn")
 
-	log.Logger.WithFields(logrus.Fields{
+	log.Logger().WithFields(logrus.Fields{
 		"fields1": "fields1_value",
 		"fields2": "fields2_value",
 	}).Error("test fields, error")
 }
 
 func TestLog(t *testing.T) {
-	log.Log().WithField("field1", "field1").Info("test field, info")
+	log.Logger().WithField("field1", "field1").Info("test field, info")
 }

logger/example/zap/log/server.log

@@ -1 +1 @@
-server.log.20231015
+server.log.20231111

logger/example/zap/log/server.log.20231111

@@ -0,0 +1,9 @@
+{"level":"info","time":"2023-11-11T16:26:01.840+0800","caller":"zap/zap_test.go:61","msg":"info level test"}
+{"level":"debug","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:64","msg":"debug level test"}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:66","msg":"info level test: 111"}
+{"level":"debug","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:69","msg":"debug level test: 111"}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:71","msg":"test with field","with_field":{"test1":"value1","test2":"value2"}}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:73","msg":"failed to fetch URL","url":"example.com","attempt":3,"backoff":1}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:80","msg":"failed to fetch URL","url":"example.com","attempt":3,"backoff":1}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/format.go:18","msg":"this is a log","Trace":"12345677"}
+{"level":"info","time":"2023-11-11T16:26:01.841+0800","caller":"zap/format.go:18","msg":"this is a log","error":"this is a new error"}

logger/example/zap/log/server_err.log

@@ -1 +1 @@
-server_err.log.20231015
+server_err.log.20231111

logger/example/zap/log/server_err.log.20231111

@@ -0,0 +1,4 @@
+{"level":"error","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:62","msg":"error level test"}
+{"level":"warn","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:63","msg":"warn level test"}
+{"level":"error","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:67","msg":"error level test: 111"}
+{"level":"warn","time":"2023-11-11T16:26:01.841+0800","caller":"zap/zap_test.go:68","msg":"warn level test: 111"}

logger/example/zap/log/zap.error.log

@@ -1,8 +1,4 @@
-{"level":"error","time":"2023-10-15T12:44:10.119+0800","caller":"zap/zap_test.go:35","msg":"error level test"}
-{"level":"warn","time":"2023-10-15T12:44:10.119+0800","caller":"zap/zap_test.go:36","msg":"warn level test"}
-{"level":"error","time":"2023-10-15T12:44:10.119+0800","caller":"zap/zap_test.go:40","msg":"error level test: 111"}
-{"level":"warn","time":"2023-10-15T12:44:10.119+0800","caller":"zap/zap_test.go:41","msg":"warn level test: 111"}
-{"level":"error","time":"2023-10-15T12:52:02.968+0800","caller":"zap/zap_test.go:45","msg":"error level test"}
-{"level":"warn","time":"2023-10-15T12:52:02.968+0800","caller":"zap/zap_test.go:46","msg":"warn level test"}
-{"level":"error","time":"2023-10-15T12:52:02.968+0800","caller":"zap/zap_test.go:50","msg":"error level test: 111"}
-{"level":"warn","time":"2023-10-15T12:52:02.968+0800","caller":"zap/zap_test.go:51","msg":"warn level test: 111"}
+{"level":"error","time":"2023-11-11T16:26:01.839+0800","caller":"zap/zap_test.go:62","msg":"error level test"}
+{"level":"warn","time":"2023-11-11T16:26:01.839+0800","caller":"zap/zap_test.go:63","msg":"warn level test"}
+{"level":"error","time":"2023-11-11T16:26:01.839+0800","caller":"zap/zap_test.go:67","msg":"error level test: 111"}
+{"level":"warn","time":"2023-11-11T16:26:01.839+0800","caller":"zap/zap_test.go:68","msg":"warn level test: 111"}