diff --git a/.gitignore b/.gitignore index 5801c2213..dcc6df15a 100644 --- a/.gitignore +++ b/.gitignore @@ -58,5 +58,6 @@ src/rttmap.csv .vscode/ log/ +*.log *.history diff --git a/Dockerfile b/Dockerfile index 89329aa00..5e0dbf60a 100644 --- a/Dockerfile +++ b/Dockerfile @@ -58,7 +58,15 @@ ENV CBTUMBLEBUG_ROOT=/app \ API_PASSWORD=default \ AUTOCONTROL_DURATION_MS=10000 \ SELF_ENDPOINT=localhost:1323 \ - API_DOC_PATH=/app/src/api/rest/docs/swagger.json + API_DOC_PATH=/app/src/api/rest/docs/swagger.json \ + LOGFILE_PATH=$CBTUMBLEBUG_ROOT/log/tumblebug.log \ + LOGFILE_MAXSIZE=10 \ + LOGFILE_MAXBACKUPS=3 \ + LOGFILE_MAXAGE=30 \ + LOGFILE_COMPRESS=false \ + LOGLEVEL=debug \ + LOGWRITER=both \ + NODE_ENV=development # Setting the entrypoint for the application ENTRYPOINT [ "/app/src/cb-tumblebug" ] diff --git a/conf/setup.env b/conf/setup.env index c5cfd699d..b28c4c4cf 100644 --- a/conf/setup.env +++ b/conf/setup.env @@ -37,3 +37,17 @@ export AUTOCONTROL_DURATION_MS=10000 # Environment variables that you don't need to touch ## Swagger UI API document file path export API_DOC_PATH=$CBTUMBLEBUG_ROOT/src/api/rest/docs/swagger.json + +## Logger configuration +# Set log file path (default logfile path: ./log/tumblebug.log) +export LOGFILE_PATH=$CBTUMBLEBUG_ROOT/log/tumblebug.log +export LOGFILE_MAXSIZE=10 +export LOGFILE_MAXBACKUPS=3 +export LOGFILE_MAXAGE=30 +export LOGFILE_COMPRESS=false +# Set log level, such as trace, debug info, warn, error, fatal, and panic +export LOGLEVEL=debug +# Set log writer, such as file, stdout, or both +export LOGWRITER=both +# Set execution environment, such as development or production +export NODE_ENV=development \ No newline at end of file diff --git a/go.mod b/go.mod index 11f0a53b6..fb203ce9b 100644 --- a/go.mod +++ b/go.mod @@ -65,6 +65,7 @@ require ( github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect github.com/rivo/uniseg v0.2.0 // indirect + github.com/rs/zerolog v1.32.0 // indirect github.com/russross/blackfriday/v2 v2.1.0 // indirect github.com/sagikazarmark/locafero v0.4.0 // indirect github.com/sagikazarmark/slog-shim v0.1.0 // indirect @@ -91,7 +92,7 @@ require ( go.uber.org/zap v1.26.0 // indirect golang.org/x/exp v0.0.0-20240112132812-db7319d0e0e3 // indirect golang.org/x/net v0.20.0 // indirect - golang.org/x/sys v0.16.0 // indirect + golang.org/x/sys v0.18.0 // indirect golang.org/x/text v0.14.0 // indirect golang.org/x/time v0.5.0 // indirect golang.org/x/tools v0.17.0 // indirect diff --git a/go.sum b/go.sum index 24b7a5998..3a7ead181 100644 --- a/go.sum +++ b/go.sum @@ -190,6 +190,7 @@ github.com/mattn/go-isatty v0.0.5/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hd github.com/mattn/go-isatty v0.0.7/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU= github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-runewidth v0.0.15 h1:UNAjwbU9l54TA3KzvqLGxwWjHmMgBUVhBiTjelZgg3U= @@ -232,6 +233,8 @@ 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.13.0/go.mod h1:YbFCdg8HfsridGWAh22vktObvhZbQsZXe4/zB0OKkWU= github.com/rs/zerolog v1.15.0/go.mod h1:xYTKnLHcpfU2225ny5qZjxnj9NvkumZYjJHlAThCjNc= +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= github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf35Ld67mk= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= @@ -415,9 +418,12 @@ golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.13.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.16.0 h1:xWw16ngr6ZMtmxDyKyIgsE93KNKz5HKmMa3b8ALHidU= golang.org/x/sys v0.16.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= +golang.org/x/sys v0.18.0 h1:DBdB3niSjOA/O0blCZBqDefyWNYveAYMNF1Wum0DYQ4= +golang.org/x/sys v0.18.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= diff --git a/go.work.sum b/go.work.sum index de77979cb..0d5ff3492 100644 --- a/go.work.sum +++ b/go.work.sum @@ -406,11 +406,13 @@ github.com/prometheus/client_golang v1.11.1/go.mod h1:Z6t4BnS23TR94PD6BsDNk8yVqr github.com/prometheus/client_model v0.2.0/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/prometheus/common v0.26.0/go.mod h1:M7rCNAaPfAosfx8veZJCuw84e35h3Cfd9VFqTh1DIvc= github.com/prometheus/procfs v0.6.0/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA= +github.com/rs/zerolog v1.15.0 h1:uPRuwkWF4J6fGsJ2R0Gn2jB1EQiav9k3S6CSdygQJXY= github.com/sagikazarmark/crypt v0.17.0/go.mod h1:SMtHTvdmsZMuY/bpZoqokSoChIrcJ/epOxZN58PbZDg= github.com/swaggo/files v0.0.0-20220728132757-551d4a08d97a h1:kAe4YSu0O0UFn1DowNo2MY5p6xzqtJ/wQ7LZynSvGaY= github.com/swaggo/files v0.0.0-20220728132757-551d4a08d97a/go.mod h1:lKJPbtWzJ9JhsTN1k1gZgleJWY/cqq0psdoMmaThG3w= go.opencensus.io v0.24.0/go.mod h1:vNK8G9p7aAivkbmorf4v+7Hgx+Zs0yY+0fOtgBfjQKo= go.uber.org/atomic v1.10.0/go.mod h1:LUxbIzbOniOlMKjJjyPfpl4v+PKK2cNJn91OQbhoJI0= +golang.org/x/oauth2 v0.15.0/go.mod h1:q48ptWNTY5XWf+JNten23lcvHpLJ0ZSxF5ttTHKVCAM= golang.org/x/sync v0.6.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk= golang.org/x/xerrors v0.0.0-20220907171357-04be3eba64a2/go.mod h1:K8+ghG5WaK9qNqU5K3HdILfMLy1f3aNYFI/wnl100a8= google.golang.org/appengine v1.6.8/go.mod h1:1jJ3jBArFh5pcgW8gCtRJnepW8FzD1V44FJffLiz/Ds= diff --git a/src/api/rest/server/middlewares/custom-middleware.go b/src/api/rest/server/middlewares/custom-middleware.go new file mode 100644 index 000000000..0453a375b --- /dev/null +++ b/src/api/rest/server/middlewares/custom-middleware.go @@ -0,0 +1,57 @@ +package middlewares + +import ( + "github.com/labstack/echo/v4" + "github.com/labstack/echo/v4/middleware" + "github.com/rs/zerolog/log" +) + +func Zerologger() echo.MiddlewareFunc { + return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{ + LogError: true, + LogRequestID: true, + LogRemoteIP: true, + LogHost: true, + LogMethod: true, + LogURI: true, + LogUserAgent: true, + LogStatus: true, + LogLatency: true, + LogContentLength: true, + LogResponseSize: true, + // HandleError: true, // forwards error to the global error handler, so it can decide appropriate status code + LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error { + if v.Error == nil { + log.Info(). + Str("id", v.RequestID). + Str("remote_ip", v.RemoteIP). + Str("host", v.Host). + Str("method", v.Method). + Str("URI", v.URI). + Str("user_agent", v.UserAgent). + Int("status", v.Status). + Int64("latency", v.Latency.Nanoseconds()). + Str("latency_human", v.Latency.String()). + Str("bytes_in", v.ContentLength). + Int64("bytes_out", v.ResponseSize). + Msg("request") + } else { + log.Error(). + Err(v.Error). + Str("id", v.RequestID). + Str("remote_ip", v.RemoteIP). + Str("host", v.Host). + Str("method", v.Method). + Str("URI", v.URI). + Str("user_agent", v.UserAgent). + Int("status", v.Status). + Int64("latency", v.Latency.Nanoseconds()). + Str("latency_human", v.Latency.String()). + Str("bytes_in", v.ContentLength). + Int64("bytes_out", v.ResponseSize). + Msg("request error") + } + return nil + }, + }) +} diff --git a/src/api/rest/server/server.go b/src/api/rest/server/server.go index 186c76658..b9a6ab76f 100644 --- a/src/api/rest/server/server.go +++ b/src/api/rest/server/server.go @@ -16,7 +16,7 @@ package server import ( "context" - "log" + // "log" "os/signal" "sync" "syscall" @@ -24,9 +24,12 @@ import ( "github.com/cloud-barista/cb-tumblebug/src/core/common" + "github.com/rs/zerolog/log" + rest_common "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/common" rest_mcir "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/mcir" rest_mcis "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/mcis" + "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/middlewares" rest_netutil "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/util" "crypto/subtle" @@ -79,10 +82,13 @@ const ( // RunServer func start Rest API server func RunServer(port string) { + log.Info().Msg("REST API Server is starting") + e := echo.New() // Middleware - e.Use(middleware.Logger()) + // e.Use(middleware.Logger()) + e.Use(middlewares.Zerologger()) e.Use(middleware.Recover()) // limit the application to 20 requests/sec using the default in-memory store e.Use(middleware.RateLimiter(middleware.NewRateLimiterMemoryStore(20))) @@ -109,7 +115,7 @@ func RunServer(port string) { allowedOrigins := os.Getenv("ALLOW_ORIGINS") if allowedOrigins == "" { - log.Fatal("ALLOW_ORIGINS env variable for CORS is " + allowedOrigins + + log.Fatal().Msgf("ALLOW_ORIGINS env variable for CORS is " + allowedOrigins + ". Please provide a proper value and source setup.env again. EXITING...") // allowedOrigins = "*" } @@ -449,14 +455,14 @@ func RunServer(port string) { defer cancel() if err := e.Shutdown(ctx); err != nil { - log.Println("Error starting the server: ", err) + log.Error().Err(err).Msg("Error starting the server") e.Logger.Panic(err) } }(&wg) port = fmt.Sprintf(":%s", port) if err := e.Start(port); err != nil && err != http.ErrServerClosed { - log.Println("Error starting the server: ", err) + log.Error().Err(err).Msg("Error starting the server") e.Logger.Panic("Shuttig down the server: ", err) } diff --git a/src/core/common/logger/logger.go b/src/core/common/logger/logger.go new file mode 100644 index 000000000..990dc06b0 --- /dev/null +++ b/src/core/common/logger/logger.go @@ -0,0 +1,181 @@ +package logger + +import ( + "os" + "strconv" + "strings" + "time" + + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" + "github.com/spf13/viper" + "gopkg.in/natefinch/lumberjack.v2" +) + +var ( + sharedLogFile *lumberjack.Logger +) + +func init() { + + // Map environment variable names to config file key names + replacer := strings.NewReplacer(".", "_") + viper.SetEnvKeyReplacer(replacer) + + viper.AutomaticEnv() + + // Set config values + logLevel := viper.GetString("loglevel") + env := viper.GetString("node.env") + + // Set the global logger to use JSON format. + zerolog.TimeFieldFormat = time.RFC3339 + + // Get log file configuration from environment variables + logFilePath, maxSize, maxBackups, maxAge, compress := getLogFileConfig() + + // Initialize a shared log file with lumberjack to manage log rotation + sharedLogFile = &lumberjack.Logger{ + Filename: logFilePath, + MaxSize: maxSize, + MaxBackups: maxBackups, + MaxAge: maxAge, + Compress: compress, + } + + // Set the log level + var level zerolog.Level + switch logLevel { + case "trace": + level = zerolog.TraceLevel + case "debug": + level = zerolog.DebugLevel + case "info": + level = zerolog.InfoLevel + case "warn": + level = zerolog.WarnLevel + case "error": + level = zerolog.ErrorLevel + case "fatal": + level = zerolog.FatalLevel + case "panic": + level = zerolog.PanicLevel + default: + log.Warn().Msgf("Invalid LOGLEVEL value: %s. Using default value: info", logLevel) + level = zerolog.InfoLevel + } + + logger := NewLogger(level) + + // Set global logger + log.Logger = *logger + + // Check the execution environment from the environment variable + // Log a message + log.Info(). + Str("logLevel", level.String()). + Str("env", env). + Int("maxSize", maxSize). + Int("maxBackups", maxBackups). + Int("maxAge", maxAge). + Bool("compress", compress). + Msg("Global logger initialized") +} + +// Create a new logger +func NewLogger(level zerolog.Level) *zerolog.Logger { + + // Set config values + logwriter := viper.GetString("logwriter") + + // Multi-writer setup: logs to both file and console + multi := zerolog.MultiLevelWriter( + sharedLogFile, + zerolog.ConsoleWriter{Out: os.Stdout}, + ) + + var logger zerolog.Logger + + // Check the execution environment from the environment variable + // Configure the log output + if logwriter == "both" { + // Apply file to the global logger + logger = zerolog.New(multi).Level(level).With().Timestamp().Caller().Logger() + } else if logwriter == "file" { + // Apply file writer to the global logger + logger = zerolog.New(sharedLogFile).Level(level).With().Timestamp().Caller().Logger() + } else if logwriter == "stdout" { + // Apply ConsoleWriter to the global logger + logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stdout}).Level(level).With().Timestamp().Caller().Logger() + } else { + log.Warn().Msgf("Invalid LOGWRITER value: %s. Using default value: both", logwriter) + // Apply multi-writer to the global logger + logger = zerolog.New(multi).Level(level).With().Timestamp().Caller().Logger() + } + + // Log a message + logger.Info(). + Str("logLevel", level.String()). + Msg("New logger created") + + if logwriter == "file" { + logger.Info(). + Str("logFilePath", sharedLogFile.Filename). + Msg("Single-write setup (logs to file only)") + + } else if logwriter == "stdout" { + logger.Info(). + Str("ConsoleWriter", "os.Stdout"). + Msg("Single-write setup (logs to console only)") + } else { + logger.Info(). + Str("logFilePath", sharedLogFile.Filename). + Str("ConsoleWriter", "os.Stdout"). + Msg("Multi-writes setup (logs to both file and console)") + } + + return &logger +} + +// Get log file configuration from environment variables +func getLogFileConfig() (string, int, int, int, bool) { + + // Set config values + logFilePath := viper.GetString("logfile.path") + + // Default: ./log/tumblebug.log + if logFilePath == "" { + log.Warn().Msg("LOGFILE_PATH is not set. Using default value: ./log/tumblebug.log") + logFilePath = "./log/tumblebug.log" + } + + // Default: 10 MB + maxSize, err := strconv.Atoi(viper.GetString("logfile.maxsize")) + if err != nil { + log.Warn().Msgf("Invalid LOGFILE_MAXSIZE value: %s. Using default value: 10 MB", viper.GetString("logfile.maxsize")) + maxSize = 10 + } + + // Default: 3 backups + maxBackups, err := strconv.Atoi(viper.GetString("logfile.maxbackups")) + if err != nil { + log.Warn().Msgf("Invalid LOGFILE_MAXBACKUPS value: %s. Using default value: 3 backups", viper.GetString("logfile.maxbackups")) + maxBackups = 3 + } + + // Default: 30 days + maxAge, err := strconv.Atoi(viper.GetString("logfile.maxage")) + if err != nil { + log.Warn().Msgf("Invalid LOGFILE_MAXAGE value: %s. Using default value: 30 days", viper.GetString("logfile.maxage")) + maxAge = 30 + } + + // Default: false + compress, err := strconv.ParseBool(viper.GetString("logfile.compress")) + if err != nil { + log.Warn().Msgf("Invalid LOGFILE_COMPRESS value: %s. Using default value: false", viper.GetString("logfile.compress")) + compress = false + } + + return logFilePath, maxSize, maxBackups, maxAge, compress +} diff --git a/src/main.go b/src/main.go index 334b0856e..e0ac20ce2 100644 --- a/src/main.go +++ b/src/main.go @@ -24,6 +24,9 @@ import ( "sync" "time" + // Black import (_) is for running a package's init() function without using its other contents. + _ "github.com/cloud-barista/cb-tumblebug/src/core/common/logger" + //_ "github.com/go-sql-driver/mysql" "github.com/fsnotify/fsnotify" _ "github.com/mattn/go-sqlite3"