Merge pull request #365 from BuxOrg/feat-200-unify-logs

feat(BUX-200): unify logs

.golangci.yml

@@ -348,6 +348,7 @@ issues:
   # excluded by default patterns execute `golangci-lint run --help`
   exclude:
     - Using the variable on range scope .* in function literal
+    - should have a package comment
 
   # Excluding configuration per-path, per-linter, per-text and per-source
   exclude-rules:

README.md

@@ -126,7 +126,6 @@ This repository was created using [MrZ's `go-template`](https://github.com/mrz18
 -   [BitcoinSchema/go-bitcoin](https://github.com/BitcoinSchema/go-bitcoin)
 -   [BuxOrg/bux](https://github.com/BuxOrg/bux)
 -   [mrz1836/go-api-router](https://github.com/mrz1836/go-api-router)
--   [mrz1836/go-logger](https://github.com/mrz1836/go-logger)
 -   [mrz1836/go-sanitize](https://github.com/mrz1836/go-sanitize)
 -   [stretchr/testify](https://github.com/stretchr/testify)
 -   [tonicpow/go-paymail](https://github.com/tonicpow/go-paymail)

actions/graphql/routes.go

@@ -19,7 +19,6 @@ import (
 	"github.com/gofrs/uuid"
 	"github.com/julienschmidt/httprouter"
 	apirouter "github.com/mrz1836/go-api-router"
-	"github.com/mrz1836/go-logger"
 	"github.com/vektah/gqlparser/v2/gqlerror"
 )
 
@@ -62,13 +61,13 @@ func RegisterRoutes(router *apirouter.Router, appConfig *config.AppConfig, servi
 				"variables": oc.Variables,
 			}
 			// LogParamsFormat "request_id=\"%s\" method=\"%s\" path=\"%s\" ip_address=\"%s\" user_agent=\"%s\" params=\"%v\"\n"
-			logger.NoFilePrintf(apirouter.LogParamsFormat, reqInfo.id, reqInfo.method, reqInfo.path, reqInfo.ip, reqInfo.userAgent, params)
+			services.Logger.Info().Msgf(apirouter.LogParamsFormat, reqInfo.id, reqInfo.method, reqInfo.path, reqInfo.ip, reqInfo.userAgent, params)
 			return next(ctx)
 		})
 		srv.SetErrorPresenter(func(ctx context.Context, err error) *gqlerror.Error {
 			// LogErrorFormat "request_id=\"%s\" ip_address=\"%s\" type=\"%s\" internal_message=\"%s\" code=%d\n"
 			reqInfo := ctx.Value(config.GraphRequestInfo).(requestInfo)
-			logger.NoFilePrintf(apirouter.LogErrorFormat, reqInfo.id, reqInfo.ip, "GraphQL", err.Error(), 500)
+			services.Logger.Info().Msgf(apirouter.LogErrorFormat, reqInfo.id, reqInfo.ip, "GraphQL", err.Error(), 500)
 			return &gqlerror.Error{
 				Message: "presented: " + err.Error(),
 				Path:    graphql.GetPath(ctx),
@@ -109,16 +108,16 @@ func RegisterRoutes(router *apirouter.Router, appConfig *config.AppConfig, servi
 				),
 			)
 			if appConfig.Debug {
-				logger.Data(2, logger.DEBUG, "started graphql playground server on "+playgroundPath)
+				services.Logger.Debug().Msgf("started graphql playground server on %s", playgroundPath)
 			}
 		} else {
-			logger.Data(2, logger.ERROR, "Failed starting graphql playground server directory equals playground directory "+serverPath+" = "+playgroundPath)
+			services.Logger.Error().Msgf("Failed starting graphql playground server directory equals playground directory %s = %s", serverPath, playgroundPath)
 		}
 	}
 
 	// Success on the routes
 	if appConfig.Debug {
-		logger.Data(2, logger.DEBUG, "registered graphql routes on "+serverPath)
+		services.Logger.Debug().Msg("registered graphql routes on " + serverPath)
 	}
 }
 

actions/paymail/routes.go

@@ -4,7 +4,6 @@ import (
 	"github.com/BuxOrg/bux-server/actions"
 	"github.com/BuxOrg/bux-server/config"
 	apirouter "github.com/mrz1836/go-api-router"
-	"github.com/mrz1836/go-logger"
 )
 
 // Action is an extension of actions.Action for this package
@@ -29,6 +28,6 @@ func RegisterRoutes(router *apirouter.Router, appConfig *config.AppConfig, servi
 	router.HTTPRouter.DELETE("/"+config.CurrentMajorVersion+"/paymail", action.Request(router, requireAdmin.Wrap(action.delete)))
 
 	if appConfig.Debug {
-		logger.Data(2, logger.DEBUG, "registered paymail routes and model")
+		services.Logger.Debug().Msg("registered paymail routes and model")
 	}
 }

cmd/server/main.go

@@ -5,7 +5,6 @@ package main
 
 import (
 	"context"
-	"fmt"
 	"os"
 	"os/signal"
 	"time"
@@ -14,7 +13,7 @@ import (
 	"github.com/BuxOrg/bux-server/dictionary"
 	_ "github.com/BuxOrg/bux-server/docs"
 	"github.com/BuxOrg/bux-server/server"
-	"github.com/mrz1836/go-logger"
+	"github.com/BuxOrg/bux/logging"
 )
 
 // main method starts everything for the BUX Server
@@ -25,17 +24,18 @@ import (
 // @name bux-auth-xpub
 func main() {
 
+	defaultLogger := logging.GetDefaultLogger()
 	// Load the Application Configuration
 	appConfig, err := config.Load("")
 	if err != nil {
-		logger.Fatalf(dictionary.GetInternalMessage(dictionary.ErrorLoadingConfig), err.Error())
+		defaultLogger.Fatal().Msgf(dictionary.GetInternalMessage(dictionary.ErrorLoadingConfig), err.Error())
 		return
 	}
 
 	// Load the Application Services
 	var services *config.AppServices
 	if services, err = appConfig.LoadServices(context.Background()); err != nil {
-		logger.Fatalf(dictionary.GetInternalMessage(dictionary.ErrorLoadingService), config.ApplicationName, err.Error())
+		defaultLogger.Fatal().Msgf(dictionary.GetInternalMessage(dictionary.ErrorLoadingService), config.ApplicationName, err.Error())
 		return
 	}
 
@@ -44,22 +44,21 @@ func main() {
 
 	// Validate configuration (after services have been loaded)
 	if err = appConfig.Validate(txn); err != nil {
-		logger.Fatalf(dictionary.GetInternalMessage(dictionary.ErrorLoadingConfig), err.Error())
+		services.Logger.Fatal().Msgf(dictionary.GetInternalMessage(dictionary.ErrorLoadingConfig), err.Error())
 		return
 	}
 
 	// (debugging: show services that are enabled or not)
 	if appConfig.Debug {
-		logger.Data(2, logger.DEBUG,
-			fmt.Sprintf("datastore: %s | cachestore: %s | taskmanager: %s [%s] | new_relic: %t | paymail: %t | graphql: %t",
-				appConfig.Datastore.Engine.String(),
-				appConfig.Cachestore.Engine.String(),
-				appConfig.TaskManager.Engine.String(),
-				appConfig.TaskManager.Factory.String(),
-				appConfig.NewRelic.Enabled,
-				appConfig.Paymail.Enabled,
-				appConfig.GraphQL.Enabled,
-			),
+		services.Logger.Debug().Msgf(
+			"datastore: %s | cachestore: %s | taskmanager: %s [%s] | new_relic: %t | paymail: %t | graphql: %t",
+			appConfig.Datastore.Engine.String(),
+			appConfig.Cachestore.Engine.String(),
+			appConfig.TaskManager.Engine.String(),
+			appConfig.TaskManager.Factory.String(),
+			appConfig.NewRelic.Enabled,
+			appConfig.Paymail.Enabled,
+			appConfig.GraphQL.Enabled,
 		)
 	}
 
@@ -76,7 +75,7 @@ func main() {
 		ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
 		defer cancel()
 		if err = appServer.Shutdown(ctx); err != nil {
-			logger.Fatalf("error shutting down: %s", err.Error())
+			services.Logger.Fatal().Msgf("error shutting down: %s", err.Error())
 		}
 
 		close(idleConnectionsClosed)
@@ -86,10 +85,7 @@ func main() {
 	txn.End()
 
 	// Listen and serve
-	logger.Data(2, logger.DEBUG,
-		"starting ["+appConfig.Environment+"] "+config.ApplicationName+" server...",
-		logger.MakeParameter("port", appConfig.Server.Port),
-	)
+	services.Logger.Debug().Msgf("starting [%s] %s server at port %s...", appConfig.Environment, config.ApplicationName, appConfig.Server.Port)
 	appServer.Serve()
 
 	<-idleConnectionsClosed

config/config.go

@@ -76,6 +76,7 @@ type (
 		BroadcastClientAPIs  []string                `json:"broadcast_client_apis" mapstructure:"broadcast_client_apis"`
 		UseBeef              bool                    `json:"use_beef" mapstructure:"use_beef"`
 		Pulse                PulseConfig             `json:"pulse" mapstructure:"pulse"`
+		Logging              *LoggingConfig          `json:"logging" mapstructure:"logging"`
 	}
 
 	// AuthenticationConfig is the configuration for Authentication
@@ -182,6 +183,14 @@ type (
 		PulseURL       string `json:"pulse_url" mapstructure:"pulse_url"`
 		PulseAuthToken string `json:"pulse_auth_token" mapstructure:"pulse_auth_token"`
 	}
+
+	// LoggingConfig is a configuration for logging
+	LoggingConfig struct {
+		Level        string `json:"level" mapstructure:"level"`
+		Format       string `json:"format" mapstructure:"format"`
+		InstanceName string `json:"instance_name" mapstructure:"instance_name"`
+		LogOrigin    bool   `json:"log_origin" mapstructure:"log_origin"`
+	}
 )
 
 // GetUserAgent will return the outgoing user agent

config/envs/development.json

@@ -112,5 +112,11 @@
   "pulse": {
     "pulse_url": "http://localhost:8000/api/v1/chain/merkleroot/verify",
     "pulse_auth_token": "asd"
+  },
+  "logging": {
+    "level": "debug",
+    "format": "console",
+    "instance_name": "bux-instance-development",
+    "log_origin": false
   }
 }

config/envs/docker-compose.json

@@ -103,5 +103,11 @@
   "pulse": {
     "pulse_url": "http://localhost:8000/api/v1/chain/merkleroot/verify",
     "pulse_auth_token": "asd"
+  },
+  "logging": {
+    "level": "debug",
+    "format": "console",
+    "instance_name": "bux-instance-docker",
+    "log_origin": false
   }
 }

config/envs/production.json

@@ -104,5 +104,11 @@
   "pulse": {
     "pulse_url": "http://localhost:8000/api/v1/chain/merkleroot/verify",
     "pulse_auth_token": "asd"
+  },
+  "logging": {
+    "level": "info",
+    "format": "json",
+    "instance_name": "bux-instance-prod",
+    "log_origin": true
   }
 }

config/envs/staging.json

@@ -104,5 +104,11 @@
   "pulse": {
     "pulse_url": "http://localhost:8000/api/v1/chain/merkleroot/verify",
     "pulse_auth_token": "asd"
+  },
+  "logging": {
+    "level": "info",
+    "format": "json",
+    "instance_name": "bux-instance-staging",
+    "log_origin": true
   }
 }

config/envs/test.json

@@ -103,5 +103,11 @@
   "pulse": {
     "pulse_url": "http://localhost:8000/api/v1/chain/merkleroot/verify",
     "pulse_auth_token": "asd"
+  },
+  "logging": {
+    "level": "info",
+    "format": "json",
+    "instance_name": "bux-instance-test",
+    "log_origin": true
   }
 }

config/load.go

@@ -8,7 +8,6 @@ import (
 
 	"github.com/BuxOrg/bux-server/dictionary"
 	"github.com/mrz1836/go-datastore"
-	"github.com/mrz1836/go-logger"
 	"github.com/spf13/viper"
 )
 
@@ -37,12 +36,10 @@ var viperLock sync.Mutex
 
 // Load all environment variables
 func Load(customWorkingDirectory string) (_appConfig *AppConfig, err error) {
-
 	// Check the environment we are running
 	environment := os.Getenv(EnvironmentKey)
 	if !isValidEnvironment(environment) {
 		err = fmt.Errorf(dictionary.GetInternalMessage(dictionary.ErrorInvalidEnv), environment)
-		logger.Data(2, logger.ERROR, err.Error())
 		return
 	}
 
@@ -72,13 +69,9 @@ func Load(customWorkingDirectory string) (_appConfig *AppConfig, err error) {
 	// Read the configuration
 	if err = viper.ReadInConfig(); err != nil {
 		err = fmt.Errorf(dictionary.GetInternalMessage(dictionary.ErrorReadingConfig), err.Error())
-		logger.Data(2, logger.ERROR, err.Error())
 		return
 	}
 
-	// Log the configuration that was detected and where it was loaded from
-	logger.Data(2, logger.INFO, environment+" configuration env file processed in dir "+workingDirectory)
-
 	// Initialize
 	_appConfigVal := AppConfig{
 		Authentication: AuthenticationConfig{},
@@ -100,7 +93,6 @@ func Load(customWorkingDirectory string) (_appConfig *AppConfig, err error) {
 	// Unmarshal into values struct
 	if err = viper.Unmarshal(&_appConfigVal); err != nil {
 		err = fmt.Errorf(dictionary.GetInternalMessage(dictionary.ErrorViper), err.Error())
-		logger.Data(2, logger.ERROR, err.Error())
 		return
 	}
 

config/services.go

@@ -10,6 +10,7 @@ import (
 	"time"
 
 	"github.com/BuxOrg/bux"
+	"github.com/BuxOrg/bux-server/logging"
 	"github.com/BuxOrg/bux/chainstate"
 	"github.com/BuxOrg/bux/cluster"
 	"github.com/BuxOrg/bux/taskmanager"
@@ -18,8 +19,8 @@ import (
 	"github.com/go-redis/redis/v8"
 	"github.com/mrz1836/go-cachestore"
 	"github.com/mrz1836/go-datastore"
-	"github.com/mrz1836/go-logger"
 	"github.com/newrelic/go-agent/v3/newrelic"
+	"github.com/rs/zerolog"
 	"github.com/tonicpow/go-minercraft/v2"
 )
 
@@ -28,6 +29,7 @@ type (
 	AppServices struct {
 		Bux      bux.ClientInterface
 		NewRelic *newrelic.Application
+		Logger   *zerolog.Logger
 	}
 )
 
@@ -48,8 +50,15 @@ func (a *AppConfig) LoadServices(ctx context.Context) (*AppServices, error) {
 	ctx = newrelic.NewContext(ctx, txn)
 	defer txn.End()
 
+	logger, err := logging.CreateLogger(a.Logging.InstanceName, a.Logging.Format, a.Logging.Level, a.Logging.LogOrigin)
+	if err != nil {
+		return nil, err
+	}
+
+	_services.Logger = logger
+
 	// Load BUX
-	if err = _services.loadBux(ctx, a, false); err != nil {
+	if err = _services.loadBux(ctx, a, false, logger); err != nil {
 		return nil, err
 	}
 
@@ -74,7 +83,7 @@ func (a *AppConfig) LoadTestServices(ctx context.Context) (*AppServices, error)
 	defer txn.End()
 
 	// Load bux for testing
-	if err = _services.loadBux(ctx, a, true); err != nil {
+	if err = _services.loadBux(ctx, a, true, _services.Logger); err != nil {
 		return nil, err
 	}
 
@@ -124,11 +133,13 @@ func (s *AppServices) CloseAll(ctx context.Context) {
 	}
 
 	// All services closed!
-	logger.Data(2, logger.DEBUG, "all services have been closed")
+	if s.Logger != nil {
+		s.Logger.Debug().Msg("all services have been closed")
+	}
 }
 
 // loadBux will load the bux client (including CacheStore and DataStore)
-func (s *AppServices) loadBux(ctx context.Context, appConfig *AppConfig, testMode bool) (err error) {
+func (s *AppServices) loadBux(ctx context.Context, appConfig *AppConfig, testMode bool, logger *zerolog.Logger) (err error) {
 	var options []bux.ClientOps
 
 	// Set new relic if enabled
@@ -149,7 +160,10 @@ func (s *AppServices) loadBux(ctx context.Context, appConfig *AppConfig, testMod
 		options = append(options, bux.WithImportBlockHeaders(appConfig.ImportBlockHeaders))
 	}
 
-	// todo: customize the logger
+	if logger != nil {
+		buxLogger := logger.With().Str("service", "bux").Logger()
+		options = append(options, bux.WithLogger(&buxLogger))
+	}
 
 	// todo: feature: override the config from JSON env (side-load your own /envs/custom-config.json