Merge pull request #12 from Neur0toxine/master

improvements for logging

core/engine.go

@@ -3,6 +3,7 @@ package core
 import (
 	"html/template"
 	"net/http"
+	"sync"
 
 	"github.com/gin-gonic/gin"
 	"github.com/gobuffalo/packr/v2"
@@ -19,7 +20,8 @@ type Engine struct {
 	Utils
 	ginEngine    *gin.Engine
 	httpClient   *http.Client
-	Logger       *logging.Logger
+	logger       LoggerInterface
+	mutex        sync.RWMutex
 	csrf         *CSRF
 	jobManager   *JobManager
 	Sessions     sessions.Store
@@ -37,7 +39,8 @@ func New() *Engine {
 		Sentry:    Sentry{},
 		Utils:     Utils{},
 		ginEngine: nil,
-		Logger:    nil,
+		logger:    nil,
+		mutex:     sync.RWMutex{},
 		prepared:  false,
 	}
 }
@@ -84,10 +87,10 @@ func (e *Engine) Prepare() *Engine {
 	e.createDB(e.Config.GetDBConfig())
 	e.createRavenClient(e.Config.GetSentryDSN())
 	e.resetUtils(e.Config.GetAWSConfig(), e.Config.IsDebug(), 0)
-	e.Logger = NewLogger(e.Config.GetTransportInfo().GetCode(), e.Config.GetLogLevel(), e.LogFormatter)
+	e.SetLogger(NewLogger(e.Config.GetTransportInfo().GetCode(), e.Config.GetLogLevel(), e.LogFormatter))
 	e.Sentry.Localizer = &e.Localizer
-	e.Utils.Logger = e.Logger
+	e.Utils.Logger = e.Logger()
-	e.Sentry.Logger = e.Logger
+	e.Sentry.Logger = e.Logger()
 	e.prepared = true
 
 	return e
@@ -138,17 +141,34 @@ func (e *Engine) Router() *gin.Engine {
 // JobManager will return singleton JobManager from Engine
 func (e *Engine) JobManager() *JobManager {
 	if e.jobManager == nil {
-		e.jobManager = NewJobManager().SetLogger(e.Logger).SetLogging(e.Config.IsDebug())
+		e.jobManager = NewJobManager().SetLogger(e.Logger()).SetLogging(e.Config.IsDebug())
 	}
 
 	return e.jobManager
 }
 
+// Logger returns current logger
+func (e *Engine) Logger() LoggerInterface {
+	return e.logger
+}
+
+// SetLogger sets provided logger instance to engine
+func (e *Engine) SetLogger(l LoggerInterface) *Engine {
+	if l == nil {
+		return e
+	}
+
+	e.mutex.Lock()
+	defer e.mutex.Unlock()
+	e.logger = l
+	return e
+}
+
 // BuildHTTPClient builds HTTP client with provided configuration
 func (e *Engine) BuildHTTPClient(replaceDefault ...bool) *Engine {
 	if e.Config.GetHTTPClientConfig() != nil {
 		client, err := NewHTTPClientBuilder().
-			WithLogger(e.Logger).
+			WithLogger(e.Logger()).
 			SetLogging(e.Config.IsDebug()).
 			FromEngine(e).Build(replaceDefault...)
 

core/engine_test.go

@@ -173,27 +173,6 @@ func (e *EngineTest) Test_BuildHTTPClient() {
 	assert.NotNil(e.T(), e.engine.httpClient)
 }
 
-func (e *EngineTest) Test_SetHTTPClient() {
-	var err error
-
-	e.engine.httpClient = nil
-	e.engine.httpClient, err = NewHTTPClientBuilder().Build()
-
-	assert.NoError(e.T(), err)
-	assert.NotNil(e.T(), e.engine.httpClient)
-}
-
-func (e *EngineTest) Test_HTTPClient() {
-	var err error
-
-	e.engine.httpClient = nil
-	assert.NotNil(e.T(), e.engine.HTTPClient())
-
-	e.engine.httpClient, err = NewHTTPClientBuilder().Build()
-	assert.NoError(e.T(), err)
-	assert.NotNil(e.T(), e.engine.httpClient)
-}
-
 func (e *EngineTest) Test_WithCookieSessions() {
 	e.engine.Sessions = nil
 	e.engine.WithCookieSessions(4)
@@ -208,6 +187,44 @@ func (e *EngineTest) Test_WithFilesystemSessions() {
 	assert.NotNil(e.T(), e.engine.Sessions)
 }
 
+func (e *EngineTest) Test_SetLogger() {
+	origLogger := e.engine.logger
+	defer func() {
+		e.engine.logger = origLogger
+	}()
+	e.engine.logger = &Logger{}
+	e.engine.SetLogger(nil)
+	assert.NotNil(e.T(), e.engine.logger)
+}
+
+func (e *EngineTest) Test_SetHTTPClient() {
+	origClient := e.engine.httpClient
+	defer func() {
+		e.engine.httpClient = origClient
+	}()
+	e.engine.httpClient = nil
+	httpClient, err := NewHTTPClientBuilder().Build()
+	require.NoError(e.T(), err)
+	assert.NotNil(e.T(), httpClient)
+	e.engine.SetHTTPClient(&http.Client{})
+	require.NotNil(e.T(), e.engine.httpClient)
+	e.engine.SetHTTPClient(nil)
+	assert.NotNil(e.T(), e.engine.httpClient)
+}
+
+func (e *EngineTest) Test_HTTPClient() {
+	origClient := e.engine.httpClient
+	defer func() {
+		e.engine.httpClient = origClient
+	}()
+	e.engine.httpClient = nil
+	require.Same(e.T(), http.DefaultClient, e.engine.HTTPClient())
+	httpClient, err := NewHTTPClientBuilder().Build()
+	require.NoError(e.T(), err)
+	e.engine.httpClient = httpClient
+	assert.Same(e.T(), httpClient, e.engine.HTTPClient())
+}
+
 func (e *EngineTest) Test_InitCSRF_Fail() {
 	defer func() {
 		assert.NotNil(e.T(), recover())

core/http_client_builder.go

@@ -8,7 +8,6 @@ import (
 	"net/http"
 	"time"
 
-	"github.com/op/go-logging"
 	"github.com/pkg/errors"
 )
 
@@ -46,7 +45,7 @@ type HTTPClientBuilder struct {
 	httpClient    *http.Client
 	httpTransport *http.Transport
 	dialer        *net.Dialer
-	logger        *logging.Logger
+	logger        LoggerInterface
 	built         bool
 	logging       bool
 	timeout       time.Duration
@@ -70,7 +69,7 @@ func NewHTTPClientBuilder() *HTTPClientBuilder {
 }
 
 // WithLogger sets provided logger into HTTPClientBuilder
-func (b *HTTPClientBuilder) WithLogger(logger *logging.Logger) *HTTPClientBuilder {
+func (b *HTTPClientBuilder) WithLogger(logger LoggerInterface) *HTTPClientBuilder {
 	if logger != nil {
 		b.logger = logger
 	}

core/job_manager.go

@@ -52,7 +52,7 @@ type Job struct {
 type JobManager struct {
 	jobs          *sync.Map
 	enableLogging bool
-	logger        *logging.Logger
+	logger        LoggerInterface
 }
 
 // getWrappedFunc wraps job into function
@@ -143,7 +143,7 @@ func DefaultJobPanicHandler() JobPanicHandler {
 }
 
 // SetLogger sets logger into JobManager
-func (j *JobManager) SetLogger(logger *logging.Logger) *JobManager {
+func (j *JobManager) SetLogger(logger LoggerInterface) *JobManager {
 	if logger != nil {
 		j.logger = logger
 	}

core/job_manager_test.go

@@ -324,10 +324,10 @@ func (t *JobManagerTest) ranFlag() bool {
 func (t *JobManagerTest) Test_SetLogger() {
 	t.manager.logger = nil
 	t.manager.SetLogger(NewLogger("test", logging.ERROR, DefaultLogFormatter()))
-	assert.IsType(t.T(), &logging.Logger{}, t.manager.logger)
+	assert.IsType(t.T(), &Logger{}, t.manager.logger)
 
 	t.manager.SetLogger(nil)
-	assert.IsType(t.T(), &logging.Logger{}, t.manager.logger)
+	assert.IsType(t.T(), &Logger{}, t.manager.logger)
 }
 
 func (t *JobManagerTest) Test_SetLogging() {

core/localizer.go

@@ -39,6 +39,23 @@ func NewLocalizer(locale language.Tag, bundle *i18n.Bundle, matcher language.Mat
 	return localizer
 }
 
+// NewLocalizerFS returns localizer instance with specified parameters. *packr.Box should be used instead of directory.
+// Usage:
+//      NewLocalizerFS(language.English, DefaultLocalizerBundle(), DefaultLocalizerMatcher(), translationsBox)
+// TODO This code should be covered with tests.
+func NewLocalizerFS(locale language.Tag, bundle *i18n.Bundle, matcher language.Matcher, translationsBox *packr.Box) *Localizer {
+	localizer := &Localizer{
+		i18n:            nil,
+		LocaleBundle:    bundle,
+		LocaleMatcher:   matcher,
+		TranslationsBox: translationsBox,
+	}
+	localizer.SetLanguage(locale)
+	localizer.LoadTranslations()
+
+	return localizer
+}
+
 // DefaultLocalizerBundle returns new localizer bundle with English as default language
 func DefaultLocalizerBundle() *i18n.Bundle {
 	return i18n.NewBundle(language.English)

core/logger.go

@@ -2,14 +2,49 @@ package core
 
 import (
 	"os"
+	"sync"
 
 	"github.com/op/go-logging"
 )
 
-// NewLogger will create new logger with specified formatter.
+// LoggerInterface contains methods which should be present in logger implementation
+type LoggerInterface interface {
+	Fatal(args ...interface{})
+	Fatalf(format string, args ...interface{})
+	Panic(args ...interface{})
+	Panicf(format string, args ...interface{})
+	Critical(args ...interface{})
+	Criticalf(format string, args ...interface{})
+	Error(args ...interface{})
+	Errorf(format string, args ...interface{})
+	Warning(args ...interface{})
+	Warningf(format string, args ...interface{})
+	Notice(args ...interface{})
+	Noticef(format string, args ...interface{})
+	Info(args ...interface{})
+	Infof(format string, args ...interface{})
+	Debug(args ...interface{})
+	Debugf(format string, args ...interface{})
+}
+
+// Logger component. Uses github.com/op/go-logging under the hood.
+// This logger can prevent any write operations (disabled by default, use .Exclusive() method to enable)
+type Logger struct {
+	logger *logging.Logger
+	mutex  *sync.RWMutex
+}
+
+// NewLogger will create new goroutine-safe logger with specified formatter.
 // Usage:
 //	    logger := NewLogger("telegram", logging.ERROR, DefaultLogFormatter())
-func NewLogger(transportCode string, logLevel logging.Level, logFormat logging.Formatter) *logging.Logger {
+func NewLogger(transportCode string, logLevel logging.Level, logFormat logging.Formatter) *Logger {
+	return &Logger{
+		logger: newInheritedLogger(transportCode, logLevel, logFormat),
+	}
+}
+
+// newInheritedLogger is a constructor for underlying logger in Logger struct.
+func newInheritedLogger(transportCode string, logLevel logging.Level, logFormat logging.Formatter) *logging.Logger {
 	logger := logging.MustGetLogger(transportCode)
 	logBackend := logging.NewLogBackend(os.Stdout, "", 0)
 	formatBackend := logging.NewBackendFormatter(logBackend, logFormat)
@@ -26,3 +61,138 @@ func DefaultLogFormatter() logging.Formatter {
 		`%{time:2006-01-02 15:04:05.000} %{level:.4s} => %{message}`,
 	)
 }
+
+// Exclusive makes logger goroutine-safe
+func (l *Logger) Exclusive() *Logger {
+	if l.mutex == nil {
+		l.mutex = &sync.RWMutex{}
+	}
+
+	return l
+}
+
+// lock locks logger
+func (l *Logger) lock() {
+	if l.mutex != nil {
+		l.mutex.Lock()
+	}
+}
+
+// unlock unlocks logger
+func (l *Logger) unlock() {
+	if l.mutex != nil {
+		l.mutex.Unlock()
+	}
+}
+
+// Fatal is equivalent to l.Critical(fmt.Sprint()) followed by a call to os.Exit(1).
+func (l *Logger) Fatal(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Fatal(args...)
+}
+
+// Fatalf is equivalent to l.Critical followed by a call to os.Exit(1).
+func (l *Logger) Fatalf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Fatalf(format, args...)
+}
+
+// Panic is equivalent to l.Critical(fmt.Sprint()) followed by a call to panic().
+func (l *Logger) Panic(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Panic(args...)
+}
+
+// Panicf is equivalent to l.Critical followed by a call to panic().
+func (l *Logger) Panicf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Panicf(format, args...)
+}
+
+// Critical logs a message using CRITICAL as log level.
+func (l *Logger) Critical(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Critical(args...)
+}
+
+// Criticalf logs a message using CRITICAL as log level.
+func (l *Logger) Criticalf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Criticalf(format, args...)
+}
+
+// Error logs a message using ERROR as log level.
+func (l *Logger) Error(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Error(args...)
+}
+
+// Errorf logs a message using ERROR as log level.
+func (l *Logger) Errorf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Errorf(format, args...)
+}
+
+// Warning logs a message using WARNING as log level.
+func (l *Logger) Warning(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Warning(args...)
+}
+
+// Warningf logs a message using WARNING as log level.
+func (l *Logger) Warningf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Warningf(format, args...)
+}
+
+// Notice logs a message using NOTICE as log level.
+func (l *Logger) Notice(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Notice(args...)
+}
+
+// Noticef logs a message using NOTICE as log level.
+func (l *Logger) Noticef(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Noticef(format, args...)
+}
+
+// Info logs a message using INFO as log level.
+func (l *Logger) Info(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Info(args...)
+}
+
+// Infof logs a message using INFO as log level.
+func (l *Logger) Infof(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Infof(format, args...)
+}
+
+// Debug logs a message using DEBUG as log level.
+func (l *Logger) Debug(args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Debug(args...)
+}
+
+// Debugf logs a message using DEBUG as log level.
+func (l *Logger) Debugf(format string, args ...interface{}) {
+	l.lock()
+	defer l.unlock()
+	l.logger.Debugf(format, args...)
+}

core/logger_test.go

@@ -1,15 +1,22 @@
 package core
 
 import (
+	// "os"
+	// "os/exec"
 	"testing"
 
 	"github.com/op/go-logging"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/suite"
 )
 
+type LoggerTest struct {
+	suite.Suite
+	logger *Logger
+}
+
 func TestLogger_NewLogger(t *testing.T) {
 	logger := NewLogger("code", logging.DEBUG, DefaultLogFormatter())
-
 	assert.NotNil(t, logger)
 }
 
@@ -19,3 +26,96 @@ func TestLogger_DefaultLogFormatter(t *testing.T) {
 	assert.NotNil(t, formatter)
 	assert.IsType(t, logging.MustStringFormatter(`%{message}`), formatter)
 }
+
+func Test_Logger(t *testing.T) {
+	suite.Run(t, new(LoggerTest))
+}
+
+func (t *LoggerTest) SetupSuite() {
+	t.logger = NewLogger("code", logging.DEBUG, DefaultLogFormatter()).Exclusive()
+}
+
+// TODO Cover Fatal and Fatalf (implementation below is no-op)
+// func (t *LoggerTest) Test_Fatal() {
+// 	if os.Getenv("FLAG") == "1" {
+// 		t.logger.Fatal("test", "fatal")
+// 		return
+// 	}
+
+// 	cmd := exec.Command(os.Args[0], "-test.run=TestGetConfig")
+// 	cmd.Env = append(os.Environ(), "FLAG=1")
+// 	err := cmd.Run()
+
+// 	e, ok := err.(*exec.ExitError)
+// 	expectedErrorString := "test fatal"
+// 	assert.Equal(t.T(), true, ok)
+// 	assert.Equal(t.T(), expectedErrorString, e.Error())
+// }
+
+func (t *LoggerTest) Test_Panic() {
+	defer func() {
+		assert.NotNil(t.T(), recover())
+	}()
+	t.logger.Panic("panic")
+}
+
+func (t *LoggerTest) Test_Panicf() {
+	defer func() {
+		assert.NotNil(t.T(), recover())
+	}()
+	t.logger.Panicf("panic")
+}
+
+func (t *LoggerTest) Test_Critical() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Critical("critical")
+}
+
+func (t *LoggerTest) Test_Criticalf() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Criticalf("critical")
+}
+
+func (t *LoggerTest) Test_Warning() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Warning("warning")
+}
+
+func (t *LoggerTest) Test_Notice() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Notice("notice")
+}
+
+func (t *LoggerTest) Test_Info() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Info("info")
+}
+
+func (t *LoggerTest) Test_Debug() {
+	defer func() {
+		if v := recover(); v != nil {
+			t.T().Fatal(v)
+		}
+	}()
+	t.logger.Debug("debug")
+}

core/sentry.go

@@ -13,7 +13,6 @@ import (
 
 	"github.com/getsentry/raven-go"
 	"github.com/gin-gonic/gin"
-	"github.com/op/go-logging"
 )
 
 // ErrorHandlerFunc will handle errors
@@ -39,7 +38,7 @@ type Sentry struct {
 	Stacktrace   bool
 	DefaultError string
 	Localizer    *Localizer
-	Logger       *logging.Logger
+	Logger       LoggerInterface
 	Client       *raven.Client
 }
 
@@ -57,7 +56,7 @@ type SentryTaggedScalar struct {
 }
 
 // NewSentry constructor
-func NewSentry(sentryDSN string, defaultError string, taggedTypes SentryTaggedTypes, logger *logging.Logger, localizer *Localizer) *Sentry {
+func NewSentry(sentryDSN string, defaultError string, taggedTypes SentryTaggedTypes, logger LoggerInterface, localizer *Localizer) *Sentry {
 	sentry := &Sentry{
 		DefaultError: defaultError,
 		TaggedTypes:  taggedTypes,

core/utils.go

@@ -17,7 +17,6 @@ import (
 	"github.com/aws/aws-sdk-go/aws/credentials"
 	"github.com/aws/aws-sdk-go/aws/session"
 	"github.com/aws/aws-sdk-go/service/s3/s3manager"
-	"github.com/op/go-logging"
 	v5 "github.com/retailcrm/api-client-go/v5"
 	v1 "github.com/retailcrm/mg-transport-api-client-go/v1"
 )
@@ -27,12 +26,12 @@ type Utils struct {
 	IsDebug      bool
 	TokenCounter uint32
 	ConfigAWS    ConfigAWS
-	Logger       *logging.Logger
+	Logger       LoggerInterface
 	slashRegex   *regexp.Regexp
 }
 
 // NewUtils will create new Utils instance
-func NewUtils(awsConfig ConfigAWS, logger *logging.Logger, debug bool) *Utils {
+func NewUtils(awsConfig ConfigAWS, logger LoggerInterface, debug bool) *Utils {
 	return &Utils{
 		IsDebug:      debug,
 		ConfigAWS:    awsConfig,

go.sum

@@ -215,6 +215,7 @@ github.com/spf13/jwalterweatherman v1.0.0/go.mod h1:cQK4TGJAtQXfYWX+Ddv3mKDzgVb6
 github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4=
 github.com/spf13/viper v1.3.2/go.mod h1:ZiWeW+zYFKm7srdB9IoDzzZXaJaI5eL9QjNiN/DMA2s=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/objx v0.1.1 h1:2vfRuCMp5sSVIDSqO8oNnWJq7mPa6KVP3iPIwFBuy8A=
 github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=