log: fix bug, expand test coverage and slightly optimize (thrasher-co…

…rp#847)

* log: fix bugs expand coverage and optimise

* log: fix linter issues

* log: fix linter issue and pack methods in same file

* log: drop defer

* logger: move global check inside getfields  and remove unused test function

* logger: Increase note thanks @gloriousCode

* logger: wrap error with writer type

* logger: change variable name

* logger: change variable names and remove validsublogger func as it doesn't add functionality over a standard map call

* logs: error when unsupported output is applied on setup calls

* logs: add glorious suggestion

* logger: add protection to reduce olympic gold medal races

* logger: fix linter issues

* log: glorious niterinos

backtester/data/kline/database/database_test.go

@@ -30,7 +30,11 @@ const (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 	var err error
 	testhelpers.PostgresTestDatabase = testhelpers.GetConnectionDetails()

backtester/main.go

@@ -64,9 +64,12 @@ func main() {
 
 	var bt *backtest.BackTest
 	var cfg *config.Config
-	logConfig := log.GenDefaultSettings()
-	log.GlobalLogConfig = &logConfig
-	log.SetupGlobalLogger()
+	log.GlobalLogConfig = log.GenDefaultSettings()
+	err = log.SetupGlobalLogger()
+	if err != nil {
+		fmt.Printf("Could not setup global logger. Error: %v.\n", err)
+		os.Exit(1)
+	}
 
 	cfg, err = config.ReadConfigFromFile(configPath)
 	if err != nil {

cmd/apichecker/apicheck.go

@@ -101,11 +101,14 @@ func main() {
 	flag.BoolVar(&create, "create", false, "specifies whether to automatically create trello list, card and checklist in a given board")
 	flag.Parse()
 	var err error
-	c := log.GenDefaultSettings()
 	log.RWM.Lock()
-	log.GlobalLogConfig = &c
+	log.GlobalLogConfig = log.GenDefaultSettings()
 	log.RWM.Unlock()
-	log.SetupGlobalLogger()
+	err = log.SetupGlobalLogger()
+	if err != nil {
+		fmt.Printf("Could not setup global logger. Error: %v.\n", err)
+		os.Exit(1)
+	}
 	configData, err = readFileData(jsonFile)
 	if err != nil {
 		log.Error(log.Global, err)

cmd/apichecker/apicheck_test.go

@@ -29,7 +29,7 @@ func TestMain(m *testing.M) {
 	c := log.GenDefaultSettings()
 	c.Enabled = convert.BoolPtr(true)
 	log.RWM.Lock()
-	log.GlobalLogConfig = &c
+	log.GlobalLogConfig = c
 	log.RWM.Unlock()
 	log.Infoln(log.Global, "set verbose to true for more detailed output")
 	var err error

config/config.go

@@ -1267,7 +1267,7 @@ func (c *Config) CheckLoggerConfig() error {
 	defer m.Unlock()
 
 	if c.Logging.Enabled == nil || c.Logging.Output == "" {
-		c.Logging = log.GenDefaultSettings()
+		c.Logging = *log.GenDefaultSettings()
 	}
 
 	if c.Logging.AdvancedSettings.ShowLogSystemName == nil {

database/repository/candle/candle_test.go

@@ -30,7 +30,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 
 	var err error

database/repository/datahistoryjob/datahistoryjob_test.go

@@ -33,7 +33,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 	var err error
 	testhelpers.PostgresTestDatabase = testhelpers.GetConnectionDetails()

database/repository/datahistoryjobresult/datahistoryjobresult_test.go

@@ -30,7 +30,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 	var err error
 	testhelpers.PostgresTestDatabase = testhelpers.GetConnectionDetails()

database/repository/exchange/exchange_test.go

@@ -30,7 +30,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 
 	var err error

database/repository/script/script_test.go

@@ -28,7 +28,11 @@ func TestMain(m *testing.M) {
 	}
 
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err = testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 
 	t := m.Run()

database/repository/trade/trade_test.go

@@ -33,7 +33,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 	var err error
 	testhelpers.PostgresTestDatabase = testhelpers.GetConnectionDetails()

database/repository/withdraw/withdraw_test.go

@@ -29,7 +29,11 @@ var (
 
 func TestMain(m *testing.M) {
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 
 	var err error

database/testhelpers/test_helpers.go

@@ -118,14 +118,15 @@ func migrateDB(db *sql.DB) error {
 }
 
 // EnableVerboseTestOutput enables debug output for SQL queries
-func EnableVerboseTestOutput() {
-	c := log.GenDefaultSettings()
+func EnableVerboseTestOutput() error {
 	log.RWM.Lock()
-	log.GlobalLogConfig = &c
+	log.GlobalLogConfig = log.GenDefaultSettings()
 	log.RWM.Unlock()
-	log.SetupGlobalLogger()
-
+	if err := log.SetupGlobalLogger(); err != nil {
+		return err
+	}
 	DBLogger := database.Logger{}
 	boil.DebugMode = true
 	boil.DebugWriter = DBLogger
+	return nil
 }

engine/engine.go

@@ -84,12 +84,18 @@ func NewFromSettings(settings *Settings, flagSet map[string]bool) (*Engine, erro
 
 	b.Config, err = loadConfigWithSettings(settings, flagSet)
 	if err != nil {
-		return nil, fmt.Errorf("failed to load config. Err: %s", err)
+		return nil, fmt.Errorf("failed to load config. Err: %w", err)
 	}
 
 	if *b.Config.Logging.Enabled {
-		gctlog.SetupGlobalLogger()
-		gctlog.SetupSubLoggers(b.Config.Logging.SubLoggers)
+		err = gctlog.SetupGlobalLogger()
+		if err != nil {
+			return nil, fmt.Errorf("failed to setup global logger. %w", err)
+		}
+		err = gctlog.SetupSubLoggers(b.Config.Logging.SubLoggers)
+		if err != nil {
+			return nil, fmt.Errorf("failed to setup sub loggers. %w", err)
+		}
 		gctlog.Infoln(gctlog.Global, "Logger initialised.")
 	}
 
@@ -99,12 +105,12 @@ func NewFromSettings(settings *Settings, flagSet map[string]bool) (*Engine, erro
 
 	err = utils.AdjustGoMaxProcs(settings.GoMaxProcs)
 	if err != nil {
-		return nil, fmt.Errorf("unable to adjust runtime GOMAXPROCS value. Err: %s", err)
+		return nil, fmt.Errorf("unable to adjust runtime GOMAXPROCS value. Err: %w", err)
 	}
 
 	b.gctScriptManager, err = gctscript.NewManager(&b.Config.GCTScript)
 	if err != nil {
-		return nil, fmt.Errorf("failed to create script manager. Err: %s", err)
+		return nil, fmt.Errorf("failed to create script manager. Err: %w", err)
 	}
 
 	b.ExchangeManager = SetupExchangeManager()

exchanges/exchange_test.go

@@ -3,6 +3,7 @@ package exchange
 import (
 	"context"
 	"errors"
+	"fmt"
 	"net"
 	"net/http"
 	"os"
@@ -29,11 +30,13 @@ const (
 )
 
 func TestMain(m *testing.M) {
-	c := log.GenDefaultSettings()
 	log.RWM.Lock()
-	log.GlobalLogConfig = &c
+	log.GlobalLogConfig = log.GenDefaultSettings()
 	log.RWM.Unlock()
-	log.SetupGlobalLogger()
+	if err := log.SetupGlobalLogger(); err != nil {
+		fmt.Println("Cannot setup global logger. Error:", err)
+		os.Exit(1)
+	}
 	os.Exit(m.Run())
 }
 

exchanges/kline/kline_test.go

@@ -2,6 +2,7 @@ package kline
 
 import (
 	"errors"
+	"fmt"
 	"io/ioutil"
 	"math/rand"
 	"os"
@@ -511,7 +512,11 @@ func TestItem_SortCandlesByTimestamp(t *testing.T) {
 func setupTest(t *testing.T) {
 	t.Helper()
 	if verbose {
-		testhelpers.EnableVerboseTestOutput()
+		err := testhelpers.EnableVerboseTestOutput()
+		if err != nil {
+			fmt.Printf("failed to enable verbose test output: %v", err)
+			os.Exit(1)
+		}
 	}
 
 	var err error

gctscript/vm/vm_test.go

@@ -33,7 +33,7 @@ func TestMain(m *testing.M) {
 	c := log.GenDefaultSettings()
 	c.Enabled = convert.BoolPtr(false)
 	log.RWM.Lock()
-	log.GlobalLogConfig = &c
+	log.GlobalLogConfig = c
 	log.RWM.Unlock()
 	os.Exit(m.Run())
 }

log/logger.go

@@ -4,7 +4,6 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"strings"
 	"time"
 )
 
@@ -13,28 +12,8 @@ var (
 	errSubLoggerAlreadyregistered = errors.New("sub logger already registered")
 )
 
-// NewSubLogger allows for a new sub logger to be registered.
-func NewSubLogger(name string) (*SubLogger, error) {
-	if name == "" {
-		return nil, errEmptyLoggerName
-	}
-	name = strings.ToUpper(name)
-	if _, ok := SubLoggers[name]; ok {
-		return nil, errSubLoggerAlreadyregistered
-	}
-	return registerNewSubLogger(name), nil
-}
-
-// SetOutput overrides the default output with a new writer
-func (s *SubLogger) SetOutput(o io.Writer) {
-	RWM.Lock()
-	defer RWM.Unlock()
-
-	s.output = o
-}
-
-func newLogger(c *Config) *Logger {
-	return &Logger{
+func newLogger(c *Config) Logger {
+	return Logger{
 		Timestamp:         c.AdvancedSettings.TimeStampFormat,
 		Spacer:            c.AdvancedSettings.Spacer,
 		ErrorHeader:       c.AdvancedSettings.Headers.Error,
@@ -50,29 +29,28 @@ func (l *Logger) newLogEvent(data, header, slName string, w io.Writer) error {
 		return errors.New("io.Writer not set")
 	}
 
-	e, ok := eventPool.Get().(*Event)
+	pool, ok := eventPool.Get().(*[]byte)
 	if !ok {
-		return errors.New("unable to type asset event")
+		return errors.New("unable to type assert slice of bytes pointer")
 	}
-	e.output = w
-	e.data = append(e.data, []byte(header)...)
+
+	*pool = append(*pool, header...)
 	if l.ShowLogSystemName {
-		e.data = append(e.data, l.Spacer...)
-		e.data = append(e.data, slName...)
+		*pool = append(*pool, l.Spacer...)
+		*pool = append(*pool, slName...)
 	}
-	e.data = append(e.data, l.Spacer...)
+	*pool = append(*pool, l.Spacer...)
 	if l.Timestamp != "" {
-		e.data = time.Now().AppendFormat(e.data, l.Timestamp)
+		*pool = time.Now().AppendFormat(*pool, l.Timestamp)
 	}
-	e.data = append(e.data, l.Spacer...)
-	e.data = append(e.data, []byte(data)...)
+	*pool = append(*pool, l.Spacer...)
+	*pool = append(*pool, data...)
 	if data == "" || data[len(data)-1] != '\n' {
-		e.data = append(e.data, '\n')
+		*pool = append(*pool, '\n')
 	}
-	_, err := e.output.Write(e.data)
-
-	e.data = e.data[:0]
-	eventPool.Put(e)
+	_, err := w.Write(*pool)
+	*pool = (*pool)[:0]
+	eventPool.Put(pool)
 
 	return err
 }
@@ -82,30 +60,25 @@ func CloseLogger() error {
 	return GlobalLogFile.Close()
 }
 
-func validSubLogger(s string) (bool, *SubLogger) {
-	if v, found := SubLoggers[s]; found {
-		return true, v
-	}
-	return false, nil
-}
-
 // Level retries the current sublogger levels
-func Level(s string) (*Levels, error) {
-	found, logger := validSubLogger(s)
+func Level(name string) (Levels, error) {
+	RWM.RLock()
+	defer RWM.RUnlock()
+	subLogger, found := SubLoggers[name]
 	if !found {
-		return nil, fmt.Errorf("logger %v not found", s)
+		return Levels{}, fmt.Errorf("logger %s not found", name)
 	}
-
-	return &logger.Levels, nil
+	return subLogger.levels, nil
 }
 
 // SetLevel sets sublogger levels
-func SetLevel(s, level string) (*Levels, error) {
-	found, logger := validSubLogger(s)
+func SetLevel(s, level string) (Levels, error) {
+	RWM.Lock()
+	defer RWM.Unlock()
+	subLogger, found := SubLoggers[s]
 	if !found {
-		return nil, fmt.Errorf("logger %v not found", s)
+		return Levels{}, fmt.Errorf("sub logger %v not found", s)
 	}
-	logger.Levels = splitLevel(level)
-
-	return &logger.Levels, nil
+	subLogger.SetLevels(splitLevel(level))
+	return subLogger.levels, nil
 }