From a2eb85eb25c15be9ebeb0547a188acc55f4ec0e8 Mon Sep 17 00:00:00 2001 From: Neur0toxine Date: Wed, 18 Oct 2023 14:27:23 +0300 Subject: [PATCH] wip: structured logging --- core/db/models/connection.go | 7 + core/engine.go | 32 +-- core/engine_test.go | 3 +- core/healthcheck/processor.go | 21 +- core/healthcheck/processor_test.go | 18 +- core/job_manager.go | 9 +- core/job_manager_test.go | 98 ++++---- core/logger/account_logger_decorator.go | 96 ------- core/logger/account_logger_decorator_test.go | 98 -------- core/logger/api_client_adapter.go | 21 ++ core/logger/attrs.go | 19 ++ core/logger/default.go | 87 +++++++ core/logger/handler.go | 8 + core/logger/logger.go | 235 +++--------------- core/logger/logger_test.go | 168 ------------- core/logger/nil_handler.go | 26 ++ core/logger/nil_logger.go | 45 ---- core/logger/nil_logger_test.go | 91 ------- core/logger/prefix_decorator.go | 111 --------- core/logger/prefix_decorator_test.go | 167 ------------- core/logger/zabbix_collector_adapter.go | 19 ++ core/module_features_uploader.go | 16 +- core/module_features_uploader_test.go | 16 +- core/sentry.go | 36 ++- core/sentry_test.go | 11 +- core/util/httputil/http_client_builder.go | 17 +- .../util/httputil/http_client_builder_test.go | 7 +- core/util/testutil/buffer_logger.go | 115 ++------- core/util/testutil/buffer_logger_test.go | 7 +- core/util/testutil/lockable_buffer.go | 150 +++++++++++ core/util/utils.go | 2 +- core/util/utils_test.go | 4 +- go.mod | 2 +- go.sum | 1 + 34 files changed, 543 insertions(+), 1220 deletions(-) delete mode 100644 core/logger/account_logger_decorator.go delete mode 100644 core/logger/account_logger_decorator_test.go create mode 100644 core/logger/api_client_adapter.go create mode 100644 core/logger/attrs.go create mode 100644 core/logger/default.go create mode 100644 core/logger/handler.go delete mode 100644 core/logger/logger_test.go create mode 100644 core/logger/nil_handler.go delete mode 100644 core/logger/nil_logger.go delete mode 100644 core/logger/nil_logger_test.go delete mode 100644 core/logger/prefix_decorator.go delete mode 100644 core/logger/prefix_decorator_test.go create mode 100644 core/logger/zabbix_collector_adapter.go create mode 100644 core/util/testutil/lockable_buffer.go diff --git a/core/db/models/connection.go b/core/db/models/connection.go index 8bb55d3..0f7e0a7 100644 --- a/core/db/models/connection.go +++ b/core/db/models/connection.go @@ -17,3 +17,10 @@ type Connection struct { ID int `gorm:"primary_key" json:"id"` Active bool `json:"active,omitempty"` } + +func (c Connection) Address() string { + if c.PublicURL != "" { + return c.PublicURL + } + return c.URL +} diff --git a/core/engine.go b/core/engine.go index bd3b38a..f997b47 100644 --- a/core/engine.go +++ b/core/engine.go @@ -5,6 +5,7 @@ import ( "fmt" "html/template" "io/fs" + "log/slog" "net/http" "sync" @@ -13,7 +14,6 @@ import ( "github.com/gin-gonic/gin" "github.com/gorilla/securecookie" "github.com/gorilla/sessions" - "github.com/op/go-logging" "github.com/retailcrm/zabbix-metrics-collector" "golang.org/x/text/language" @@ -62,16 +62,15 @@ func (a AppInfo) Release() string { // Engine struct. type Engine struct { - logger logger.Logger - AppInfo AppInfo - Sessions sessions.Store - LogFormatter logging.Formatter - Config config.Configuration - Zabbix metrics.Transport - ginEngine *gin.Engine - csrf *middleware.CSRF - httpClient *http.Client - jobManager *JobManager + logger logger.Logger + AppInfo AppInfo + Sessions sessions.Store + Config config.Configuration + Zabbix metrics.Transport + ginEngine *gin.Engine + csrf *middleware.CSRF + httpClient *http.Client + jobManager *JobManager db.ORM Localizer util.Utils @@ -133,9 +132,6 @@ func (e *Engine) Prepare() *Engine { if e.DefaultError == "" { e.DefaultError = "error" } - if e.LogFormatter == nil { - e.LogFormatter = logger.DefaultLogFormatter() - } if e.LocaleMatcher == nil { e.LocaleMatcher = DefaultLocalizerMatcher() } @@ -150,9 +146,13 @@ func (e *Engine) Prepare() *Engine { e.Localizer.Preload(e.PreloadLanguages) } + if !e.Config.IsDebug() { + logger.DefaultOpts.Level = slog.LevelInfo + } + e.CreateDB(e.Config.GetDBConfig()) e.ResetUtils(e.Config.GetAWSConfig(), e.Config.IsDebug(), 0) - e.SetLogger(logger.NewStandard(e.Config.GetTransportInfo().GetCode(), e.Config.GetLogLevel(), e.LogFormatter)) + e.SetLogger(logger.NewDefaultText()) e.Sentry.Localizer = &e.Localizer e.Utils.Logger = e.Logger() e.Sentry.Logger = e.Logger() @@ -175,7 +175,7 @@ func (e *Engine) UseZabbix(collectors []metrics.Collector) *Engine { } cfg := e.Config.GetZabbixConfig() sender := zabbix.NewSender(cfg.ServerHost, cfg.ServerPort) - e.Zabbix = metrics.NewZabbix(collectors, sender, cfg.Host, cfg.Interval, e.Logger()) + e.Zabbix = metrics.NewZabbix(collectors, sender, cfg.Host, cfg.Interval, logger.ZabbixCollectorAdapter(e.Logger())) return e } diff --git a/core/engine_test.go b/core/engine_test.go index 259ef92..b59e5d3 100644 --- a/core/engine_test.go +++ b/core/engine_test.go @@ -123,7 +123,6 @@ func (e *EngineTest) Test_Prepare() { assert.True(e.T(), e.engine.prepared) assert.NotNil(e.T(), e.engine.Config) assert.NotEmpty(e.T(), e.engine.DefaultError) - assert.NotEmpty(e.T(), e.engine.LogFormatter) assert.NotEmpty(e.T(), e.engine.LocaleMatcher) assert.False(e.T(), e.engine.isUnd(e.engine.Localizer.LanguageTag)) assert.NotNil(e.T(), e.engine.DB) @@ -253,7 +252,7 @@ func (e *EngineTest) Test_SetLogger() { defer func() { e.engine.logger = origLogger }() - e.engine.logger = &logger.StandardLogger{} + e.engine.logger = logger.NewDefaultNil() e.engine.SetLogger(nil) assert.NotNil(e.T(), e.engine.logger) } diff --git a/core/healthcheck/processor.go b/core/healthcheck/processor.go index fc11ccd..cb178d3 100644 --- a/core/healthcheck/processor.go +++ b/core/healthcheck/processor.go @@ -1,6 +1,8 @@ package healthcheck import ( + "log/slog" + "github.com/retailcrm/mg-transport-core/v2/core/logger" ) @@ -29,19 +31,19 @@ type CounterProcessor struct { func (c CounterProcessor) Process(id int, counter Counter) bool { // nolint:varnamelen if counter.IsFailed() { if counter.IsFailureProcessed() { - c.debugLog("skipping counter id=%d because its failure is already processed", id) + c.debugLog("skipping counter because its failure is already processed", slog.Int(logger.CounterIDAttr, id)) return true } apiURL, apiKey, _, exists := c.ConnectionDataProvider(id) if !exists { - c.debugLog("cannot find connection data for counter id=%d", id) + c.debugLog("cannot find connection data for counter", slog.Int(logger.CounterIDAttr, id)) return true } err := c.Notifier(apiURL, apiKey, counter.Message()) if err != nil { - c.debugLog("cannot send notification for counter id=%d: %s (message: %s)", - id, err, counter.Message()) + c.debugLog("cannot send notification for counter", + slog.Int(logger.CounterIDAttr, id), logger.ErrAttr(err), slog.String(logger.FailureMessageAttr, counter.Message())) } counter.FailureProcessed() return true @@ -53,7 +55,8 @@ func (c CounterProcessor) Process(id int, counter Counter) bool { // nolint:varn // Ignore this counter for now because total count of requests is less than minimal count. // The results may not be representative. if (succeeded + failed) < c.MinRequests { - c.debugLog("skipping counter id=%d because it has fewer than %d requests", id, c.MinRequests) + c.debugLog("skipping counter because it has too few requests", + slog.Int(logger.CounterIDAttr, id), slog.Any("minRequests", c.MinRequests)) return true } @@ -72,13 +75,13 @@ func (c CounterProcessor) Process(id int, counter Counter) bool { // nolint:varn apiURL, apiKey, lang, exists := c.ConnectionDataProvider(id) if !exists { - c.debugLog("cannot find connection data for counter id=%d", id) + c.debugLog("cannot find connection data for counter", slog.Int(logger.CounterIDAttr, id)) return true } err := c.Notifier(apiURL, apiKey, c.getErrorText(counter.Name(), c.Error, lang)) if err != nil { - c.debugLog("cannot send notification for counter id=%d: %s (message: %s)", - id, err, counter.Message()) + c.debugLog("cannot send notification for counter", + slog.Int(logger.CounterIDAttr, id), logger.ErrAttr(err), slog.String(logger.FailureMessageAttr, counter.Message())) } counter.CountersProcessed() return true @@ -96,6 +99,6 @@ func (c CounterProcessor) getErrorText(name, msg, lang string) string { func (c CounterProcessor) debugLog(msg string, args ...interface{}) { if c.Debug { - c.Logger.Debugf(msg, args...) + c.Logger.Debug(msg, args...) } } diff --git a/core/healthcheck/processor_test.go b/core/healthcheck/processor_test.go index 9774310..ecaa6a1 100644 --- a/core/healthcheck/processor_test.go +++ b/core/healthcheck/processor_test.go @@ -95,7 +95,8 @@ func (t *CounterProcessorTest) Test_FailureProcessed() { p.Process(1, c) c.AssertExpectations(t.T()) - t.Assert().Contains(log.String(), "skipping counter id=1 because its failure is already processed") + t.Assert().Contains(log.String(), "skipping counter because its failure is already processed") + t.Assert().Contains(log.String(), "id=1") } func (t *CounterProcessorTest) Test_CounterFailed_CannotFindConnection() { @@ -107,7 +108,8 @@ func (t *CounterProcessorTest) Test_CounterFailed_CannotFindConnection() { p.Process(1, c) c.AssertExpectations(t.T()) - t.Assert().Contains(log.String(), "cannot find connection data for counter id=1") + t.Assert().Contains(log.String(), "cannot find connection data for counter") + t.Assert().Contains(log.String(), "id=1") } func (t *CounterProcessorTest) Test_CounterFailed_ErrWhileNotifying() { @@ -121,7 +123,10 @@ func (t *CounterProcessorTest) Test_CounterFailed_ErrWhileNotifying() { p.Process(1, c) c.AssertExpectations(t.T()) - t.Assert().Contains(log.String(), "cannot send notification for counter id=1: http status code: 500 (message: error message)") + t.Assert().Contains(log.String(), "cannot send notification for counter") + t.Assert().Contains(log.String(), "id=1") + t.Assert().Contains(log.String(), `error="http status code: 500"`) + t.Assert().Contains(log.String(), `message="error message"`) t.Assert().Equal(t.apiURL, n.apiURL) t.Assert().Equal(t.apiKey, n.apiKey) t.Assert().Equal("error message", n.message) @@ -155,7 +160,7 @@ func (t *CounterProcessorTest) Test_TooFewRequests() { p.Process(1, c) c.AssertExpectations(t.T()) t.Assert().Contains(log.String(), - fmt.Sprintf("skipping counter id=%d because it has fewer than %d requests", 1, DefaultMinRequests)) + fmt.Sprintf(`msg="skipping counter because it has too few requests" id=%d minRequests=%d`, 1, DefaultMinRequests)) } func (t *CounterProcessorTest) Test_ThresholdNotPassed() { @@ -200,7 +205,8 @@ func (t *CounterProcessorTest) Test_ThresholdPassed_NoConnectionFound() { p.Process(1, c) c.AssertExpectations(t.T()) - t.Assert().Contains(log.String(), "cannot find connection data for counter id=1") + t.Assert().Contains(log.String(), "cannot find connection data for counter") + t.Assert().Contains(log.String(), "id=1") t.Assert().Empty(n.message) } @@ -218,7 +224,7 @@ func (t *CounterProcessorTest) Test_ThresholdPassed_NotifyingError() { p.Process(1, c) c.AssertExpectations(t.T()) - t.Assert().Contains(log.String(), "cannot send notification for counter id=1: unknown error (message: )") + t.Assert().Contains(log.String(), `msg="cannot send notification for counter" id=1 error="unknown error" message=""`) t.Assert().Equal(`default error [{"Name":"MockedCounter"}]`, n.message) } diff --git a/core/job_manager.go b/core/job_manager.go index fac84de..ed1db6d 100644 --- a/core/job_manager.go +++ b/core/job_manager.go @@ -3,6 +3,7 @@ package core import ( "errors" "fmt" + "log/slog" "sync" "time" @@ -46,7 +47,7 @@ type Job struct { // SetLogger(logger). // SetLogging(false) // _ = manager.RegisterJob("updateTokens", &Job{ -// Command: func(log logger.Logger) error { +// Command: func(log logger.LoggerOld) error { // // logic goes here... // logger.Info("All tokens were updated successfully") // return nil @@ -146,14 +147,14 @@ func (j *Job) runOnceSync(name string, log logger.Logger) { // NewJobManager is a JobManager constructor. func NewJobManager() *JobManager { - return &JobManager{jobs: &sync.Map{}, nilLogger: logger.NewNil()} + return &JobManager{jobs: &sync.Map{}, nilLogger: logger.NewDefaultNil()} } // DefaultJobErrorHandler returns default error handler for a job. func DefaultJobErrorHandler() JobErrorHandler { return func(name string, err error, log logger.Logger) { if err != nil && name != "" { - log.Errorf("Job `%s` errored with an error: `%s`", name, err.Error()) + log.Error("job failed with an error", slog.String("job", name), logger.ErrAttr(err)) } } } @@ -162,7 +163,7 @@ func DefaultJobErrorHandler() JobErrorHandler { func DefaultJobPanicHandler() JobPanicHandler { return func(name string, recoverValue interface{}, log logger.Logger) { if recoverValue != nil && name != "" { - log.Errorf("Job `%s` panicked with value: `%#v`", name, recoverValue) + log.Error("job panicked with the value", slog.String("job", name), slog.Any("value", recoverValue)) } } } diff --git a/core/job_manager_test.go b/core/job_manager_test.go index 6da22de..dbfb09c 100644 --- a/core/job_manager_test.go +++ b/core/job_manager_test.go @@ -1,15 +1,16 @@ package core import ( + "context" "errors" "fmt" + "log/slog" "math/rand" "strings" "sync" "testing" "time" - "github.com/op/go-logging" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/stretchr/testify/suite" @@ -25,7 +26,7 @@ type JobTest struct { executeErr chan error panicValue chan interface{} lastLog string - lastMsgLevel logging.Level + lastMsgLevel slog.Level syncBool bool } @@ -36,68 +37,69 @@ type JobManagerTest struct { syncRunnerFlag bool } -type callbackLoggerFunc func(level logging.Level, format string, args ...interface{}) +type callbackLoggerFunc func(ctx context.Context, level slog.Level, msg string, args ...any) type callbackLogger struct { fn callbackLoggerFunc } -func (n *callbackLogger) Fatal(args ...interface{}) { - n.fn(logging.CRITICAL, "", args...) +func (n *callbackLogger) Handler() slog.Handler { + return logger.NilHandler } -func (n *callbackLogger) Fatalf(format string, args ...interface{}) { - n.fn(logging.CRITICAL, format, args...) +func (n *callbackLogger) With(args ...any) logger.Logger { + return n } -func (n *callbackLogger) Panic(args ...interface{}) { - n.fn(logging.CRITICAL, "", args...) -} -func (n *callbackLogger) Panicf(format string, args ...interface{}) { - n.fn(logging.CRITICAL, format, args...) +func (n *callbackLogger) WithGroup(name string) logger.Logger { + return n } -func (n *callbackLogger) Critical(args ...interface{}) { - n.fn(logging.CRITICAL, "", args...) +func (n *callbackLogger) ForAccount(handler, conn, acc any) logger.Logger { + return n } -func (n *callbackLogger) Criticalf(format string, args ...interface{}) { - n.fn(logging.CRITICAL, format, args...) +func (n *callbackLogger) Enabled(ctx context.Context, level slog.Level) bool { + return true } -func (n *callbackLogger) Error(args ...interface{}) { - n.fn(logging.ERROR, "", args...) -} -func (n *callbackLogger) Errorf(format string, args ...interface{}) { - n.fn(logging.ERROR, format, args...) +func (n *callbackLogger) Log(ctx context.Context, level slog.Level, msg string, args ...any) { + n.fn(ctx, level, msg, args...) } -func (n *callbackLogger) Warning(args ...interface{}) { - n.fn(logging.WARNING, "", args...) -} -func (n *callbackLogger) Warningf(format string, args ...interface{}) { - n.fn(logging.WARNING, format, args...) +func (n *callbackLogger) LogAttrs(ctx context.Context, level slog.Level, msg string, attrs ...slog.Attr) { } -func (n *callbackLogger) Notice(args ...interface{}) { - n.fn(logging.NOTICE, "", args...) -} -func (n *callbackLogger) Noticef(format string, args ...interface{}) { - n.fn(logging.NOTICE, format, args...) +func (n *callbackLogger) Debug(msg string, args ...any) { + n.Log(nil, slog.LevelDebug, msg, args...) } -func (n *callbackLogger) Info(args ...interface{}) { - n.fn(logging.INFO, "", args...) -} -func (n *callbackLogger) Infof(format string, args ...interface{}) { - n.fn(logging.INFO, format, args...) +func (n *callbackLogger) DebugContext(ctx context.Context, msg string, args ...any) { + n.Log(ctx, slog.LevelDebug, msg, args...) } -func (n *callbackLogger) Debug(args ...interface{}) { - n.fn(logging.DEBUG, "", args...) +func (n *callbackLogger) Info(msg string, args ...any) { + n.Log(nil, slog.LevelInfo, msg, args...) } -func (n *callbackLogger) Debugf(format string, args ...interface{}) { - n.fn(logging.DEBUG, format, args...) + +func (n *callbackLogger) InfoContext(ctx context.Context, msg string, args ...any) { + n.Log(ctx, slog.LevelInfo, msg, args...) +} + +func (n *callbackLogger) Warn(msg string, args ...any) { + n.Log(nil, slog.LevelWarn, msg, args...) +} + +func (n *callbackLogger) WarnContext(ctx context.Context, msg string, args ...any) { + n.Log(ctx, slog.LevelWarn, msg, args...) +} + +func (n *callbackLogger) Error(msg string, args ...any) { + n.Log(nil, slog.LevelError, msg, args...) +} + +func (n *callbackLogger) ErrorContext(ctx context.Context, msg string, args ...any) { + n.Log(ctx, slog.LevelError, msg, args...) } func TestJob(t *testing.T) { @@ -115,9 +117,9 @@ func TestDefaultJobErrorHandler(t *testing.T) { fn := DefaultJobErrorHandler() require.NotNil(t, fn) - fn("job", errors.New("test"), &callbackLogger{fn: func(level logging.Level, s string, i ...interface{}) { + fn("job", errors.New("test"), &callbackLogger{fn: func(_ context.Context, level slog.Level, s string, i ...interface{}) { require.Len(t, i, 2) - assert.Equal(t, fmt.Sprintf("%s", i[1]), "test") + assert.Equal(t, "error=test", fmt.Sprintf("%s", i[1])) }}) } @@ -128,9 +130,9 @@ func TestDefaultJobPanicHandler(t *testing.T) { fn := DefaultJobPanicHandler() require.NotNil(t, fn) - fn("job", errors.New("test"), &callbackLogger{fn: func(level logging.Level, s string, i ...interface{}) { + fn("job", errors.New("test"), &callbackLogger{fn: func(_ context.Context, level slog.Level, s string, i ...interface{}) { require.Len(t, i, 2) - assert.Equal(t, fmt.Sprintf("%s", i[1]), "test") + assert.Equal(t, "value=test", fmt.Sprintf("%s", i[1])) }}) } @@ -147,7 +149,7 @@ func (t *JobTest) testPanicHandler() JobPanicHandler { } func (t *JobTest) testLogger() logger.Logger { - return &callbackLogger{fn: func(level logging.Level, format string, args ...interface{}) { + return &callbackLogger{fn: func(_ context.Context, level slog.Level, format string, args ...interface{}) { if format == "" { var sb strings.Builder sb.Grow(3 * len(args)) // nolint:gomnd @@ -404,11 +406,11 @@ func (t *JobManagerTest) WaitForJob() bool { func (t *JobManagerTest) Test_SetLogger() { t.manager.logger = nil - t.manager.SetLogger(logger.NewStandard("test", logging.ERROR, logger.DefaultLogFormatter())) - assert.IsType(t.T(), &logger.StandardLogger{}, t.manager.logger) + t.manager.SetLogger(logger.NewDefaultText()) + assert.IsType(t.T(), &logger.Default{}, t.manager.logger) t.manager.SetLogger(nil) - assert.IsType(t.T(), &logger.StandardLogger{}, t.manager.logger) + assert.IsType(t.T(), &logger.Default{}, t.manager.logger) } func (t *JobManagerTest) Test_SetLogging() { diff --git a/core/logger/account_logger_decorator.go b/core/logger/account_logger_decorator.go deleted file mode 100644 index e35d8e9..0000000 --- a/core/logger/account_logger_decorator.go +++ /dev/null @@ -1,96 +0,0 @@ -package logger - -import ( - "fmt" - - "github.com/op/go-logging" -) - -// DefaultAccountLoggerFormat contains default prefix format for the AccountLoggerDecorator. -// Its messages will look like this (assuming you will provide the connection URL and account name): -// messageHandler (https://any.simla.com => @tg_account): sent message with id=1 -const DefaultAccountLoggerFormat = "%s (%s => %s):" - -type ComponentAware interface { - SetComponent(string) -} - -type ConnectionAware interface { - SetConnectionIdentifier(string) -} - -type AccountAware interface { - SetAccountIdentifier(string) -} - -type PrefixFormatAware interface { - SetPrefixFormat(string) -} - -type AccountLogger interface { - PrefixedLogger - ComponentAware - ConnectionAware - AccountAware - PrefixFormatAware -} - -type AccountLoggerDecorator struct { - format string - component string - connIdentifier string - accIdentifier string - PrefixDecorator -} - -func DecorateForAccount(base Logger, component, connIdentifier, accIdentifier string) AccountLogger { - return (&AccountLoggerDecorator{ - PrefixDecorator: PrefixDecorator{ - backend: base, - }, - component: component, - connIdentifier: connIdentifier, - accIdentifier: accIdentifier, - }).updatePrefix() -} - -// NewForAccount returns logger for account. It uses StandardLogger under the hood. -func NewForAccount( - transportCode, component, connIdentifier, accIdentifier string, - logLevel logging.Level, - logFormat logging.Formatter) AccountLogger { - return DecorateForAccount(NewStandard(transportCode, logLevel, logFormat), - component, connIdentifier, accIdentifier) -} - -func (a *AccountLoggerDecorator) SetComponent(s string) { - a.component = s - a.updatePrefix() -} - -func (a *AccountLoggerDecorator) SetConnectionIdentifier(s string) { - a.connIdentifier = s - a.updatePrefix() -} - -func (a *AccountLoggerDecorator) SetAccountIdentifier(s string) { - a.accIdentifier = s - a.updatePrefix() -} - -func (a *AccountLoggerDecorator) SetPrefixFormat(s string) { - a.format = s - a.updatePrefix() -} - -func (a *AccountLoggerDecorator) updatePrefix() AccountLogger { - a.SetPrefix(fmt.Sprintf(a.prefixFormat(), a.component, a.connIdentifier, a.accIdentifier)) - return a -} - -func (a *AccountLoggerDecorator) prefixFormat() string { - if a.format == "" { - return DefaultAccountLoggerFormat - } - return a.format -} diff --git a/core/logger/account_logger_decorator_test.go b/core/logger/account_logger_decorator_test.go deleted file mode 100644 index ab6a8b9..0000000 --- a/core/logger/account_logger_decorator_test.go +++ /dev/null @@ -1,98 +0,0 @@ -package logger - -import ( - "bytes" - "fmt" - "testing" - - "github.com/op/go-logging" - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/suite" -) - -const ( - testComponent = "ComponentName" - testConnectionID = "https://test.retailcrm.pro" - testAccountID = "@account_name" -) - -type AccountLoggerDecoratorTest struct { - suite.Suite - buf *bytes.Buffer - logger AccountLogger -} - -func TestAccountLoggerDecorator(t *testing.T) { - suite.Run(t, new(AccountLoggerDecoratorTest)) -} - -func TestNewForAccount(t *testing.T) { - buf := &bytes.Buffer{} - logger := NewForAccount("code", "component", "conn", "acc", logging.DEBUG, DefaultLogFormatter()) - logger.(*AccountLoggerDecorator).backend.(*StandardLogger). - SetBaseLogger(NewBase(buf, "code", logging.DEBUG, DefaultLogFormatter())) - logger.Debugf("message %s", "text") - - assert.Contains(t, buf.String(), fmt.Sprintf(DefaultAccountLoggerFormat+" message", "component", "conn", "acc")) -} - -func (t *AccountLoggerDecoratorTest) SetupSuite() { - t.buf = &bytes.Buffer{} - t.logger = DecorateForAccount((&StandardLogger{}). - SetBaseLogger(NewBase(t.buf, "code", logging.DEBUG, DefaultLogFormatter())), - testComponent, testConnectionID, testAccountID) -} - -func (t *AccountLoggerDecoratorTest) SetupTest() { - t.buf.Reset() - t.logger.SetComponent(testComponent) - t.logger.SetConnectionIdentifier(testConnectionID) - t.logger.SetAccountIdentifier(testAccountID) - t.logger.SetPrefixFormat(DefaultAccountLoggerFormat) -} - -func (t *AccountLoggerDecoratorTest) Test_LogWithNewFormat() { - t.logger.SetPrefixFormat("[%s (%s: %s)] =>") - t.logger.Infof("test message") - - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), - fmt.Sprintf("[%s (%s: %s)] =>", testComponent, testConnectionID, testAccountID)) -} - -func (t *AccountLoggerDecoratorTest) Test_Log() { - t.logger.Infof("test message") - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), - fmt.Sprintf(DefaultAccountLoggerFormat, testComponent, testConnectionID, testAccountID)) -} - -func (t *AccountLoggerDecoratorTest) Test_SetComponent() { - t.logger.SetComponent("NewComponent") - t.logger.Infof("test message") - - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), - fmt.Sprintf(DefaultAccountLoggerFormat, "NewComponent", testConnectionID, testAccountID)) -} - -func (t *AccountLoggerDecoratorTest) Test_SetConnectionIdentifier() { - t.logger.SetComponent("NewComponent") - t.logger.SetConnectionIdentifier("https://test.simla.com") - t.logger.Infof("test message") - - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), - fmt.Sprintf(DefaultAccountLoggerFormat, "NewComponent", "https://test.simla.com", testAccountID)) -} - -func (t *AccountLoggerDecoratorTest) Test_SetAccountIdentifier() { - t.logger.SetComponent("NewComponent") - t.logger.SetConnectionIdentifier("https://test.simla.com") - t.logger.SetAccountIdentifier("@new_account_name") - t.logger.Infof("test message") - - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), - fmt.Sprintf(DefaultAccountLoggerFormat, "NewComponent", "https://test.simla.com", "@new_account_name")) -} diff --git a/core/logger/api_client_adapter.go b/core/logger/api_client_adapter.go new file mode 100644 index 0000000..7951336 --- /dev/null +++ b/core/logger/api_client_adapter.go @@ -0,0 +1,21 @@ +package logger + +import ( + "fmt" + + retailcrm "github.com/retailcrm/api-client-go/v2" +) + +type apiClientAdapter struct { + logger Logger +} + +// APIClientAdapter returns BasicLogger that calls underlying logger. +func APIClientAdapter(logger Logger) retailcrm.BasicLogger { + return &apiClientAdapter{logger: logger} +} + +// Printf data in the log using Debug method. +func (l *apiClientAdapter) Printf(format string, v ...interface{}) { + l.logger.Debug(fmt.Sprintf(format, v...)) +} diff --git a/core/logger/attrs.go b/core/logger/attrs.go new file mode 100644 index 0000000..293e0b5 --- /dev/null +++ b/core/logger/attrs.go @@ -0,0 +1,19 @@ +package logger + +import "log/slog" + +const ( + HandlerAttr = "handler" + ConnectionAttr = "connection" + AccountAttr = "account" + CounterIDAttr = "counterId" + ErrorAttr = "error" + FailureMessageAttr = "failureMessage" +) + +func ErrAttr(err any) slog.Attr { + if err == nil { + return slog.String(ErrorAttr, "") + } + return slog.Any(ErrorAttr, err) +} diff --git a/core/logger/default.go b/core/logger/default.go new file mode 100644 index 0000000..78240a3 --- /dev/null +++ b/core/logger/default.go @@ -0,0 +1,87 @@ +package logger + +import ( + "context" + "log/slog" + "os" +) + +type Default struct { + Logger *slog.Logger +} + +func NewDefault(log *slog.Logger) Logger { + return &Default{Logger: log} +} + +func NewDefaultText() Logger { + return NewDefault(slog.New(slog.NewTextHandler(os.Stdout, DefaultOpts))) +} + +func NewDefaultJSON() Logger { + return NewDefault(slog.New(slog.NewJSONHandler(os.Stdout, DefaultOpts))) +} + +func NewDefaultNil() Logger { + return NewDefault(slog.New(NilHandler)) +} + +func (d *Default) Handler() slog.Handler { + return d.Logger.Handler() +} + +func (d *Default) ForAccount(handler, conn, acc any) Logger { + return d.With(slog.Any(HandlerAttr, handler), slog.Any(ConnectionAttr, conn), slog.Any(AccountAttr, acc)) +} + +func (d *Default) With(args ...any) Logger { + return &Default{Logger: d.Logger.With(args...)} +} + +func (d *Default) WithGroup(name string) Logger { + return &Default{Logger: d.Logger.WithGroup(name)} +} + +func (d *Default) Enabled(ctx context.Context, level slog.Level) bool { + return d.Logger.Enabled(ctx, level) +} + +func (d *Default) Log(ctx context.Context, level slog.Level, msg string, args ...any) { + d.Logger.Log(ctx, level, msg, args...) +} + +func (d *Default) LogAttrs(ctx context.Context, level slog.Level, msg string, attrs ...slog.Attr) { + d.Logger.LogAttrs(ctx, level, msg, attrs...) +} + +func (d *Default) Debug(msg string, args ...any) { + d.Logger.Debug(msg, args...) +} + +func (d *Default) DebugContext(ctx context.Context, msg string, args ...any) { + d.Logger.DebugContext(ctx, msg, args...) +} + +func (d *Default) Info(msg string, args ...any) { + d.Logger.Info(msg, args...) +} + +func (d *Default) InfoContext(ctx context.Context, msg string, args ...any) { + d.Logger.InfoContext(ctx, msg, args...) +} + +func (d *Default) Warn(msg string, args ...any) { + d.Logger.Warn(msg, args...) +} + +func (d *Default) WarnContext(ctx context.Context, msg string, args ...any) { + d.Logger.WarnContext(ctx, msg, args...) +} + +func (d *Default) Error(msg string, args ...any) { + d.Logger.Error(msg, args...) +} + +func (d *Default) ErrorContext(ctx context.Context, msg string, args ...any) { + d.Logger.ErrorContext(ctx, msg, args...) +} diff --git a/core/logger/handler.go b/core/logger/handler.go new file mode 100644 index 0000000..1c5ffe9 --- /dev/null +++ b/core/logger/handler.go @@ -0,0 +1,8 @@ +package logger + +import "log/slog" + +var DefaultOpts = &slog.HandlerOptions{ + AddSource: false, + Level: slog.LevelDebug, +} diff --git a/core/logger/logger.go b/core/logger/logger.go index 32445f9..4fb9f16 100644 --- a/core/logger/logger.go +++ b/core/logger/logger.go @@ -1,205 +1,44 @@ package logger import ( - "io" - "os" - "sync" - - "github.com/op/go-logging" + "context" + "log/slog" ) -// Logger contains methods which should be present in logger implementation. +// LoggerOld contains methods which should be present in logger implementation. +type LoggerOld interface { + Fatal(args ...any) + Fatalf(format string, args ...any) + Panic(args ...any) + Panicf(format string, args ...any) + Critical(args ...any) + Criticalf(format string, args ...any) + Error(args ...any) + Errorf(format string, args ...any) + Warning(args ...any) + Warningf(format string, args ...any) + Notice(args ...any) + Noticef(format string, args ...any) + Info(args ...any) + Infof(format string, args ...any) + Debug(args ...any) + Debugf(format string, args ...any) +} + type Logger 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{}) -} - -// StandardLogger is a default implementation of Logger. 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 StandardLogger struct { - logger *logging.Logger - mutex *sync.RWMutex -} - -// NewStandard will create new StandardLogger with specified formatter. -// Usage: -// logger := NewLogger("telegram", logging.ERROR, DefaultLogFormatter()) -func NewStandard(transportCode string, logLevel logging.Level, logFormat logging.Formatter) *StandardLogger { - return &StandardLogger{ - logger: NewBase(os.Stdout, transportCode, logLevel, logFormat), - } -} - -// NewBase is a constructor for underlying logger in the StandardLogger struct. -func NewBase(out io.Writer, transportCode string, logLevel logging.Level, logFormat logging.Formatter) *logging.Logger { - logger := logging.MustGetLogger(transportCode) - logBackend := logging.NewLogBackend(out, "", 0) - formatBackend := logging.NewBackendFormatter(logBackend, logFormat) - backend1Leveled := logging.AddModuleLevel(formatBackend) - backend1Leveled.SetLevel(logLevel, "") - logger.SetBackend(backend1Leveled) - - return logger -} - -// DefaultLogFormatter will return default formatter for logs. -func DefaultLogFormatter() logging.Formatter { - return logging.MustStringFormatter( - `%{time:2006-01-02 15:04:05.000} %{level:.4s} => %{message}`, - ) -} - -// Exclusive makes logger goroutine-safe. -func (l *StandardLogger) Exclusive() *StandardLogger { - if l.mutex == nil { - l.mutex = &sync.RWMutex{} - } - - return l -} - -// SetBaseLogger replaces base logger with the provided instance. -func (l *StandardLogger) SetBaseLogger(logger *logging.Logger) *StandardLogger { - l.logger = logger - return l -} - -// lock locks logger. -func (l *StandardLogger) lock() { - if l.mutex != nil { - l.mutex.Lock() - } -} - -// unlock unlocks logger. -func (l *StandardLogger) 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 *StandardLogger) 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 *StandardLogger) 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 *StandardLogger) 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 *StandardLogger) 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 *StandardLogger) Critical(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Critical(args...) -} - -// Criticalf logs a message using CRITICAL as log level. -func (l *StandardLogger) 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 *StandardLogger) Error(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Error(args...) -} - -// Errorf logs a message using ERROR as log level. -func (l *StandardLogger) 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 *StandardLogger) Warning(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Warning(args...) -} - -// Warningf logs a message using WARNING as log level. -func (l *StandardLogger) 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 *StandardLogger) Notice(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Notice(args...) -} - -// Noticef logs a message using NOTICE as log level. -func (l *StandardLogger) 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 *StandardLogger) Info(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Info(args...) -} - -// Infof logs a message using INFO as log level. -func (l *StandardLogger) 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 *StandardLogger) Debug(args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Debug(args...) -} - -// Debugf logs a message using DEBUG as log level. -func (l *StandardLogger) Debugf(format string, args ...interface{}) { - l.lock() - defer l.unlock() - l.logger.Debugf(format, args...) + Handler() slog.Handler + With(args ...any) Logger + WithGroup(name string) Logger + ForAccount(handler, conn, acc any) Logger + Enabled(ctx context.Context, level slog.Level) bool + Log(ctx context.Context, level slog.Level, msg string, args ...any) + LogAttrs(ctx context.Context, level slog.Level, msg string, attrs ...slog.Attr) + Debug(msg string, args ...any) + DebugContext(ctx context.Context, msg string, args ...any) + Info(msg string, args ...any) + InfoContext(ctx context.Context, msg string, args ...any) + Warn(msg string, args ...any) + WarnContext(ctx context.Context, msg string, args ...any) + Error(msg string, args ...any) + ErrorContext(ctx context.Context, msg string, args ...any) } diff --git a/core/logger/logger_test.go b/core/logger/logger_test.go deleted file mode 100644 index cb9c371..0000000 --- a/core/logger/logger_test.go +++ /dev/null @@ -1,168 +0,0 @@ -package logger - -import ( - "bytes" - "testing" - - "github.com/op/go-logging" - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/suite" -) - -type StandardLoggerTest struct { - suite.Suite - logger *StandardLogger - buf *bytes.Buffer -} - -func TestLogger_NewLogger(t *testing.T) { - logger := NewStandard("code", logging.DEBUG, DefaultLogFormatter()) - assert.NotNil(t, logger) -} - -func TestLogger_DefaultLogFormatter(t *testing.T) { - formatter := DefaultLogFormatter() - - assert.NotNil(t, formatter) - assert.IsType(t, logging.MustStringFormatter(`%{message}`), formatter) -} - -func Test_Logger(t *testing.T) { - suite.Run(t, new(StandardLoggerTest)) -} - -func (t *StandardLoggerTest) SetupSuite() { - t.buf = &bytes.Buffer{} - t.logger = (&StandardLogger{}). - Exclusive(). - SetBaseLogger(NewBase(t.buf, "code", logging.DEBUG, DefaultLogFormatter())) -} - -func (t *StandardLoggerTest) SetupTest() { - t.buf.Reset() -} - -// TODO Cover Fatal and Fatalf (implementation below is no-op) -// func (t *StandardLoggerTest) 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" -// t.Assert().Equal(true, ok) -// t.Assert().Equal(expectedErrorString, e.Error()) -// } - -func (t *StandardLoggerTest) Test_Panic() { - defer func() { - t.Assert().NotNil(recover()) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), "panic") - }() - t.logger.Panic("panic") -} - -func (t *StandardLoggerTest) Test_Panicf() { - defer func() { - t.Assert().NotNil(recover()) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), "panicf") - }() - t.logger.Panicf("panicf") -} - -func (t *StandardLoggerTest) Test_Critical() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), "critical") - }() - t.logger.Critical("critical") -} - -func (t *StandardLoggerTest) Test_Criticalf() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), "critical") - }() - t.logger.Criticalf("critical") -} - -func (t *StandardLoggerTest) Test_Warning() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "WARN") - t.Assert().Contains(t.buf.String(), "warning") - }() - t.logger.Warning("warning") -} - -func (t *StandardLoggerTest) Test_Notice() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "NOTI") - t.Assert().Contains(t.buf.String(), "notice") - }() - t.logger.Notice("notice") -} - -func (t *StandardLoggerTest) Test_Info() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), "info") - }() - t.logger.Info("info") -} - -func (t *StandardLoggerTest) Test_Debug() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "DEBU") - t.Assert().Contains(t.buf.String(), "debug") - }() - t.logger.Debug("debug") -} - -func (t *StandardLoggerTest) Test_Warningf() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "WARN") - t.Assert().Contains(t.buf.String(), "warning") - }() - t.logger.Warningf("%s", "warning") -} - -func (t *StandardLoggerTest) Test_Noticef() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "NOTI") - t.Assert().Contains(t.buf.String(), "notice") - }() - t.logger.Noticef("%s", "notice") -} - -func (t *StandardLoggerTest) Test_Infof() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), "info") - }() - t.logger.Infof("%s", "info") -} - -func (t *StandardLoggerTest) Test_Debugf() { - defer func() { - t.Require().Nil(recover()) - t.Assert().Contains(t.buf.String(), "DEBU") - t.Assert().Contains(t.buf.String(), "debug") - }() - t.logger.Debugf("%s", "debug") -} diff --git a/core/logger/nil_handler.go b/core/logger/nil_handler.go new file mode 100644 index 0000000..6b167b3 --- /dev/null +++ b/core/logger/nil_handler.go @@ -0,0 +1,26 @@ +package logger + +import ( + "context" + "log/slog" +) + +var NilHandler slog.Handler = &nilHandler{} + +type nilHandler struct{} + +func (n *nilHandler) Enabled(ctx context.Context, level slog.Level) bool { + return false +} + +func (n *nilHandler) Handle(ctx context.Context, record slog.Record) error { + return nil +} + +func (n *nilHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return n +} + +func (n *nilHandler) WithGroup(name string) slog.Handler { + return n +} diff --git a/core/logger/nil_logger.go b/core/logger/nil_logger.go deleted file mode 100644 index 440b4d0..0000000 --- a/core/logger/nil_logger.go +++ /dev/null @@ -1,45 +0,0 @@ -package logger - -import ( - "fmt" - "os" -) - -// Nil provides Logger implementation that does almost nothing when called. -// Panic, Panicf, Fatal and Fatalf methods still cause panic and immediate program termination respectively. -// All other methods won't do anything at all. -type Nil struct{} - -func (n Nil) Fatal(args ...interface{}) { - os.Exit(1) -} - -func (n Nil) Fatalf(format string, args ...interface{}) { - os.Exit(1) -} - -func (n Nil) Panic(args ...interface{}) { - panic(fmt.Sprint(args...)) -} - -func (n Nil) Panicf(format string, args ...interface{}) { - panic(fmt.Sprintf(format, args...)) -} - -func (n Nil) Critical(args ...interface{}) {} -func (n Nil) Criticalf(format string, args ...interface{}) {} -func (n Nil) Error(args ...interface{}) {} -func (n Nil) Errorf(format string, args ...interface{}) {} -func (n Nil) Warning(args ...interface{}) {} -func (n Nil) Warningf(format string, args ...interface{}) {} -func (n Nil) Notice(args ...interface{}) {} -func (n Nil) Noticef(format string, args ...interface{}) {} -func (n Nil) Info(args ...interface{}) {} -func (n Nil) Infof(format string, args ...interface{}) {} -func (n Nil) Debug(args ...interface{}) {} -func (n Nil) Debugf(format string, args ...interface{}) {} - -// NewNil is a Nil logger constructor. -func NewNil() Logger { - return &Nil{} -} diff --git a/core/logger/nil_logger_test.go b/core/logger/nil_logger_test.go deleted file mode 100644 index f41c03e..0000000 --- a/core/logger/nil_logger_test.go +++ /dev/null @@ -1,91 +0,0 @@ -package logger - -import ( - "bytes" - "io" - "os" - "testing" - "time" - - "github.com/stretchr/testify/suite" -) - -type NilTest struct { - suite.Suite - logger Logger - realStdout *os.File - r *os.File - w *os.File -} - -func TestNilLogger(t *testing.T) { - suite.Run(t, new(NilTest)) -} - -func (t *NilTest) SetupSuite() { - t.logger = NewNil() -} - -func (t *NilTest) SetupTest() { - t.realStdout = os.Stdout - t.r, t.w, _ = os.Pipe() - os.Stdout = t.w -} - -func (t *NilTest) TearDownTest() { - if t.realStdout != nil { - t.Require().NoError(t.w.Close()) - os.Stdout = t.realStdout - } -} - -func (t *NilTest) readStdout() string { - outC := make(chan string) - go func() { - var buf bytes.Buffer - _, err := io.Copy(&buf, t.r) - t.Require().NoError(err) - outC <- buf.String() - close(outC) - }() - - t.Require().NoError(t.w.Close()) - os.Stdout = t.realStdout - t.realStdout = nil - - select { - case c := <-outC: - return c - case <-time.After(time.Second): - return "" - } -} - -func (t *NilTest) Test_Noop() { - t.logger.Critical("message") - t.logger.Criticalf("message") - t.logger.Error("message") - t.logger.Errorf("message") - t.logger.Warning("message") - t.logger.Warningf("message") - t.logger.Notice("message") - t.logger.Noticef("message") - t.logger.Info("message") - t.logger.Infof("message") - t.logger.Debug("message") - t.logger.Debugf("message") - - t.Assert().Empty(t.readStdout()) -} - -func (t *NilTest) Test_Panic() { - t.Assert().Panics(func() { - t.logger.Panic("") - }) -} - -func (t *NilTest) Test_Panicf() { - t.Assert().Panics(func() { - t.logger.Panicf("") - }) -} diff --git a/core/logger/prefix_decorator.go b/core/logger/prefix_decorator.go deleted file mode 100644 index 2e83912..0000000 --- a/core/logger/prefix_decorator.go +++ /dev/null @@ -1,111 +0,0 @@ -package logger - -import "github.com/op/go-logging" - -// PrefixAware is implemented if the logger allows you to change the prefix. -type PrefixAware interface { - SetPrefix(string) - Prefix() string -} - -// PrefixedLogger is a base interface for the logger with prefix. -type PrefixedLogger interface { - Logger - PrefixAware -} - -// PrefixDecorator is an implementation of the PrefixedLogger. It will allow you to decorate any Logger with -// the provided predefined prefix. -type PrefixDecorator struct { - backend Logger - prefix []interface{} -} - -// DecorateWithPrefix using provided base logger and provided prefix. -// No internal state of the base logger will be touched. -func DecorateWithPrefix(backend Logger, prefix string) PrefixedLogger { - return &PrefixDecorator{backend: backend, prefix: []interface{}{prefix}} -} - -// NewWithPrefix returns logger with prefix. It uses StandardLogger under the hood. -func NewWithPrefix(transportCode, prefix string, logLevel logging.Level, logFormat logging.Formatter) PrefixedLogger { - return DecorateWithPrefix(NewStandard(transportCode, logLevel, logFormat), prefix) -} - -// SetPrefix will replace existing prefix with the provided value. -// Use this format for prefixes: "prefix here:" - omit space at the end (it will be inserted automatically). -func (p *PrefixDecorator) SetPrefix(prefix string) { - p.prefix = []interface{}{prefix} -} - -func (p *PrefixDecorator) getFormat(fmt string) string { - return p.prefix[0].(string) + " " + fmt -} - -func (p *PrefixDecorator) Prefix() string { - return p.prefix[0].(string) -} - -func (p *PrefixDecorator) Fatal(args ...interface{}) { - p.backend.Fatal(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Fatalf(format string, args ...interface{}) { - p.backend.Fatalf(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Panic(args ...interface{}) { - p.backend.Panic(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Panicf(format string, args ...interface{}) { - p.backend.Panicf(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Critical(args ...interface{}) { - p.backend.Critical(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Criticalf(format string, args ...interface{}) { - p.backend.Criticalf(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Error(args ...interface{}) { - p.backend.Error(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Errorf(format string, args ...interface{}) { - p.backend.Errorf(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Warning(args ...interface{}) { - p.backend.Warning(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Warningf(format string, args ...interface{}) { - p.backend.Warningf(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Notice(args ...interface{}) { - p.backend.Notice(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Noticef(format string, args ...interface{}) { - p.backend.Noticef(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Info(args ...interface{}) { - p.backend.Info(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Infof(format string, args ...interface{}) { - p.backend.Infof(p.getFormat(format), args...) -} - -func (p *PrefixDecorator) Debug(args ...interface{}) { - p.backend.Debug(append(p.prefix, args...)...) -} - -func (p *PrefixDecorator) Debugf(format string, args ...interface{}) { - p.backend.Debugf(p.getFormat(format), args...) -} diff --git a/core/logger/prefix_decorator_test.go b/core/logger/prefix_decorator_test.go deleted file mode 100644 index 5b66ec5..0000000 --- a/core/logger/prefix_decorator_test.go +++ /dev/null @@ -1,167 +0,0 @@ -package logger - -import ( - "bytes" - "testing" - - "github.com/op/go-logging" - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/suite" -) - -const testPrefix = "TestPrefix:" - -type PrefixDecoratorTest struct { - suite.Suite - buf *bytes.Buffer - logger PrefixedLogger -} - -func TestPrefixDecorator(t *testing.T) { - suite.Run(t, new(PrefixDecoratorTest)) -} - -func TestNewWithPrefix(t *testing.T) { - buf := &bytes.Buffer{} - logger := NewWithPrefix("code", "Prefix:", logging.DEBUG, DefaultLogFormatter()) - logger.(*PrefixDecorator).backend.(*StandardLogger). - SetBaseLogger(NewBase(buf, "code", logging.DEBUG, DefaultLogFormatter())) - logger.Debugf("message %s", "text") - - assert.Contains(t, buf.String(), "Prefix: message text") -} - -func (t *PrefixDecoratorTest) SetupSuite() { - t.buf = &bytes.Buffer{} - t.logger = DecorateWithPrefix((&StandardLogger{}). - SetBaseLogger(NewBase(t.buf, "code", logging.DEBUG, DefaultLogFormatter())), testPrefix) -} - -func (t *PrefixDecoratorTest) SetupTest() { - t.buf.Reset() - t.logger.SetPrefix(testPrefix) -} - -func (t *PrefixDecoratorTest) Test_SetPrefix() { - t.logger.Info("message") - t.Assert().Equal(testPrefix, t.logger.Prefix()) - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), testPrefix+" message") - - t.logger.SetPrefix(testPrefix + testPrefix) - t.logger.Info("message") - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), testPrefix+testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Panic() { - t.Require().Panics(func() { - t.logger.Panic("message") - }) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Panicf() { - t.Require().Panics(func() { - t.logger.Panicf("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Critical() { - t.Require().NotPanics(func() { - t.logger.Critical("message") - }) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Criticalf() { - t.Require().NotPanics(func() { - t.logger.Criticalf("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "CRIT") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Error() { - t.Require().NotPanics(func() { - t.logger.Error("message") - }) - t.Assert().Contains(t.buf.String(), "ERRO") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Errorf() { - t.Require().NotPanics(func() { - t.logger.Errorf("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "ERRO") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Warning() { - t.Require().NotPanics(func() { - t.logger.Warning("message") - }) - t.Assert().Contains(t.buf.String(), "WARN") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Warningf() { - t.Require().NotPanics(func() { - t.logger.Warningf("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "WARN") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Notice() { - t.Require().NotPanics(func() { - t.logger.Notice("message") - }) - t.Assert().Contains(t.buf.String(), "NOTI") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Noticef() { - t.Require().NotPanics(func() { - t.logger.Noticef("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "NOTI") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Info() { - t.Require().NotPanics(func() { - t.logger.Info("message") - }) - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Infof() { - t.Require().NotPanics(func() { - t.logger.Infof("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "INFO") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Debug() { - t.Require().NotPanics(func() { - t.logger.Debug("message") - }) - t.Assert().Contains(t.buf.String(), "DEBU") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} - -func (t *PrefixDecoratorTest) Test_Debugf() { - t.Require().NotPanics(func() { - t.logger.Debugf("%s", "message") - }) - t.Assert().Contains(t.buf.String(), "DEBU") - t.Assert().Contains(t.buf.String(), testPrefix+" message") -} diff --git a/core/logger/zabbix_collector_adapter.go b/core/logger/zabbix_collector_adapter.go new file mode 100644 index 0000000..0dc9067 --- /dev/null +++ b/core/logger/zabbix_collector_adapter.go @@ -0,0 +1,19 @@ +package logger + +import ( + "fmt" + + metrics "github.com/retailcrm/zabbix-metrics-collector" +) + +type zabbixCollectorAdapter struct { + log Logger +} + +func (a *zabbixCollectorAdapter) Errorf(format string, args ...interface{}) { + a.log.Error(fmt.Sprintf(format, args...)) +} + +func ZabbixCollectorAdapter(log Logger) metrics.ErrorLogger { + return &zabbixCollectorAdapter{log: log} +} diff --git a/core/module_features_uploader.go b/core/module_features_uploader.go index f2979d9..33a9e44 100644 --- a/core/module_features_uploader.go +++ b/core/module_features_uploader.go @@ -5,6 +5,7 @@ import ( "context" "fmt" "html/template" + "log/slog" "os" "github.com/aws/aws-sdk-go-v2/aws" @@ -64,14 +65,13 @@ func NewModuleFeaturesUploader( awsConfig.WithCredentialsProvider(customProvider), ) if err != nil { - log.Fatal(err) + log.Error("cannot load S3 configuration", logger.ErrAttr(err)) return nil } client := manager.NewUploader(s3.NewFromConfig(cfg)) - if err != nil { - log.Fatal(err) + log.Error("cannot load S3 configuration", logger.ErrAttr(err)) return nil } @@ -87,18 +87,18 @@ func NewModuleFeaturesUploader( } func (s *ModuleFeaturesUploader) Upload() { - s.log.Debugf("upload module features started...") + s.log.Debug("upload module features started...") content, err := os.ReadFile(s.featuresFilename) if err != nil { - s.log.Errorf("cannot read markdown file %s %s", s.featuresFilename, err.Error()) + s.log.Error("cannot read markdown file %s %s", slog.String("fileName", s.featuresFilename), logger.ErrAttr(err)) return } for _, lang := range languages { translated, err := s.translate(content, lang) if err != nil { - s.log.Errorf("cannot translate module features file to %s: %s", lang.String(), err.Error()) + s.log.Error("cannot translate module features file", slog.String("lang", lang.String()), logger.ErrAttr(err)) continue } @@ -106,7 +106,7 @@ func (s *ModuleFeaturesUploader) Upload() { resp, err := s.uploadFile(html, lang.String()) if err != nil { - s.log.Errorf("cannot upload file %s: %s", lang.String(), err.Error()) + s.log.Error("cannot upload file", slog.String("lang", lang.String()), logger.ErrAttr(err)) continue } @@ -114,7 +114,7 @@ func (s *ModuleFeaturesUploader) Upload() { } fmt.Println() - s.log.Debugf("upload module features finished") + s.log.Debug("upload module features finished") } func (s *ModuleFeaturesUploader) translate(content []byte, lang language.Tag) ([]byte, error) { diff --git a/core/module_features_uploader_test.go b/core/module_features_uploader_test.go index 60bc9b1..936d688 100644 --- a/core/module_features_uploader_test.go +++ b/core/module_features_uploader_test.go @@ -1,19 +1,18 @@ package core import ( - "bytes" "context" - "github.com/aws/aws-sdk-go-v2/feature/s3/manager" "os" "testing" + "github.com/aws/aws-sdk-go-v2/feature/s3/manager" + "github.com/retailcrm/mg-transport-core/v2/core/util/testutil" + "github.com/aws/aws-sdk-go-v2/service/s3" - "github.com/op/go-logging" "github.com/stretchr/testify/suite" "golang.org/x/text/language" "github.com/retailcrm/mg-transport-core/v2/core/config" - "github.com/retailcrm/mg-transport-core/v2/core/logger" ) type ModuleFeaturesUploaderTest struct { @@ -36,8 +35,7 @@ func (t *ModuleFeaturesUploaderTest) TearDownSuite() { } func (t *ModuleFeaturesUploaderTest) TestModuleFeaturesUploader_NewModuleFeaturesUploader() { - logs := &bytes.Buffer{} - log := logger.NewBase(logs, "code", logging.DEBUG, logger.DefaultLogFormatter()) + log := testutil.NewBufferedLogger() conf := config.AWS{Bucket: "bucketName", FolderName: "folder/name"} uploader := NewModuleFeaturesUploader(log, conf, t.localizer, "filename.txt") @@ -50,8 +48,7 @@ func (t *ModuleFeaturesUploaderTest) TestModuleFeaturesUploader_NewModuleFeature } func (t *ModuleFeaturesUploaderTest) TestModuleFeaturesUploader_translate() { - logs := &bytes.Buffer{} - log := logger.NewBase(logs, "code", logging.DEBUG, logger.DefaultLogFormatter()) + log := testutil.NewBufferedLogger() conf := config.AWS{Bucket: "bucketName", FolderName: "folder/name"} uploader := NewModuleFeaturesUploader(log, conf, t.localizer, "filename.txt") content := "test content " + t.localizer.GetLocalizedMessage("message") @@ -62,8 +59,7 @@ func (t *ModuleFeaturesUploaderTest) TestModuleFeaturesUploader_translate() { } func (t *ModuleFeaturesUploaderTest) TestModuleFeaturesUploader_uploadFile() { - logs := &bytes.Buffer{} - log := logger.NewBase(logs, "code", logging.DEBUG, logger.DefaultLogFormatter()) + log := testutil.NewBufferedLogger() conf := config.AWS{Bucket: "bucketName", FolderName: "folder/name"} uploader := NewModuleFeaturesUploader(log, conf, t.localizer, "source.md") content := "test content" diff --git a/core/sentry.go b/core/sentry.go index 3511c1c..b7d2e0c 100644 --- a/core/sentry.go +++ b/core/sentry.go @@ -2,6 +2,7 @@ package core import ( "fmt" + "log/slog" "net" "net/http" "net/http/httputil" @@ -22,9 +23,6 @@ import ( "github.com/gin-gonic/gin" ) -// reset is borrowed directly from the gin. -const reset = "\033[0m" - // ErrorHandlerFunc will handle errors. type ErrorHandlerFunc func(recovery interface{}, c *gin.Context) @@ -142,17 +140,17 @@ func (s *Sentry) SentryMiddlewares() []gin.HandlerFunc { // obtainErrorLogger extracts logger from the context or builds it right here from tags used in Sentry events // Those tags can be configured with SentryLoggerConfig field. -func (s *Sentry) obtainErrorLogger(c *gin.Context) logger.AccountLogger { +func (s *Sentry) obtainErrorLogger(c *gin.Context) logger.Logger { if item, ok := c.Get("logger"); ok { - if accountLogger, ok := item.(logger.AccountLogger); ok { - return accountLogger + if ctxLogger, ok := item.(logger.Logger); ok { + return ctxLogger } } connectionID := "{no connection ID}" accountID := "{no account ID}" if s.SentryLoggerConfig.TagForConnection == "" && s.SentryLoggerConfig.TagForAccount == "" { - return logger.DecorateForAccount(s.Logger, "Sentry", connectionID, accountID) + return s.Logger.ForAccount("Sentry", connectionID, accountID) } for tag := range s.tagsFromContext(c) { @@ -164,7 +162,7 @@ func (s *Sentry) obtainErrorLogger(c *gin.Context) logger.AccountLogger { } } - return logger.DecorateForAccount(s.Logger, "Sentry", connectionID, accountID) + return s.Logger.ForAccount("Sentry", connectionID, accountID) } // tagsSetterMiddleware sets event tags into Sentry events. @@ -201,13 +199,13 @@ func (s *Sentry) exceptionCaptureMiddleware() gin.HandlerFunc { // nolint:gocogn for _, err := range publicErrors { messages[index] = err.Error() s.CaptureException(c, err) - l.Error(err) + l.Error(err.Error()) index++ } for _, err := range privateErrors { s.CaptureException(c, err) - l.Error(err) + l.Error(err.Error()) } if privateLen > 0 || recovery != nil { @@ -250,8 +248,9 @@ func (s *Sentry) recoveryMiddleware() gin.HandlerFunc { // nolint } } if l != nil { - stack := stacktrace.FormattedStack(3, l.Prefix()+" ") - formattedErr := fmt.Sprintf("%s %s", l.Prefix(), err) + // TODO: Check if we can output stacktraces with prefix data like before if we really need it. + stack := stacktrace.FormattedStack(3, "trace: ") + formattedErr := logger.ErrAttr(err) httpRequest, _ := httputil.DumpRequest(c.Request, false) headers := strings.Split(string(httpRequest), "\r\n") for idx, header := range headers { @@ -259,18 +258,17 @@ func (s *Sentry) recoveryMiddleware() gin.HandlerFunc { // nolint if current[0] == "Authorization" { headers[idx] = current[0] + ": *" } - headers[idx] = l.Prefix() + " " + headers[idx] + headers[idx] = "header: " + headers[idx] } - headersToStr := strings.Join(headers, "\r\n") + headersToStr := slog.String("headers", strings.Join(headers, "\r\n")) + formattedStack := slog.String("stacktrace", string(stack)) switch { case brokenPipe: - l.Errorf("%s\n%s%s", formattedErr, headersToStr, reset) + l.Error("error", formattedErr, headersToStr) case gin.IsDebugging(): - l.Errorf("[Recovery] %s panic recovered:\n%s\n%s\n%s%s", - timeFormat(time.Now()), headersToStr, formattedErr, stack, reset) + l.Error("[Recovery] panic recovered", headersToStr, formattedErr, formattedStack) default: - l.Errorf("[Recovery] %s panic recovered:\n%s\n%s%s", - timeFormat(time.Now()), formattedErr, stack, reset) + l.Error("[Recovery] panic recovered", formattedErr, formattedStack) } } if brokenPipe { diff --git a/core/sentry_test.go b/core/sentry_test.go index 9a8d319..fe574f2 100644 --- a/core/sentry_test.go +++ b/core/sentry_test.go @@ -2,7 +2,6 @@ package core import ( "errors" - "fmt" "net/http" "net/http/httptest" "sync" @@ -278,7 +277,7 @@ func (s *SentryTest) TestSentry_CaptureException() { func (s *SentryTest) TestSentry_obtainErrorLogger_Existing() { ctx, _ := s.ginCtxMock() - log := logger.DecorateForAccount(testutil.NewBufferedLogger(), "component", "conn", "acc") + log := testutil.NewBufferedLogger().ForAccount("component", "conn", "acc") ctx.Set("logger", log) s.Assert().Equal(log, s.sentry.obtainErrorLogger(ctx)) @@ -299,12 +298,8 @@ func (s *SentryTest) TestSentry_obtainErrorLogger_Constructed() { s.Assert().NotNil(log) s.Assert().NotNil(logNoConfig) - s.Assert().Implements((*logger.AccountLogger)(nil), log) - s.Assert().Implements((*logger.AccountLogger)(nil), logNoConfig) - s.Assert().Equal( - fmt.Sprintf(logger.DefaultAccountLoggerFormat, "Sentry", "{no connection ID}", "{no account ID}"), - logNoConfig.Prefix()) - s.Assert().Equal(fmt.Sprintf(logger.DefaultAccountLoggerFormat, "Sentry", "conn_url", "acc_name"), log.Prefix()) + s.Assert().Implements((*logger.Logger)(nil), log) + s.Assert().Implements((*logger.Logger)(nil), logNoConfig) } func (s *SentryTest) TestSentry_MiddlewaresError() { diff --git a/core/util/httputil/http_client_builder.go b/core/util/httputil/http_client_builder.go index 3e1a17b..0948fcb 100644 --- a/core/util/httputil/http_client_builder.go +++ b/core/util/httputil/http_client_builder.go @@ -5,6 +5,7 @@ import ( "crypto/tls" "crypto/x509" "fmt" + "log/slog" "net" "net/http" "net/url" @@ -231,11 +232,11 @@ func (b *HTTPClientBuilder) buildMocks() error { } if b.mockHost != "" && b.mockPort != "" && len(b.mockedDomains) > 0 { - b.logf("Mock address is \"%s\"\n", net.JoinHostPort(b.mockHost, b.mockPort)) - b.logf("Mocked domains: ") + b.log("Mock address has been set", slog.String("address", net.JoinHostPort(b.mockHost, b.mockPort))) + b.log("Mocked domains: ") for _, domain := range b.mockedDomains { - b.logf(" - %s\n", domain) + b.log(fmt.Sprintf(" - %s\n", domain)) } b.httpTransport.Proxy = nil @@ -259,7 +260,7 @@ func (b *HTTPClientBuilder) buildMocks() error { addr = net.JoinHostPort(b.mockHost, b.mockPort) } - b.logf("Mocking \"%s\" with \"%s\"\n", oldAddr, addr) + b.log(fmt.Sprintf("Mocking \"%s\" with \"%s\"\n", oldAddr, addr)) } } @@ -270,13 +271,13 @@ func (b *HTTPClientBuilder) buildMocks() error { return nil } -// logf prints logs via Engine or via fmt.Printf. -func (b *HTTPClientBuilder) logf(format string, args ...interface{}) { +// log prints logs via Engine or via fmt.Println. +func (b *HTTPClientBuilder) log(msg string, args ...interface{}) { if b.logging { if b.logger != nil { - b.logger.Infof(format, args...) + b.logger.Info(msg, args...) } else { - fmt.Printf(format, args...) + fmt.Println(append([]any{msg}, args...)) } } } diff --git a/core/util/httputil/http_client_builder_test.go b/core/util/httputil/http_client_builder_test.go index 277e281..dae78c4 100644 --- a/core/util/httputil/http_client_builder_test.go +++ b/core/util/httputil/http_client_builder_test.go @@ -16,7 +16,6 @@ import ( "testing" "time" - "github.com/op/go-logging" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/stretchr/testify/suite" @@ -137,14 +136,14 @@ func (t *HTTPClientBuilderTest) Test_buildMocks() { } func (t *HTTPClientBuilderTest) Test_WithLogger() { - logger := logger.NewStandard("telegram", logging.ERROR, logger.DefaultLogFormatter()) builder := NewHTTPClientBuilder() require.Nil(t.T(), builder.logger) builder.WithLogger(nil) assert.Nil(t.T(), builder.logger) - builder.WithLogger(logger) + log := logger.NewDefaultText() + builder.WithLogger(log) assert.NotNil(t.T(), builder.logger) } @@ -153,7 +152,7 @@ func (t *HTTPClientBuilderTest) Test_logf() { assert.Nil(t.T(), recover()) }() - t.builder.logf("test %s", "string") + t.builder.log(fmt.Sprintf("test %s", "string")) } func (t *HTTPClientBuilderTest) Test_Build() { diff --git a/core/util/testutil/buffer_logger.go b/core/util/testutil/buffer_logger.go index 79619d6..f28713d 100644 --- a/core/util/testutil/buffer_logger.go +++ b/core/util/testutil/buffer_logger.go @@ -1,13 +1,9 @@ package testutil import ( - "bytes" "fmt" "io" - "os" - "sync" - - "github.com/op/go-logging" + "log/slog" "github.com/retailcrm/mg-transport-core/v2/core/logger" ) @@ -29,119 +25,46 @@ type BufferedLogger interface { // BufferLogger is an implementation of the BufferedLogger. type BufferLogger struct { - buf bytes.Buffer - rw sync.RWMutex + logger.Default + buf LockableBuffer } // NewBufferedLogger returns new BufferedLogger instance. func NewBufferedLogger() BufferedLogger { - return &BufferLogger{} + bl := &BufferLogger{} + bl.Logger = slog.New(slog.NewTextHandler(&bl.buf, logger.DefaultOpts)) + return bl +} + +// With doesn't do anything here and only added for backwards compatibility with the interface. +func (l *BufferLogger) With(args ...any) logger.Logger { + return &BufferLogger{ + Default: logger.Default{ + Logger: l.Logger.With(args...), + }, + } +} + +func (l *BufferLogger) ForAccount(handler, conn, acc any) logger.Logger { + return l.With(slog.Any(logger.HandlerAttr, handler), slog.Any(logger.ConnectionAttr, conn), slog.Any(logger.AccountAttr, acc)) } // Read bytes from the logger buffer. io.Reader implementation. func (l *BufferLogger) Read(p []byte) (n int, err error) { - defer l.rw.RUnlock() - l.rw.RLock() return l.buf.Read(p) } // String contents of the logger buffer. fmt.Stringer implementation. func (l *BufferLogger) String() string { - defer l.rw.RUnlock() - l.rw.RLock() return l.buf.String() } // Bytes is a shorthand for the underlying bytes.Buffer method. Returns byte slice with the buffer contents. func (l *BufferLogger) Bytes() []byte { - defer l.rw.RUnlock() - l.rw.RLock() return l.buf.Bytes() } // Reset is a shorthand for the underlying bytes.Buffer method. It will reset buffer contents. func (l *BufferLogger) Reset() { - defer l.rw.Unlock() - l.rw.Lock() l.buf.Reset() } - -func (l *BufferLogger) write(level logging.Level, args ...interface{}) { - defer l.rw.Unlock() - l.rw.Lock() - l.buf.WriteString(fmt.Sprintln(append([]interface{}{level.String(), "=>"}, args...)...)) -} - -func (l *BufferLogger) writef(level logging.Level, format string, args ...interface{}) { - defer l.rw.Unlock() - l.rw.Lock() - l.buf.WriteString(fmt.Sprintf(level.String()+" => "+format, args...)) -} - -func (l *BufferLogger) Fatal(args ...interface{}) { - l.write(logging.CRITICAL, args...) - os.Exit(1) -} - -func (l *BufferLogger) Fatalf(format string, args ...interface{}) { - l.writef(logging.CRITICAL, format, args...) - os.Exit(1) -} - -func (l *BufferLogger) Panic(args ...interface{}) { - l.write(logging.CRITICAL, args...) - panic(fmt.Sprint(args...)) -} - -func (l *BufferLogger) Panicf(format string, args ...interface{}) { - l.writef(logging.CRITICAL, format, args...) - panic(fmt.Sprintf(format, args...)) -} - -func (l *BufferLogger) Critical(args ...interface{}) { - l.write(logging.CRITICAL, args...) -} - -func (l *BufferLogger) Criticalf(format string, args ...interface{}) { - l.writef(logging.CRITICAL, format, args...) -} - -func (l *BufferLogger) Error(args ...interface{}) { - l.write(logging.ERROR, args...) -} - -func (l *BufferLogger) Errorf(format string, args ...interface{}) { - l.writef(logging.ERROR, format, args...) -} - -func (l *BufferLogger) Warning(args ...interface{}) { - l.write(logging.WARNING, args...) -} - -func (l *BufferLogger) Warningf(format string, args ...interface{}) { - l.writef(logging.WARNING, format, args...) -} - -func (l *BufferLogger) Notice(args ...interface{}) { - l.write(logging.NOTICE, args...) -} - -func (l *BufferLogger) Noticef(format string, args ...interface{}) { - l.writef(logging.NOTICE, format, args...) -} - -func (l *BufferLogger) Info(args ...interface{}) { - l.write(logging.INFO, args...) -} - -func (l *BufferLogger) Infof(format string, args ...interface{}) { - l.writef(logging.INFO, format, args...) -} - -func (l *BufferLogger) Debug(args ...interface{}) { - l.write(logging.DEBUG, args...) -} - -func (l *BufferLogger) Debugf(format string, args ...interface{}) { - l.writef(logging.DEBUG, format, args...) -} diff --git a/core/util/testutil/buffer_logger_test.go b/core/util/testutil/buffer_logger_test.go index 8a76d2a..0bfa23e 100644 --- a/core/util/testutil/buffer_logger_test.go +++ b/core/util/testutil/buffer_logger_test.go @@ -4,7 +4,6 @@ import ( "io" "testing" - "github.com/op/go-logging" "github.com/stretchr/testify/suite" ) @@ -30,17 +29,17 @@ func (t *BufferLoggerTest) Test_Read() { data, err := io.ReadAll(t.logger) t.Require().NoError(err) - t.Assert().Equal([]byte(logging.DEBUG.String()+" => test\n"), data) + t.Assert().Contains(string(data), "level=DEBUG msg=test") } func (t *BufferLoggerTest) Test_Bytes() { t.logger.Debug("test") - t.Assert().Equal([]byte(logging.DEBUG.String()+" => test\n"), t.logger.Bytes()) + t.Assert().Contains(string(t.logger.Bytes()), "level=DEBUG msg=test") } func (t *BufferLoggerTest) Test_String() { t.logger.Debug("test") - t.Assert().Equal(logging.DEBUG.String()+" => test\n", t.logger.String()) + t.Assert().Contains(t.logger.String(), "level=DEBUG msg=test") } func (t *BufferLoggerTest) TestRace() { diff --git a/core/util/testutil/lockable_buffer.go b/core/util/testutil/lockable_buffer.go new file mode 100644 index 0000000..ae71356 --- /dev/null +++ b/core/util/testutil/lockable_buffer.go @@ -0,0 +1,150 @@ +package testutil + +import ( + "bytes" + "io" + "sync" +) + +type LockableBuffer struct { + buf bytes.Buffer + rw sync.RWMutex +} + +func (b *LockableBuffer) Bytes() []byte { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.Bytes() +} + +func (b *LockableBuffer) AvailableBuffer() []byte { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.AvailableBuffer() +} + +func (b *LockableBuffer) String() string { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.String() +} + +func (b *LockableBuffer) Len() int { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.Len() +} + +func (b *LockableBuffer) Cap() int { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.Cap() +} + +func (b *LockableBuffer) Available() int { + defer b.rw.RUnlock() + b.rw.RLock() + return b.buf.Available() +} + +func (b *LockableBuffer) Truncate(n int) { + defer b.rw.Unlock() + b.rw.Lock() + b.buf.Truncate(n) +} + +func (b *LockableBuffer) Reset() { + defer b.rw.Unlock() + b.rw.Lock() + b.buf.Reset() +} + +func (b *LockableBuffer) Grow(n int) { + defer b.rw.Unlock() + b.rw.Lock() + b.buf.Grow(n) +} + +func (b *LockableBuffer) Write(p []byte) (n int, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.Write(p) +} + +func (b *LockableBuffer) WriteString(s string) (n int, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.WriteString(s) +} + +func (b *LockableBuffer) ReadFrom(r io.Reader) (n int64, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.ReadFrom(r) +} + +func (b *LockableBuffer) WriteTo(w io.Writer) (n int64, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.WriteTo(w) +} + +func (b *LockableBuffer) WriteByte(c byte) error { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.WriteByte(c) +} + +func (b *LockableBuffer) WriteRune(r rune) (n int, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.WriteRune(r) +} + +func (b *LockableBuffer) Read(p []byte) (n int, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.Read(p) +} + +func (b *LockableBuffer) Next(n int) []byte { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.Next(n) +} + +func (b *LockableBuffer) ReadByte() (byte, error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.ReadByte() +} + +func (b *LockableBuffer) ReadRune() (r rune, size int, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.ReadRune() +} + +func (b *LockableBuffer) UnreadRune() error { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.UnreadRune() +} + +func (b *LockableBuffer) UnreadByte() error { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.UnreadByte() +} + +func (b *LockableBuffer) ReadBytes(delim byte) (line []byte, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.ReadBytes(delim) +} + +func (b *LockableBuffer) ReadString(delim byte) (line string, err error) { + defer b.rw.Unlock() + b.rw.Lock() + return b.buf.ReadString(delim) +} diff --git a/core/util/utils.go b/core/util/utils.go index 2ff8f5f..92914c0 100644 --- a/core/util/utils.go +++ b/core/util/utils.go @@ -132,7 +132,7 @@ func (u *Utils) GenerateToken() string { func (u *Utils) GetAPIClient( url, key string, scopes []string, credentials ...[]string) (*retailcrm.Client, int, error) { client := retailcrm.New(url, key). - WithLogger(retailcrm.DebugLoggerAdapter(u.Logger)) + WithLogger(logger.APIClientAdapter(u.Logger)) client.Debug = u.IsDebug cr, status, err := client.APICredentials() diff --git a/core/util/utils_test.go b/core/util/utils_test.go index ce7a015..2890c54 100644 --- a/core/util/utils_test.go +++ b/core/util/utils_test.go @@ -9,7 +9,7 @@ import ( "time" "github.com/h2non/gock" - "github.com/op/go-logging" + retailcrm "github.com/retailcrm/api-client-go/v2" v1 "github.com/retailcrm/mg-transport-api-client-go/v1" "github.com/stretchr/testify/assert" @@ -38,7 +38,7 @@ func mgClient() *v1.MgClient { } func (u *UtilsTest) SetupSuite() { - logger := logger.NewStandard("code", logging.DEBUG, logger.DefaultLogFormatter()) + logger := logger.NewDefaultText() awsConfig := config.AWS{ AccessKeyID: "access key id (will be removed)", SecretAccessKey: "secret access key", diff --git a/go.mod b/go.mod index 0a8c1e7..9d9e50e 100644 --- a/go.mod +++ b/go.mod @@ -1,6 +1,6 @@ module github.com/retailcrm/mg-transport-core/v2 -go 1.18 +go 1.21 require ( github.com/DATA-DOG/go-sqlmock v1.3.3 diff --git a/go.sum b/go.sum index 6f7ec25..ae08450 100644 --- a/go.sum +++ b/go.sum @@ -157,6 +157,7 @@ github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2 github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE= github.com/go-martini/martini v0.0.0-20170121215854-22fa46961aab/go.mod h1:/P9AEU963A2AYjv4d1V5eVL1CQbEJq6aCNHDDjibzu8= github.com/go-playground/assert/v2 v2.2.0 h1:JvknZsQTYeFEAhQwI4qEt9cyV5ONwRHC+lYKSsYSR8s= +github.com/go-playground/assert/v2 v2.2.0/go.mod h1:VDjEfimB/XKnb+ZQfWdccd7VUvScMdVu0Titje2rxJ4= github.com/go-playground/locales v0.14.1 h1:EWaQ/wswjilfKLTECiXz7Rh+3BjFhfDFKv/oXslEjJA= github.com/go-playground/locales v0.14.1/go.mod h1:hxrqLVvrK65+Rwrd5Fc6F2O76J/NuW9t0sjnWqG1slY= github.com/go-playground/universal-translator v0.18.1 h1:Bcnm0ZwsGyWbCzImXv+pAJnYK9S473LQFuzCbDbfSFY=