Refactor logging (#71)

* rework logger * remove WithError(nil) * remove LOG_DIR for api * unify component key for searching logs * Revert "remove LOG_DIR for api" This reverts commit 7ad11de. * put back file logging * add component for user_action * put back logging with context for handlers * fix: revert changes for using utils.FromContext instead of native logrus * fix: using logger for gorm instance DB Co-authored-by: Dmitry Ng <[email protected]>
vxcontrol · Jan 19, 2023 · d182a6c · d182a6c
1 parent bc11301
commit d182a6c
Show file tree

Hide file tree

Showing 34 changed files with 297 additions and 326 deletions.
diff --git a/.env.template b/.env.template
@@ -1,6 +1,7 @@
 DEBUG=true
 LOG_LEVEL=debug
 LOG_FORMAT=text
+LOG_DIR=build/logs
 
 # vxapi
 API_STATIC_URL=http://127.0.0.1:8080

diff --git a/.vscode/launch.json b/.vscode/launch.json
@@ -37,7 +37,7 @@
                 "VALID_PATH": "${workspaceFolder}/security/vconf",
                 "LOG_DIR": "${workspaceFolder}/build/logs"
             },
-            "args": ["-debug", "-profiling"], 
+            "args": ["-debug", "-profiling"],
             "cwd": "${workspaceFolder}/build",
             "dlvFlags": ["--check-go-version=false"],
             "preLaunchTask": "build vxserver"
@@ -52,7 +52,7 @@
             "env": {
                 "LOG_DIR": "${workspaceFolder}/build/logs"
             },
-            "args": ["-debug"], 
+            "args": ["-debug"],
             "cwd": "${workspaceFolder}/build",
             "dlvFlags": ["--check-go-version=false"],
             "preLaunchTask": "build vxagent"
@@ -78,7 +78,7 @@
                 "--file=${workspaceFolder}/security/vconf/lic/sbh.json",
                 "--version=example",
                 "--force=true"
-            ], 
+            ],
             "cwd": "${workspaceFolder}/scripts/sbh_generator",
             "dlvFlags": ["--check-go-version=false"]
         },
@@ -98,4 +98,4 @@
             "dlvFlags": ["--check-go-version=false"]
         }
     ]
-}
+}
diff --git a/Makefile b/Makefile
@@ -131,6 +131,7 @@ db-create:
 .PHONY: db-seed
 db-seed:
 	awk '1;/-- \+migrate Down/{exit}' $(CURDIR)/db/api/migrations/0001_initial.sql | mysql --host=$(DB_HOST) --user=$(DB_USER) --password=$(DB_PASS) --port=$(DB_PORT) --batch $(DB_NAME)
+	awk '1;/-- \+migrate Down/{exit}' $(CURDIR)/db/api/migrations/0002_add_user_password_change_flag.sql | mysql --host=$(DB_HOST) --user=$(DB_USER) --password=$(DB_PASS) --port=$(DB_PORT) --batch $(DB_NAME)
 	mysql --host=$(DB_HOST) --user=$(DB_USER) --password=$(DB_PASS) --port=$(DB_PORT) $(DB_NAME) < $(CURDIR)/db/api/seed.sql
 	awk '1;/-- \+migrate Down/{exit}' $(CURDIR)/db/server/migrations/0001_initial.sql | mysql --host=$(DB_HOST) --user=$(AGENT_SERVER_DB_USER) --password=$(AGENT_SERVER_DB_PASS) --port=$(DB_PORT) $(AGENT_SERVER_DB_NAME)
 	awk '1;/-- \+migrate Down/{exit}' $(CURDIR)/db/server/migrations/0002_aggregate_conn_type.sql | mysql --host=$(DB_HOST) --user=$(AGENT_SERVER_DB_USER) --password=$(AGENT_SERVER_DB_PASS) --port=$(DB_PORT) $(AGENT_SERVER_DB_NAME)

diff --git a/build/package/dbmigrate/entrypoint.sh b/build/package/dbmigrate/entrypoint.sh
@@ -98,7 +98,7 @@ IGNORE INTO \`users\` (
 EOT
 
 # Waiting migrations from vxui into mysql to upload seed data
-GET_MIGRATION="SELECT count(*) FROM gorp_migrations WHERE id = '0001_initial.sql';"
+GET_MIGRATION="SELECT count(*) FROM gorp_migrations WHERE id = '0002_add_user_password_change_flag.sql';"
 while true; do
     MIGRATION=$(mysql -h"$DB_HOST" -P"$DB_PORT" -u"$DB_USER" -p"$DB_PASS" "$DB_NAME" -Nse "$GET_MIGRATION" 2>/dev/null)
     if [[ $? -eq 0 && $MIGRATION -eq 1 ]]; then

diff --git a/cmd/api/main.go b/cmd/api/main.go
@@ -24,7 +24,7 @@ import (
 	useraction "soldr/pkg/app/api/user_action"
 	"soldr/pkg/app/api/utils/meter"
 	"soldr/pkg/app/api/worker"
-	"soldr/pkg/log"
+	"soldr/pkg/logger"
 	"soldr/pkg/observability"
 	"soldr/pkg/secret"
 	"soldr/pkg/storage/mysql"
@@ -47,6 +47,7 @@ type Config struct {
 type LogConfig struct {
 	Level  string `config:"log_level"`
 	Format string `config:"log_format"`
+	Dir    string `config:"log_dir"`
 }
 
 type DBConfig struct {
@@ -57,7 +58,6 @@ type DBConfig struct {
 	Port int    `config:"db_port,required"`
 }
 
-// TODO: refactor old env names
 type PublicAPIConfig struct {
 	Addr            string        `config:"api_listen_http"`
 	AddrHTTPS       string        `config:"api_listen_https"`
@@ -80,6 +80,7 @@ func defaultConfig() Config {
 		Log: LogConfig{
 			Level:  "info",
 			Format: "json",
+			Dir:    "logs",
 		},
 		Tracing: TracingConfig{
 			Addr: "otel.local:8148",
@@ -121,32 +122,34 @@ func main() {
 		version.IsDevelop = "true"
 	}
 
+	logLevels := []logrus.Level{
+		logrus.PanicLevel,
+		logrus.FatalLevel,
+		logrus.ErrorLevel,
+		logrus.WarnLevel,
+		logrus.InfoLevel,
+	}
 	if cfg.Debug {
+		logLevels = append(logLevels, logrus.DebugLevel)
 		cfg.Log.Level = "debug"
+		cfg.Log.Format = "text"
 	}
-	logLevel, err := log.ParseLevel(cfg.Log.Level)
-	if err != nil {
-		fmt.Fprintf(os.Stderr, "could not parse log level: %s", err)
-		return
-	}
-	logFormat, err := log.ParseFormat(cfg.Log.Format)
-	if err != nil {
-		fmt.Fprintf(os.Stderr, "could not parse log format: %s", err)
-		return
-	}
-	logDir := "logs"
+
+	logDir := cfg.Log.Dir
 	if dir, ok := os.LookupEnv("LOG_DIR"); ok {
 		logDir = dir
 	}
 	logFile := &lumberjack.Logger{
-		Filename:   path.Join(logDir, "app.log"),
-		MaxSize:    100,
+		Filename:   path.Join(logDir, "api.log"),
+		MaxSize:    10,
 		MaxBackups: 7,
 		MaxAge:     14,
 		Compress:   true,
 	}
-	logger := log.New(log.Config{Level: logLevel, Format: logFormat}, io.MultiWriter(os.Stdout, logFile))
-	ctx = log.AttachToContext(ctx, logger)
+
+	logrus.SetLevel(logger.ParseLevel(cfg.Log.Level))
+	logrus.SetFormatter(logger.ParseFormat(cfg.Log.Format))
+	logrus.SetOutput(io.MultiWriter(os.Stdout, logFile))
 
 	dsn := fmt.Sprintf("%s:%s@%s/%s?parseTime=true",
 		cfg.DB.User,
@@ -156,11 +159,11 @@ func main() {
 	)
 	db, err := mysql.New(&mysql.Config{DSN: secret.NewString(dsn)})
 	if err != nil {
-		logger.WithError(err).Error("could not create DB instance")
+		logrus.WithError(err).Error("could not create DB instance")
 		return
 	}
 	if err = db.RetryConnect(ctx, 10, 100*time.Millisecond); err != nil {
-		logger.WithError(err).Error("could not connect to database")
+		logrus.WithError(err).Error("could not connect to database")
 		return
 	}
 
@@ -169,12 +172,12 @@ func main() {
 		migrationDir = dir
 	}
 	if err = db.Migrate(migrationDir); err != nil {
-		logger.WithError(err).Error("could not apply migrations")
+		logrus.WithError(err).Error("could not apply migrations")
 		return
 	}
-	dbWithORM, err := db.WithORM(ctx)
+	dbWithORM, err := db.WithORM()
 	if err != nil {
-		logger.WithError(err).Error("could not create ORM")
+		logrus.WithError(err).Error("could not create ORM")
 		return
 	}
 	if cfg.Debug {
@@ -202,7 +205,7 @@ func main() {
 		attr,
 	)
 	if err != nil {
-		logger.WithError(err).Error("could not create tracer provider")
+		logrus.WithError(err).Error("could not create tracer provider")
 		return
 	}
 	meterClient := observability.NewProxyMeterClient(
@@ -214,7 +217,7 @@ func main() {
 		}),
 	)
 	if err != nil {
-		logger.WithError(err).Error("could not create meter client")
+		logrus.WithError(err).Error("could not create meter client")
 		return
 	}
 	meterProvider, err := observability.NewMeterProvider(
@@ -225,20 +228,10 @@ func main() {
 		attr,
 	)
 	if err != nil {
-		logger.WithError(err).Error("could not create meter provider")
+		logrus.WithError(err).Error("could not create meter provider")
 		return
 	}
 
-	logLevels := []logrus.Level{
-		logrus.PanicLevel,
-		logrus.FatalLevel,
-		logrus.ErrorLevel,
-		logrus.WarnLevel,
-		logrus.InfoLevel,
-	}
-	if cfg.Debug {
-		logLevels = append(logLevels, logrus.DebugLevel)
-	}
 	observability.InitObserver(
 		ctx,
 		tracerProvider,
@@ -252,7 +245,7 @@ func main() {
 
 	gormMeter := meterProvider.Meter("vxapi-meter")
 	if err = meter.InitGormMetrics(gormMeter); err != nil {
-		logger.WithError(err).Error("could not initialize vxapi-meter")
+		logrus.WithError(err).Error("could not initialize vxapi-meter")
 		return
 	}
 
@@ -265,7 +258,7 @@ func main() {
 	eventWorker := srvevents.NewEventPoller(exchanger, cfg.EventWorker.PollInterval, dbWithORM)
 	go func() {
 		if err = eventWorker.Run(ctx); err != nil {
-			logger.WithError(err).Error("could not start event worker")
+			logrus.WithError(err).Error("could not start event worker")
 		}
 	}()
 
@@ -278,7 +271,7 @@ func main() {
 	// run worker to synchronize events retention policy to all instance DB
 	go worker.SyncRetentionEvents(ctx, dbWithORM)
 
-	userActionWriter := useraction.NewLogWriter(logger)
+	userActionWriter := useraction.NewLogWriter()
 
 	router := server.NewRouter(
 		dbWithORM,
@@ -305,7 +298,7 @@ func main() {
 			}.ListenAndServeTLS(ctx, router)
 		})
 	}
-	if err := srvg.Wait(); err != nil {
-		logger.WithError(err).Error("failed to start server")
+	if err = srvg.Wait(); err != nil {
+		logrus.WithError(err).Error("failed to start server")
 	}
 }
diff --git a/cmd/server/main.go b/cmd/server/main.go
@@ -286,7 +286,7 @@ func initGorm(dsn *db.DSN, logDir string) (*gorm.DB, error) {
 	logger := logrus.New()
 	logger.SetOutput(&lumberjack.Logger{
 		Filename:   filepath.Join(logDir, "server-gorm.log"),
-		MaxSize:    100,
+		MaxSize:    10,
 		MaxBackups: 7,
 		MaxAge:     14,
 		Compress:   true,

diff --git a/db/api/migrations/0002_add_user_password_change_flag.sql b/db/api/migrations/0002_add_user_password_change_flag.sql
@@ -1,7 +1,7 @@
 -- +migrate Up
 
 ALTER TABLE `users` ADD COLUMN
-    `password_change_required` BOOL NOT NULL DEFAULT false;
+    `password_change_required` BOOL NOT NULL DEFAULT false AFTER `tenant_id`;
 
 -- +migrate Down
 

diff --git a/go.mod b/go.mod
@@ -233,7 +233,6 @@ require (
 	github.com/quasilyte/gogrep v0.0.0-20220828223005-86e4605de09f // indirect
 	github.com/quasilyte/regex/syntax v0.0.0-20200407221936-30656e2c4a95 // indirect
 	github.com/quasilyte/stdinfo v0.0.0-20220114132959-f7386bf02567 // indirect
-	github.com/quasoft/memstore v0.0.0-20191010062613-2bce066d2b0b // indirect
 	github.com/rogpeppe/go-internal v1.9.0 // indirect
 	github.com/rs/xid v1.4.0 // indirect
 	github.com/ryancurrah/gomodguard v1.2.4 // indirect

diff --git a/go.sum b/go.sum
@@ -907,7 +907,6 @@ github.com/quasilyte/regex/syntax v0.0.0-20200407221936-30656e2c4a95 h1:L8QM9bvf
 github.com/quasilyte/regex/syntax v0.0.0-20200407221936-30656e2c4a95/go.mod h1:rlzQ04UMyJXu/aOvhd8qT+hvDrFpiwqp8MRXDY9szc0=
 github.com/quasilyte/stdinfo v0.0.0-20220114132959-f7386bf02567 h1:M8mH9eK4OUR4lu7Gd+PU1fV2/qnDNfzT635KRSObncs=
 github.com/quasilyte/stdinfo v0.0.0-20220114132959-f7386bf02567/go.mod h1:DWNGW8A4Y+GyBgPuaQJuWiy0XYftx4Xm/y5Jqk9I6VQ=
-github.com/quasoft/memstore v0.0.0-20191010062613-2bce066d2b0b h1:aUNXCGgukb4gtY99imuIeoh8Vr0GSwAlYxPAhqZrpFc=
 github.com/quasoft/memstore v0.0.0-20191010062613-2bce066d2b0b/go.mod h1:wTPjTepVu7uJBYgZ0SdWHQlIas582j6cn2jgk4DDdlg=
 github.com/rainycape/unidecode v0.0.0-20150907023854-cb7f23ec59be/go.mod h1:MIDFMn7db1kT65GmV94GzpX9Qdi7N/pQlwb+AN8wh+Q=
 github.com/robfig/cron v1.2.0/go.mod h1:JGuDeoQd7Z6yL4zQhZ3OPEVHB7fL6Ka6skscFHfmt2k=

diff --git a/pkg/app/api/client/agent_server.go b/pkg/app/api/client/agent_server.go
@@ -3,6 +3,7 @@ package client
 import (
 	"context"
 	"fmt"
+	"os"
 	"time"
 
 	"github.com/jinzhu/gorm"
@@ -57,10 +58,13 @@ func (c *AgentServerClient) GetDB(ctx context.Context, hash string) (*gorm.DB, e
 		return nil, fmt.Errorf("could not connect to database: %w", err)
 	}
 
-	dbWithORM, err := dbConn.WithORM(ctx)
+	dbWithORM, err := dbConn.WithORM()
 	if err != nil {
 		return nil, fmt.Errorf("could not create ORM: %w", err)
 	}
+	if _, exists := os.LookupEnv("DEBUG"); exists {
+		dbWithORM.LogMode(true)
+	}
 	c.dbConns.Set(hash, dbWithORM)
 
 	return dbWithORM, nil