chore: refactor error log for manager api (#689)

* chore: refactor log

* fix: custom log by conf

* feat: add error log

* fix default config

* fix CI fail

* fix: should not save log to file by default

* test: add test case

* test: add test case

* fix CI fail

* fix error

* fix CI

* fix error

* fix according to reviews

* test: more test cases

* fix error

* chore: use `/dev/stdout` as default log file path

* fix typo

* fix docker for logs dir

* fix CI fail

* fix: delete useless files

* fix: change file name

.github/workflows/cli_test.yml

@@ -0,0 +1,31 @@
+name: Test CLI
+
+on:
+  push:
+    branches:
+      - master
+      - v2.0
+  pull_request:
+    branches:
+      - master
+      - v2.0
+
+jobs:
+  run-test:
+    runs-on: ubuntu-latest
+
+    services:
+      etcd:
+        image: bitnami/etcd:3.4.13
+        ports:
+          - 2379:2379
+          - 2380:2380
+        env:
+          ALLOW_NONE_AUTHENTICATION: yes
+
+    steps:
+      - uses: actions/checkout@v2
+
+      - name: run test
+        working-directory: ./api
+        run: sudo ./test/shell/cli_test.sh

Dockerfile

@@ -77,6 +77,8 @@ COPY --from=api-builder /usr/local/apisix-dashboard/output/ ./
 
 COPY --from=fe-builder /usr/local/apisix-dashboard/output/ ./
 
+RUN mkdir logs
+
 EXPOSE 8080
 
 CMD [ "/usr/local/apisix-dashboard/manager-api" ]

api/Dockerfile

@@ -54,6 +54,8 @@ WORKDIR /go/manager-api
 COPY --from=build-env /go/manager-api/ /go/manager-api/
 COPY --from=build-env /usr/share/zoneinfo/Hongkong /etc/localtime
 
+RUN mkdir logs
+
 EXPOSE 8080
 
 RUN chmod +x ./entry.sh

api/conf/conf.go

@@ -22,6 +22,7 @@ import (
 	"io/ioutil"
 	"log"
 	"os"
+	"path/filepath"
 
 	"github.com/tidwall/gjson"
 	"gopkg.in/yaml.v2"
@@ -45,6 +46,8 @@ var (
 	ServerHost    = "127.0.0.1"
 	ServerPort    = 80
 	ETCDEndpoints = []string{"127.0.0.1:2379"}
+	ErrorLogLevel = "warn"
+	ErrorLogPath  = "logs/error.log"
 	UserList      = make(map[string]User, 2)
 	AuthConf      Authentication
 )
@@ -58,9 +61,19 @@ type Listen struct {
 	Port int
 }
 
+type ErrorLog struct {
+	Level    string
+	FilePath string `yaml:"file_path"`
+}
+
+type Log struct {
+	ErrorLog ErrorLog `yaml:"error_log"`
+}
+
 type Conf struct {
 	Etcd   Etcd
 	Listen Listen
+	Log    Log
 }
 
 type User struct {
@@ -109,6 +122,7 @@ func setConf() {
 		if config.Conf.Listen.Port != 0 {
 			ServerPort = config.Conf.Listen.Port
 		}
+
 		if config.Conf.Listen.Host != "" {
 			ServerHost = config.Conf.Listen.Host
 		}
@@ -118,6 +132,20 @@ func setConf() {
 			ETCDEndpoints = config.Conf.Etcd.Endpoints
 		}
 
+		//error log
+		if config.Conf.Log.ErrorLog.Level != "" {
+			ErrorLogLevel = config.Conf.Log.ErrorLog.Level
+		}
+		if config.Conf.Log.ErrorLog.FilePath != "" {
+			ErrorLogPath = config.Conf.Log.ErrorLog.FilePath
+		}
+		if !filepath.IsAbs(ErrorLogPath) {
+			ErrorLogPath, err = filepath.Abs(WorkDir + "/" + ErrorLogPath)
+			if err != nil {
+				panic(err)
+			}
+		}
+
 		//auth
 		initAuthentication(config.Authentication)
 	}

api/conf/conf.yaml

@@ -22,6 +22,11 @@ conf:
   etcd:
     endpoints:               # supports defining multiple etcd host addresses for an etcd cluster
       - 127.0.0.1:2379
+  log:
+    error_log:
+      level: warn                  # supports levels, lower to higher: debug, info, warn, error, panic, fatal
+      file_path: logs/error.log    # supports relative path, absolute path, standard output
+                                   # such as: logs/error.log, /tmp/logs/error.log, /dev/stdout, /dev/stderr
 authentication:
   secret: secret             # secret for jwt token generation.
                              # *NOTE*: Highly recommended to modify this value to protect `manager api`.

api/filter/logging.go

@@ -16,74 +16,4 @@
  */
 package filter
 
-import (
-	"bytes"
-	"io/ioutil"
-	"time"
-
-	"github.com/gin-gonic/gin"
-	"github.com/shiningrush/droplet/log"
-	"github.com/sirupsen/logrus"
-)
-
-func RequestLogHandler() gin.HandlerFunc {
-	return func(c *gin.Context) {
-		start, host, remoteIP, path, method := time.Now(), c.Request.Host, c.ClientIP(), c.Request.URL.Path, c.Request.Method
-		var val interface{}
-		if method == "GET" {
-			val = c.Request.URL.Query()
-		} else {
-			val, _ = c.GetRawData()
-
-			// set RequestBody back
-			c.Request.Body = ioutil.NopCloser(bytes.NewReader(val.([]byte)))
-		}
-		c.Set("requestBody", val)
-		uuid, _ := c.Get("X-Request-Id")
-
-		param, _ := c.Get("requestBody")
-
-		switch paramType := param.(type) {
-		case []byte:
-			param = string(param.([]byte))
-			log.Infof("type of param: %#v", paramType)
-		default:
-		}
-
-		blw := &bodyLogWriter{body: bytes.NewBufferString(""), ResponseWriter: c.Writer}
-		c.Writer = blw
-		c.Next()
-		latency := time.Since(start) / 1000000
-		statusCode := c.Writer.Status()
-		respBody := blw.body.String()
-		if uuid == "" {
-			uuid = c.Writer.Header().Get("X-Request-Id")
-		}
-		var errs []string
-		for _, err := range c.Errors {
-			errs = append(errs, err.Error())
-		}
-		logger.WithFields(logrus.Fields{
-			"requestId":  uuid,
-			"latency":    latency,
-			"remoteIp":   remoteIP,
-			"method":     method,
-			"path":       path,
-			"statusCode": statusCode,
-			"host":       host,
-			"params":     param,
-			"respBody":   respBody,
-			"errMsg":     errs,
-		}).Info("")
-	}
-}
-
-type bodyLogWriter struct {
-	gin.ResponseWriter
-	body *bytes.Buffer
-}
-
-func (w bodyLogWriter) Write(b []byte) (int, error) {
-	w.body.Write(b)
-	return w.ResponseWriter.Write(b)
-}
+//for logging access log, will refactor it in a new pr.

api/filter/recover.go

@@ -26,11 +26,9 @@ import (
 
 	"github.com/apisix/manager-api/log"
 	"github.com/gin-gonic/gin"
-	"github.com/sirupsen/logrus"
 )
 
 var (
-	logger    = log.GetLogger()
 	dunno     = []byte("???")
 	centerDot = []byte("·")
 	dot       = []byte(".")
@@ -41,12 +39,13 @@ func RecoverHandler() gin.HandlerFunc {
 	return func(c *gin.Context) {
 		defer func() {
 			if err := recover(); err != nil {
-				uuid := c.Writer.Header().Get("X-Request-Id")
-				logger.WithFields(logrus.Fields{
-					"uuid": uuid,
-				})
+				fmt.Println("err；", err)
+				//uuid := c.Writer.Header().Get("X-Request-Id")
 				stack := stack(3)
-				logger.Errorf("[Recovery] %s panic recovered:\n\n%s\n%s", timeFormat(time.Now()), err, stack)
+				fmt.Printf("[Recovery] %s panic recovered:\n\n%s\n%s", timeFormat(time.Now()), err, stack)
+
+				//log.With(zap.String("uuid", uuid))
+				log.Errorf("[Recovery] %s panic recovered:\n\n%s\n%s", timeFormat(time.Now()), err, stack)
 				c.AbortWithStatus(http.StatusInternalServerError)
 			}
 		}()
@@ -58,7 +57,7 @@ func WrapGo(f func(...interface{}), args ...interface{}) {
 	defer func() {
 		if err := recover(); err != nil {
 			stack := stack(3)
-			logger.Errorf("[Recovery] %s panic recovered:\n\n%s\n%s", timeFormat(time.Now()), err, stack)
+			log.Errorf("[Recovery] %s panic recovered:\n\n%s\n%s", timeFormat(time.Now()), err, stack)
 		}
 	}()
 	f(args...)

api/go.mod

@@ -17,6 +17,9 @@ require (
 	github.com/gin-gonic/gin v1.6.3
 	github.com/gogo/protobuf v1.3.1 // indirect
 	github.com/google/uuid v1.1.2 // indirect
+	github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible
+	github.com/lestrrat-go/strftime v1.0.3 // indirect
+	github.com/natefinch/lumberjack v2.0.0+incompatible
 	github.com/satori/go.uuid v1.2.0
 	github.com/shiningrush/droplet v0.2.1
 	github.com/shiningrush/droplet/wrapper/gin v0.2.0

api/go.sum

@@ -89,6 +89,11 @@ github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
 github.com/leodido/go-urn v1.1.0/go.mod h1:+cyI34gQWZcE1eQU7NVgKkkzdXDQHr1dBMtdAPozLkw=
 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/lestrrat-go/envload v0.0.0-20180220234015-a3eb8ddeffcc/go.mod h1:kopuH9ugFRkIXf3YoqHKyrJ9YfUFsckUU9S7B+XP+is=
+github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible h1:Y6sqxHMyB1D2YSzWkLibYKgg+SwmyFU9dF2hn6MdTj4=
+github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible/go.mod h1:ZQnN8lSECaebrkQytbHj4xNgtg8CR7RYXnPok8e0EHA=
+github.com/lestrrat-go/strftime v1.0.3 h1:qqOPU7y+TM8Y803I8fG9c/DyKG3xH/xkng6keC1015Q=
+github.com/lestrrat-go/strftime v1.0.3/go.mod h1:E1nN3pCbtMSu1yjSVeyuRFVm/U0xoR76fd03sz+Qz4g=
 github.com/mattn/go-isatty v0.0.9/go.mod h1:YNRxwqDuOph6SZLI9vUUz6OYw3QyUt7WiY2yME+cCiQ=
 github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY=
 github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU=
@@ -97,6 +102,9 @@ github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421/go.mod h1:6dJ
 github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q=
 github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0=
 github.com/modern-go/reflect2 v1.0.1/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0=
+github.com/natefinch/lumberjack v2.0.0+incompatible h1:4QJd3OLAMgj7ph+yZTuX13Ld4UpgHp07nNdFX7mqFfM=
+github.com/natefinch/lumberjack v2.0.0+incompatible/go.mod h1:Wi9p2TTF5DG5oU+6YfsmYQpsTIOm0B1VNzQg9Mw6nPk=
+github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I=
 github.com/pkg/errors v0.8.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=

api/internal/core/store/query.go

@@ -16,6 +16,7 @@ package store
 
 import (
 	"github.com/apisix/manager-api/internal/core/entity"
+	"github.com/apisix/manager-api/log"
 )
 
 type Query struct {
@@ -88,7 +89,7 @@ func NewQuery(sort *Sort, filter *Filter, pagination *Pagination) *Query {
 
 func NewSort(sortRaw []string) *Sort {
 	if sortRaw == nil || len(sortRaw)%2 == 1 {
-		// Empty sort list or invalid (odd) length
+		log.Info("empty sort for query")
 		return NoSort
 	}
 	list := []SortBy{}
@@ -117,6 +118,7 @@ func NewSort(sortRaw []string) *Sort {
 
 func NewFilter(filterRaw []string) *Filter {
 	if filterRaw == nil || len(filterRaw)%2 == 1 {
+		log.Info("empty filter for query")
 		return NoFilter
 	}
 	list := []FilterBy{}