From 8bee421d0a58c4e065a2f587bda6084394fab26c Mon Sep 17 00:00:00 2001 From: Lakhan Samani Date: Wed, 25 May 2022 15:04:26 +0530 Subject: [PATCH] feat: add flag for log level --- server/db/db.go | 2 +- server/env/env.go | 3 +- server/main.go | 54 ++++++++++++-------- server/middlewares/log.go | 92 ++++++++++++++++++++-------------- server/routes/routes.go | 7 ++- server/sessionstore/session.go | 1 + 6 files changed, 95 insertions(+), 64 deletions(-) diff --git a/server/db/db.go b/server/db/db.go index 51b450f..a93cc01 100644 --- a/server/db/db.go +++ b/server/db/db.go @@ -24,7 +24,7 @@ func InitDB() error { isCassandra := envstore.EnvStoreObj.GetStringStoreEnvVariable(constants.EnvKeyDatabaseType) == constants.DbTypeCassandraDB if isSQL { - log.Info("Initializing SQL Driver") + log.Info("Initializing SQL Driver for: ", envstore.EnvStoreObj.GetStringStoreEnvVariable(constants.EnvKeyDatabaseType)) Provider, err = sql.NewProvider() if err != nil { log.Fatal("Failed to initialize SQL driver: ", err) diff --git a/server/env/env.go b/server/env/env.go index bc2be8d..abf9b53 100644 --- a/server/env/env.go +++ b/server/env/env.go @@ -5,7 +5,6 @@ import ( "os" "strings" - "github.com/gin-gonic/gin" "github.com/google/uuid" "github.com/joho/godotenv" log "github.com/sirupsen/logrus" @@ -30,6 +29,7 @@ func InitRequiredEnv() error { if envstore.ARG_ENV_FILE != nil && *envstore.ARG_ENV_FILE != "" { envPath = *envstore.ARG_ENV_FILE } + log.Info("env path: ", envPath) err := godotenv.Load(envPath) if err != nil { @@ -121,7 +121,6 @@ func InitAllEnv() error { if envData.StringEnv[constants.EnvKeyEnv] == "production" { envData.BoolEnv[constants.EnvKeyIsProd] = true - gin.SetMode(gin.ReleaseMode) } else { envData.BoolEnv[constants.EnvKeyIsProd] = false } diff --git a/server/main.go b/server/main.go index 287cc4c..347dbae 100644 --- a/server/main.go +++ b/server/main.go @@ -3,6 +3,7 @@ package main import ( "flag" + "github.com/sirupsen/logrus" log "github.com/sirupsen/logrus" "github.com/authorizerdev/authorizer/server/constants" @@ -16,11 +17,11 @@ import ( var VERSION string -type UTCFormatter struct { +type LogUTCFormatter struct { log.Formatter } -func (u UTCFormatter) Format(e *log.Entry) ([]byte, error) { +func (u LogUTCFormatter) Format(e *log.Entry) ([]byte, error) { e.Time = e.Time.UTC() return u.Formatter.Format(e) } @@ -29,28 +30,37 @@ func main() { envstore.ARG_DB_URL = flag.String("database_url", "", "Database connection string") envstore.ARG_DB_TYPE = flag.String("database_type", "", "Database type, possible values are postgres,mysql,sqlite") envstore.ARG_ENV_FILE = flag.String("env_file", "", "Env file path") - // envstore.ARG_LOG_LEVEL = flag.String("log_level", "", "Log level, possible values are debug,info,warn,error,fatal,panic") + envstore.ARG_LOG_LEVEL = flag.String("log_level", "info", "Log level, possible values are debug,info,warn,error,fatal,panic") + flag.Parse() - log.SetFormatter(UTCFormatter{&log.JSONFormatter{}}) + // global log level + logrus.SetFormatter(LogUTCFormatter{&logrus.JSONFormatter{}}) + logrus.SetReportCaller(true) + + // log instance for gin server + log := logrus.New() + log.SetFormatter(LogUTCFormatter{&logrus.JSONFormatter{}}) log.SetReportCaller(true) - log.SetLevel(log.DebugLevel) - // switch *envstore.ARG_LOG_LEVEL { - // case "debug": - // log.SetLevel(log.DebugLevel) - // case "info": - // log.SetLevel(log.InfoLevel) - // case "warn": - // log.SetLevel(log.WarnLevel) - // case "error": - // log.SetLevel(log.ErrorLevel) - // case "fatal": - // log.SetLevel(log.FatalLevel) - // case "panic": - // log.SetLevel(log.PanicLevel) - // default: - // log.SetLevel(log.InfoLevel) - // } + var logLevel logrus.Level + switch *envstore.ARG_LOG_LEVEL { + case "debug": + logLevel = logrus.DebugLevel + case "info": + logLevel = logrus.InfoLevel + case "warn": + logLevel = logrus.WarnLevel + case "error": + logLevel = logrus.ErrorLevel + case "fatal": + logLevel = logrus.FatalLevel + case "panic": + logLevel = logrus.PanicLevel + default: + logLevel = logrus.InfoLevel + } + logrus.SetLevel(logLevel) + log.SetLevel(logLevel) constants.VERSION = VERSION @@ -91,7 +101,7 @@ func main() { log.Fatalln("Error while initializing oauth: ", err) } - router := routes.InitRouter() + router := routes.InitRouter(log) log.Info("Starting Authorizer: ", VERSION) router.Run(":" + envstore.EnvStoreObj.GetStringStoreEnvVariable(constants.EnvKeyPort)) } diff --git a/server/middlewares/log.go b/server/middlewares/log.go index c15a6a6..357b4b2 100644 --- a/server/middlewares/log.go +++ b/server/middlewares/log.go @@ -2,59 +2,77 @@ package middlewares import ( "fmt" - "io" + "math" + "net/http" + "os" "time" "github.com/gin-gonic/gin" - log "github.com/sirupsen/logrus" - - "github.com/authorizerdev/authorizer/server/constants" - "github.com/authorizerdev/authorizer/server/utils" + "github.com/sirupsen/logrus" ) -// GinLogWriteFunc convert func to io.Writer. -type GinLogWriteFunc func([]byte) (int, error) +var timeFormat = "02/Jan/2006:15:04:05 -0700" -// GinLog Write function -func (fn GinLogWriteFunc) Write(data []byte) (int, error) { - return fn(data) -} +// Logger is the logrus logger handler +func Logger(logger logrus.FieldLogger, notLogged ...string) gin.HandlerFunc { + hostname, err := os.Hostname() + if err != nil { + hostname = "unknown" + } -// NewGinLogrusWrite logrus writer for gin -func NewGinLogrusWrite() io.Writer { - return GinLogWriteFunc(func(data []byte) (int, error) { - log.Info("%v", data) - return 0, nil - }) -} + var skip map[string]struct{} + + if length := len(notLogged); length > 0 { + skip = make(map[string]struct{}, length) + + for _, p := range notLogged { + skip[p] = struct{}{} + } + } -// JSONLogMiddleware logs a gin HTTP request in JSON format, with some additional custom key/values -func JSONLogMiddleware() gin.HandlerFunc { return func(c *gin.Context) { - // Start timer + // other handler can change c.Path so: + path := c.Request.URL.Path start := time.Now() - - // Process Request c.Next() + stop := time.Since(start) + latency := int(math.Ceil(float64(stop.Nanoseconds()) / 1000000.0)) + statusCode := c.Writer.Status() + clientIP := c.ClientIP() + clientUserAgent := c.Request.UserAgent() + referer := c.Request.Referer() + dataLength := c.Writer.Size() + if dataLength < 0 { + dataLength = 0 + } - // Stop timer - duration := utils.GetDurationInMillseconds(start) + if _, ok := skip[path]; ok { + return + } - entry := log.WithFields(log.Fields{ - "client_ip": utils.GetIP(c.Request), - "duration": fmt.Sprintf("%.2f", duration), - "method": c.Request.Method, - "path": c.Request.RequestURI, - "status": c.Writer.Status(), - "referrer": c.Request.Referer(), - "request_id": c.Writer.Header().Get("Request-Id"), - "authorizer_version": constants.VERSION, + entry := logger.WithFields(logrus.Fields{ + "hostname": hostname, + "statusCode": statusCode, + "latency": latency, // time to process + "clientIP": clientIP, + "method": c.Request.Method, + "path": path, + "referer": referer, + "dataLength": dataLength, + "userAgent": clientUserAgent, }) - if c.Writer.Status() >= 500 { - entry.Error(c.Errors.String()) + if len(c.Errors) > 0 { + entry.Error(c.Errors.ByType(gin.ErrorTypePrivate).String()) } else { - entry.Info("") + msg := fmt.Sprintf("%s - %s [%s] \"%s %s\" %d %d \"%s\" \"%s\" (%dms)", clientIP, hostname, time.Now().Format(timeFormat), c.Request.Method, path, statusCode, dataLength, referer, clientUserAgent, latency) + if statusCode >= http.StatusInternalServerError { + entry.Error(msg) + } else if statusCode >= http.StatusBadRequest { + entry.Warn(msg) + } else { + entry.Info(msg) + } } } } diff --git a/server/routes/routes.go b/server/routes/routes.go index 977d465..4ce00f9 100644 --- a/server/routes/routes.go +++ b/server/routes/routes.go @@ -2,15 +2,18 @@ package routes import ( "github.com/gin-gonic/gin" + "github.com/sirupsen/logrus" "github.com/authorizerdev/authorizer/server/handlers" "github.com/authorizerdev/authorizer/server/middlewares" ) // InitRouter initializes gin router -func InitRouter() *gin.Engine { +func InitRouter(log *logrus.Logger) *gin.Engine { + gin.SetMode(gin.ReleaseMode) router := gin.New() - router.Use(gin.Recovery()) + + router.Use(middlewares.Logger(log), gin.Recovery()) router.Use(middlewares.GinContextToContextMiddleware()) router.Use(middlewares.CORSMiddleware()) diff --git a/server/sessionstore/session.go b/server/sessionstore/session.go index 475f3b4..7626e8f 100644 --- a/server/sessionstore/session.go +++ b/server/sessionstore/session.go @@ -145,6 +145,7 @@ func InitSession() error { return nil } + log.Info("using in memory store to save sessions") // if redis url is not set use in memory store SessionStoreObj.InMemoryStoreObj = &InMemoryStore{ sessionStore: map[string]map[string]string{},