From 9ad220967e34af2c54e83279a9add13536dca4fb Mon Sep 17 00:00:00 2001 From: Pavel Date: Wed, 25 Dec 2019 17:36:02 +0300 Subject: [PATCH 1/6] allow alternative logger implementations --- core/engine.go | 2 +- core/http_client_builder.go | 5 +- core/job_manager.go | 4 +- core/job_manager_test.go | 4 +- core/localizer.go | 17 ++++ core/logger.go | 150 +++++++++++++++++++++++++++++++++++- core/sentry.go | 5 +- core/utils.go | 5 +- 8 files changed, 176 insertions(+), 16 deletions(-) diff --git a/core/engine.go b/core/engine.go index 2de7c2f..c8c051f 100644 --- a/core/engine.go +++ b/core/engine.go @@ -19,7 +19,7 @@ type Engine struct { Utils ginEngine *gin.Engine httpClient *http.Client - Logger *logging.Logger + Logger LoggerInterface csrf *CSRF jobManager *JobManager Sessions sessions.Store diff --git a/core/http_client_builder.go b/core/http_client_builder.go index 41d1731..5dc6963 100644 --- a/core/http_client_builder.go +++ b/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 } diff --git a/core/job_manager.go b/core/job_manager.go index 76bd8d1..a24540c 100644 --- a/core/job_manager.go +++ b/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 } diff --git a/core/job_manager_test.go b/core/job_manager_test.go index fc994dc..5ca079a 100644 --- a/core/job_manager_test.go +++ b/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() { diff --git a/core/localizer.go b/core/localizer.go index 321f492..e06d891 100644 --- a/core/localizer.go +++ b/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) diff --git a/core/logger.go b/core/logger.go index 7c16627..0e9ea1c 100644 --- a/core/logger.go +++ b/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. +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), + mutex: &sync.RWMutex{}, + } +} + +// 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,114 @@ func DefaultLogFormatter() logging.Formatter { `%{time:2006-01-02 15:04:05.000} %{level:.4s} => %{message}`, ) } + +// Fatal is equivalent to l.Critical(fmt.Sprint()) followed by a call to os.Exit(1). +func (l *Logger) Fatal(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.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.mutex.Lock() + defer l.mutex.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.mutex.Lock() + defer l.mutex.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.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Panicf(format, args...) +} + +// Critical logs a message using CRITICAL as log level. +func (l *Logger) Critical(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Critical(args...) +} + +// Criticalf logs a message using CRITICAL as log level. +func (l *Logger) Criticalf(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Criticalf(format, args...) +} + +// Error logs a message using ERROR as log level. +func (l *Logger) Error(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Error(args...) +} + +// Errorf logs a message using ERROR as log level. +func (l *Logger) Errorf(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Errorf(format, args...) +} + +// Warning logs a message using WARNING as log level. +func (l *Logger) Warning(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Warning(args...) +} + +func (l *Logger) Warningf(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Warningf(format, args...) +} + +// Warningf logs a message using WARNING as log level. +func (l *Logger) Notice(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Notice(args...) +} + +// Noticef logs a message using NOTICE as log level. +func (l *Logger) Noticef(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Noticef(format, args...) +} + +// Info logs a message using INFO as log level. +func (l *Logger) Info(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Info(args...) +} + +// Infof logs a message using INFO as log level. +func (l *Logger) Infof(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Infof(format, args...) +} + +// Debug logs a message using DEBUG as log level. +func (l *Logger) Debug(args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Debug(args...) +} + +// Debugf logs a message using DEBUG as log level. +func (l *Logger) Debugf(format string, args ...interface{}) { + l.mutex.Lock() + defer l.mutex.Unlock() + l.logger.Debugf(format, args...) +} diff --git a/core/sentry.go b/core/sentry.go index 377062a..637251a 100644 --- a/core/sentry.go +++ b/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, diff --git a/core/utils.go b/core/utils.go index c0161e6..a963f1e 100644 --- a/core/utils.go +++ b/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, From 990f4f06974f4bbd7478614b7287a3290e8cb88e Mon Sep 17 00:00:00 2001 From: Pavel Date: Thu, 26 Dec 2019 16:26:38 +0300 Subject: [PATCH 2/6] logger accessor via mutex --- core/engine.go | 40 +++++++++++++++++++++++++++++++++------- core/logger.go | 4 ++-- 2 files changed, 35 insertions(+), 9 deletions(-) diff --git a/core/engine.go b/core/engine.go index c8c051f..c71a60e 100644 --- a/core/engine.go +++ b/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 LoggerInterface + 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.Sentry.Logger = e.Logger + e.Utils.Logger = e.Logger() + e.Sentry.Logger = e.Logger() e.prepared = true return e @@ -138,17 +141,40 @@ 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 in goroutine-safe way +func (e *Engine) Logger() LoggerInterface { + e.mutex.RLock() + defer e.mutex.RUnlock() + return e.logger +} + +// UnsafeLogger returns current logger in goroutine-unsafe way. Using this method you can cause race condition. +func (e *Engine) UnsafeLogger() LoggerInterface { + return e.logger +} + +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...) diff --git a/core/logger.go b/core/logger.go index 0e9ea1c..b5fe7de 100644 --- a/core/logger.go +++ b/core/logger.go @@ -28,9 +28,10 @@ type LoggerInterface interface { } // Logger component. Uses github.com/op/go-logging under the hood. +// This logger utilises sync.RWMutex functionality in order to avoid race conditions (in some cases it is useful). type Logger struct { logger *logging.Logger - mutex *sync.RWMutex + mutex sync.RWMutex } // NewLogger will create new goroutine-safe logger with specified formatter. @@ -39,7 +40,6 @@ type Logger struct { func NewLogger(transportCode string, logLevel logging.Level, logFormat logging.Formatter) *Logger { return &Logger{ logger: newInheritedLogger(transportCode, logLevel, logFormat), - mutex: &sync.RWMutex{}, } } From b82d4e8258a1072640d770972b67581235c30d97 Mon Sep 17 00:00:00 2001 From: Pavel Date: Thu, 26 Dec 2019 16:45:47 +0300 Subject: [PATCH 3/6] better engine coverage --- core/engine_test.go | 70 +++++++++++++++++++++++++++++++-------------- go.sum | 1 + 2 files changed, 50 insertions(+), 21 deletions(-) diff --git a/core/engine_test.go b/core/engine_test.go index c9f9f18..d97af66 100644 --- a/core/engine_test.go +++ b/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,55 @@ func (e *EngineTest) Test_WithFilesystemSessions() { assert.NotNil(e.T(), e.engine.Sessions) } +func (e *EngineTest) Test_UnsafeLogger() { + origLogger := e.engine.logger + defer func() { + e.engine.logger = origLogger + }() + e.engine.logger = nil + assert.Nil(e.T(), e.engine.UnsafeLogger()) + e.engine.logger = &Logger{} + assert.IsType(e.T(), &Logger{}, e.engine.UnsafeLogger()) +} + +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()) diff --git a/go.sum b/go.sum index b03e9da..d98e41b 100644 --- a/go.sum +++ b/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= From aca2daae8d7ea316111fae1876b609e71ae1cf89 Mon Sep 17 00:00:00 2001 From: Pavel Date: Thu, 26 Dec 2019 17:19:25 +0300 Subject: [PATCH 4/6] better logger coverage --- core/logger_test.go | 98 ++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 97 insertions(+), 1 deletion(-) diff --git a/core/logger_test.go b/core/logger_test.go index 879fbd8..756bb62 100644 --- a/core/logger_test.go +++ b/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,92 @@ 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)) +} + +// 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") +} From ea81193031021f2fb2188520012a2ffd5cf1da1f Mon Sep 17 00:00:00 2001 From: Pavel Date: Thu, 26 Dec 2019 18:00:55 +0300 Subject: [PATCH 5/6] fixes for doc --- core/engine.go | 1 + core/logger.go | 3 ++- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/core/engine.go b/core/engine.go index c71a60e..395ced6 100644 --- a/core/engine.go +++ b/core/engine.go @@ -159,6 +159,7 @@ func (e *Engine) UnsafeLogger() LoggerInterface { return e.logger } +// SetLogger sets provided logger instance to engine func (e *Engine) SetLogger(l LoggerInterface) *Engine { if l == nil { return e diff --git a/core/logger.go b/core/logger.go index b5fe7de..1c440b9 100644 --- a/core/logger.go +++ b/core/logger.go @@ -125,13 +125,14 @@ func (l *Logger) Warning(args ...interface{}) { l.logger.Warning(args...) } +// Warningf logs a message using WARNING as log level. func (l *Logger) Warningf(format string, args ...interface{}) { l.mutex.Lock() defer l.mutex.Unlock() l.logger.Warningf(format, args...) } -// Warningf logs a message using WARNING as log level. +// Notice logs a message using NOTICE as log level. func (l *Logger) Notice(args ...interface{}) { l.mutex.Lock() defer l.mutex.Unlock() From fc90dd21cec71cf44a518268787cb2ed97de6486 Mon Sep 17 00:00:00 2001 From: Pavel Date: Fri, 27 Dec 2019 12:23:10 +0300 Subject: [PATCH 6/6] make logger locking optional, fix for logger tests --- core/engine.go | 9 +---- core/engine_test.go | 11 ------ core/logger.go | 91 ++++++++++++++++++++++++++++----------------- core/logger_test.go | 16 +++++--- 4 files changed, 68 insertions(+), 59 deletions(-) diff --git a/core/engine.go b/core/engine.go index 395ced6..c808bf1 100644 --- a/core/engine.go +++ b/core/engine.go @@ -147,15 +147,8 @@ func (e *Engine) JobManager() *JobManager { return e.jobManager } -// Logger returns current logger in goroutine-safe way +// Logger returns current logger func (e *Engine) Logger() LoggerInterface { - e.mutex.RLock() - defer e.mutex.RUnlock() - return e.logger -} - -// UnsafeLogger returns current logger in goroutine-unsafe way. Using this method you can cause race condition. -func (e *Engine) UnsafeLogger() LoggerInterface { return e.logger } diff --git a/core/engine_test.go b/core/engine_test.go index d97af66..8024604 100644 --- a/core/engine_test.go +++ b/core/engine_test.go @@ -187,17 +187,6 @@ func (e *EngineTest) Test_WithFilesystemSessions() { assert.NotNil(e.T(), e.engine.Sessions) } -func (e *EngineTest) Test_UnsafeLogger() { - origLogger := e.engine.logger - defer func() { - e.engine.logger = origLogger - }() - e.engine.logger = nil - assert.Nil(e.T(), e.engine.UnsafeLogger()) - e.engine.logger = &Logger{} - assert.IsType(e.T(), &Logger{}, e.engine.UnsafeLogger()) -} - func (e *EngineTest) Test_SetLogger() { origLogger := e.engine.logger defer func() { diff --git a/core/logger.go b/core/logger.go index 1c440b9..06275b3 100644 --- a/core/logger.go +++ b/core/logger.go @@ -28,10 +28,10 @@ type LoggerInterface interface { } // Logger component. Uses github.com/op/go-logging under the hood. -// This logger utilises sync.RWMutex functionality in order to avoid race conditions (in some cases it is useful). +// This logger can prevent any write operations (disabled by default, use .Exclusive() method to enable) type Logger struct { logger *logging.Logger - mutex sync.RWMutex + mutex *sync.RWMutex } // NewLogger will create new goroutine-safe logger with specified formatter. @@ -62,114 +62,137 @@ func DefaultLogFormatter() logging.Formatter { ) } +// 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + 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.mutex.Lock() - defer l.mutex.Unlock() + l.lock() + defer l.unlock() l.logger.Debugf(format, args...) } diff --git a/core/logger_test.go b/core/logger_test.go index 756bb62..b7333db 100644 --- a/core/logger_test.go +++ b/core/logger_test.go @@ -31,6 +31,10 @@ 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" { @@ -64,7 +68,7 @@ func (t *LoggerTest) Test_Panicf() { func (t *LoggerTest) Test_Critical() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }() @@ -73,7 +77,7 @@ func (t *LoggerTest) Test_Critical() { func (t *LoggerTest) Test_Criticalf() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }() @@ -82,7 +86,7 @@ func (t *LoggerTest) Test_Criticalf() { func (t *LoggerTest) Test_Warning() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }() @@ -91,7 +95,7 @@ func (t *LoggerTest) Test_Warning() { func (t *LoggerTest) Test_Notice() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }() @@ -100,7 +104,7 @@ func (t *LoggerTest) Test_Notice() { func (t *LoggerTest) Test_Info() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }() @@ -109,7 +113,7 @@ func (t *LoggerTest) Test_Info() { func (t *LoggerTest) Test_Debug() { defer func() { - if v := recover(); v == nil { + if v := recover(); v != nil { t.T().Fatal(v) } }()