From 2f8def6f8c385201ee7f18709ebcce6aa435ea14 Mon Sep 17 00:00:00 2001 From: Mobin Hosseini Date: Fri, 17 Jun 2022 14:35:15 +0300 Subject: [PATCH] Add metrics to zerolog and std logger (#517) --- log/log.go | 116 +++++++++++++++++++++++++------------ log/log_test.go | 34 ++++++----- log/std/logger.go | 12 ++++ log/std/logger_test.go | 38 ++++++++++++ log/zerolog/logger.go | 12 ++++ log/zerolog/logger_test.go | 37 ++++++++++++ 6 files changed, 198 insertions(+), 51 deletions(-) diff --git a/log/log.go b/log/log.go index e03a7d75f..7f0f36698 100644 --- a/log/log.go +++ b/log/log.go @@ -31,20 +31,26 @@ const ( NoLevel Level = "" ) -var levelOrder = map[Level]int{ - DebugLevel: 0, - InfoLevel: 1, - WarnLevel: 2, - ErrorLevel: 3, - FatalLevel: 4, - PanicLevel: 5, - NoLevel: 6, -} - -// LevelOrder returns the numerical order of the level. -func LevelOrder(lvl Level) int { - return levelOrder[lvl] -} +var ( + levelOrder = map[Level]int{ + DebugLevel: 0, + InfoLevel: 1, + WarnLevel: 2, + ErrorLevel: 3, + FatalLevel: 4, + PanicLevel: 5, + NoLevel: 6, + } + logCounter = prometheus.NewCounterVec( + prometheus.CounterOpts{ + Namespace: "observability", + Subsystem: "log", + Name: "counter", + Help: "Counts logger calls per level", + }, + []string{"level"}, + ) +) // Logger interface definition of a logger. type Logger interface { @@ -67,23 +73,59 @@ type Logger interface { type ctxKey struct{} var ( - logger Logger = &fmtLogger{} - once sync.Once - logCounter = prometheus.NewCounterVec( - prometheus.CounterOpts{ - Namespace: "observability", - Subsystem: "log", - Name: "counter", - Help: "Counts the log level", - }, - []string{"level"}, - ) + logger Logger = &fmtLogger{} + once sync.Once ) func init() { prometheus.MustRegister(logCounter) } +// LevelCount returns the total level count. +func LevelCount(level string) prometheus.Counter { + return logCounter.WithLabelValues(level) +} + +// ResetLogCounter resets the log counter. +func ResetLogCounter() { + logCounter.Reset() +} + +// IncreaseFatalCounter increases the fatal counter. +func IncreaseFatalCounter() { + logCounter.WithLabelValues(string(FatalLevel)).Inc() +} + +// IncreasePanicCounter increases the panic counter. +func IncreasePanicCounter() { + logCounter.WithLabelValues(string(PanicLevel)).Inc() +} + +// IncreaseErrorCounter increases the error counter. +func IncreaseErrorCounter() { + logCounter.WithLabelValues(string(ErrorLevel)).Inc() +} + +// IncreaseWarnCounter increases the warn counter. +func IncreaseWarnCounter() { + logCounter.WithLabelValues(string(WarnLevel)).Inc() +} + +// IncreaseInfoCounter increases the info counter. +func IncreaseInfoCounter() { + logCounter.WithLabelValues(string(InfoLevel)).Inc() +} + +// IncreaseDebugCounter increases the debug counter. +func IncreaseDebugCounter() { + logCounter.WithLabelValues(string(DebugLevel)).Inc() +} + +// LevelOrder returns the numerical order of the level. +func LevelOrder(lvl Level) int { + return levelOrder[lvl] +} + // Setup logging by providing a logger factory. func Setup(l Logger) error { if l == nil { @@ -119,73 +161,61 @@ func Sub(ff map[string]interface{}) Logger { // Panic logging. func Panic(args ...interface{}) { - logCounter.WithLabelValues(string(PanicLevel)).Inc() logger.Panic(args...) } // Panicf logging. func Panicf(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(PanicLevel)).Inc() logger.Panicf(msg, args...) } // Fatal logging. func Fatal(args ...interface{}) { - logCounter.WithLabelValues(string(FatalLevel)).Inc() logger.Fatal(args...) } // Fatalf logging. func Fatalf(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(FatalLevel)).Inc() logger.Fatalf(msg, args...) } // Error logging. func Error(args ...interface{}) { - logCounter.WithLabelValues(string(ErrorLevel)).Inc() logger.Error(args...) } // Errorf logging. func Errorf(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(ErrorLevel)).Inc() logger.Errorf(msg, args...) } // Warn logging. func Warn(args ...interface{}) { - logCounter.WithLabelValues(string(WarnLevel)).Inc() logger.Warn(args...) } // Warnf logging. func Warnf(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(WarnLevel)).Inc() logger.Warnf(msg, args...) } // Info logging. func Info(args ...interface{}) { - logCounter.WithLabelValues(string(InfoLevel)).Inc() logger.Info(args...) } // Infof logging. func Infof(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(InfoLevel)).Inc() logger.Infof(msg, args...) } // Debug logging. func Debug(args ...interface{}) { - logCounter.WithLabelValues(string(DebugLevel)).Inc() logger.Debug(args...) } // Debugf logging. func Debugf(msg string, args ...interface{}) { - logCounter.WithLabelValues(string(DebugLevel)).Inc() logger.Debugf(msg, args...) } @@ -203,65 +233,77 @@ func (fl *fmtLogger) Sub(map[string]interface{}) Logger { // Panic logging. func (fl *fmtLogger) Panic(args ...interface{}) { + IncreasePanicCounter() fmt.Print(args...) panic(args) } // Panicf logging. func (fl *fmtLogger) Panicf(msg string, args ...interface{}) { + IncreasePanicCounter() fmt.Printf(msg, args...) panic(args) } // Fatal logging. func (fl *fmtLogger) Fatal(args ...interface{}) { + IncreaseFatalCounter() fmt.Print(args...) os.Exit(1) } // Fatalf logging. func (fl *fmtLogger) Fatalf(msg string, args ...interface{}) { + IncreaseFatalCounter() fmt.Printf(msg, args...) os.Exit(1) } // Error logging. func (fl *fmtLogger) Error(args ...interface{}) { + IncreaseErrorCounter() fmt.Print(args...) } // Errorf logging. func (fl *fmtLogger) Errorf(msg string, args ...interface{}) { + IncreaseErrorCounter() fmt.Printf(msg, args...) } // Warn logging. func (fl *fmtLogger) Warn(args ...interface{}) { + IncreaseWarnCounter() fmt.Print(args...) } // Warnf logging. func (fl *fmtLogger) Warnf(msg string, args ...interface{}) { + IncreaseWarnCounter() fmt.Printf(msg, args...) } // Info logging. func (fl *fmtLogger) Info(args ...interface{}) { + IncreaseInfoCounter() fmt.Print(args...) } // Infof logging. func (fl *fmtLogger) Infof(msg string, args ...interface{}) { + IncreaseInfoCounter() fmt.Printf(msg, args...) } // Debug logging. func (fl *fmtLogger) Debug(args ...interface{}) { + IncreaseDebugCounter() fmt.Print(args...) } // Debugf logging. func (fl *fmtLogger) Debugf(msg string, args ...interface{}) { + IncreaseDebugCounter() fmt.Printf(msg, args...) } diff --git a/log/log_test.go b/log/log_test.go index f10e77b19..fd7b48ea8 100644 --- a/log/log_test.go +++ b/log/log_test.go @@ -37,30 +37,36 @@ func TestLevelOrder(t *testing.T) { func TestLogMetrics(t *testing.T) { t.Parallel() - logCounter.Reset() - l := testLogger{} - logger = &l + ResetLogCounter() + l = &fmtLogger{} tests := map[string]struct { lvl Level logfunc func(args ...interface{}) logfuncf func(msg string, args ...interface{}) }{ - "debug": {lvl: DebugLevel, logfunc: Debug, logfuncf: Debugf}, - "info": {lvl: InfoLevel, logfunc: Info, logfuncf: Infof}, - "warn": {lvl: WarnLevel, logfunc: Warn, logfuncf: Warnf}, - "error": {lvl: ErrorLevel, logfunc: Error, logfuncf: Errorf}, - "fatal": {lvl: FatalLevel, logfunc: Fatal, logfuncf: Fatalf}, - "panic": {lvl: PanicLevel, logfunc: Panic, logfuncf: Panicf}, + "debug": {lvl: DebugLevel, logfunc: l.Debug, logfuncf: l.Debugf}, + "info": {lvl: InfoLevel, logfunc: l.Info, logfuncf: l.Infof}, + "warn": {lvl: WarnLevel, logfunc: l.Warn, logfuncf: l.Warnf}, + "error": {lvl: ErrorLevel, logfunc: l.Error, logfuncf: l.Errorf}, + "panic": {lvl: PanicLevel, logfunc: l.Panic, logfuncf: l.Panicf}, } for name, tt := range tests { tt := tt t.Run(name, func(t *testing.T) { t.Parallel() - assert.Equal(t, 0.0, testutil.ToFloat64(logCounter.WithLabelValues(string(tt.lvl)))) - tt.logfunc(name) - assert.Equal(t, 1.0, testutil.ToFloat64(logCounter.WithLabelValues(string(tt.lvl)))) - tt.logfuncf(name) - assert.Equal(t, 2.0, testutil.ToFloat64(logCounter.WithLabelValues(string(tt.lvl)))) + assert.Equal(t, 0.0, testutil.ToFloat64(LevelCount(string(tt.lvl)))) + if tt.lvl == PanicLevel { + assert.Panics(t, func() { tt.logfunc(name) }) + } else { + tt.logfunc(name) + } + assert.Equal(t, 1.0, testutil.ToFloat64(LevelCount(string(tt.lvl)))) + if tt.lvl == PanicLevel { + assert.Panics(t, func() { tt.logfuncf(name) }) + } else { + tt.logfuncf(name) + } + assert.Equal(t, 2.0, testutil.ToFloat64(LevelCount(string(tt.lvl)))) }) } } diff --git a/log/std/logger.go b/log/std/logger.go index 7a848be19..a002247fb 100644 --- a/log/std/logger.go +++ b/log/std/logger.go @@ -99,6 +99,7 @@ func (l *Logger) Sub(fields map[string]interface{}) patronLog.Logger { // Fatal logging. func (l *Logger) Fatal(args ...interface{}) { + patronLog.IncreaseFatalCounter() if !l.shouldLog(patronLog.FatalLevel) { return } @@ -109,6 +110,7 @@ func (l *Logger) Fatal(args ...interface{}) { // Fatalf logging. func (l *Logger) Fatalf(msg string, args ...interface{}) { + patronLog.IncreaseFatalCounter() if !l.shouldLog(patronLog.FatalLevel) { return } @@ -119,6 +121,7 @@ func (l *Logger) Fatalf(msg string, args ...interface{}) { // Panic logging. func (l *Logger) Panic(args ...interface{}) { + patronLog.IncreasePanicCounter() if !l.shouldLog(patronLog.PanicLevel) { return } @@ -128,6 +131,7 @@ func (l *Logger) Panic(args ...interface{}) { // Panicf logging. func (l *Logger) Panicf(msg string, args ...interface{}) { + patronLog.IncreasePanicCounter() if !l.shouldLog(patronLog.PanicLevel) { return } @@ -137,6 +141,7 @@ func (l *Logger) Panicf(msg string, args ...interface{}) { // Error logging. func (l *Logger) Error(args ...interface{}) { + patronLog.IncreaseErrorCounter() if !l.shouldLog(patronLog.ErrorLevel) { return } @@ -146,6 +151,7 @@ func (l *Logger) Error(args ...interface{}) { // Errorf logging. func (l *Logger) Errorf(msg string, args ...interface{}) { + patronLog.IncreaseErrorCounter() if !l.shouldLog(patronLog.ErrorLevel) { return } @@ -155,6 +161,7 @@ func (l *Logger) Errorf(msg string, args ...interface{}) { // Warn logging. func (l *Logger) Warn(args ...interface{}) { + patronLog.IncreaseWarnCounter() if !l.shouldLog(patronLog.WarnLevel) { return } @@ -164,6 +171,7 @@ func (l *Logger) Warn(args ...interface{}) { // Warnf logging. func (l *Logger) Warnf(msg string, args ...interface{}) { + patronLog.IncreaseWarnCounter() if !l.shouldLog(patronLog.WarnLevel) { return } @@ -173,6 +181,7 @@ func (l *Logger) Warnf(msg string, args ...interface{}) { // Info logging. func (l *Logger) Info(args ...interface{}) { + patronLog.IncreaseInfoCounter() if !l.shouldLog(patronLog.InfoLevel) { return } @@ -182,6 +191,7 @@ func (l *Logger) Info(args ...interface{}) { // Infof logging. func (l *Logger) Infof(msg string, args ...interface{}) { + patronLog.IncreaseInfoCounter() if !l.shouldLog(patronLog.InfoLevel) { return } @@ -191,6 +201,7 @@ func (l *Logger) Infof(msg string, args ...interface{}) { // Debug logging. func (l *Logger) Debug(args ...interface{}) { + patronLog.IncreaseDebugCounter() if !l.shouldLog(patronLog.DebugLevel) { return } @@ -200,6 +211,7 @@ func (l *Logger) Debug(args ...interface{}) { // Debugf logging. func (l *Logger) Debugf(msg string, args ...interface{}) { + patronLog.IncreaseDebugCounter() if !l.shouldLog(patronLog.DebugLevel) { return } diff --git a/log/std/logger_test.go b/log/std/logger_test.go index 40ec2c8dc..2dcf7b5c1 100644 --- a/log/std/logger_test.go +++ b/log/std/logger_test.go @@ -7,6 +7,7 @@ import ( "time" "github.com/beatlabs/patron/log" + "github.com/prometheus/client_golang/prometheus/testutil" "github.com/stretchr/testify/assert" ) @@ -25,6 +26,43 @@ func TestNewLogger(t *testing.T) { assert.Contains(t, logger.fieldsLine, "name=john doe") } +func TestLogMetrics(t *testing.T) { + t.Parallel() + log.ResetLogCounter() + var b bytes.Buffer + l := New(&b, log.InfoLevel, nil) + tests := map[string]struct { + lvl log.Level + logfunc func(args ...interface{}) + logfuncf func(msg string, args ...interface{}) + }{ + "debug": {lvl: log.DebugLevel, logfunc: l.Debug, logfuncf: l.Debugf}, + "info": {lvl: log.InfoLevel, logfunc: l.Info, logfuncf: l.Infof}, + "warn": {lvl: log.WarnLevel, logfunc: l.Warn, logfuncf: l.Warnf}, + "error": {lvl: log.ErrorLevel, logfunc: l.Error, logfuncf: l.Errorf}, + "panic": {lvl: log.PanicLevel, logfunc: l.Panic, logfuncf: l.Panicf}, + } + for name, tt := range tests { + tt := tt + t.Run(name, func(t *testing.T) { + t.Parallel() + assert.Equal(t, 0.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + if tt.lvl == log.PanicLevel { + assert.Panics(t, func() { tt.logfunc(name) }) + } else { + tt.logfunc(name) + } + assert.Equal(t, 1.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + if tt.lvl == log.PanicLevel { + assert.Panics(t, func() { tt.logfuncf(name) }) + } else { + tt.logfuncf(name) + } + assert.Equal(t, 2.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + }) + } +} + func TestNewWithFlagsLogger(t *testing.T) { var b bytes.Buffer logger := NewWithFlags(&b, log.InfoLevel, map[string]interface{}{"name": "john doe", "age": 18}, 0) diff --git a/log/zerolog/logger.go b/log/zerolog/logger.go index 7af1bccbf..4cb82bc9c 100644 --- a/log/zerolog/logger.go +++ b/log/zerolog/logger.go @@ -69,61 +69,73 @@ func (l *Logger) Sub(ff map[string]interface{}) log.Logger { // Panic logging. func (l *Logger) Panic(args ...interface{}) { + log.IncreasePanicCounter() l.logger.Panic().Msg(fmt.Sprint(args...)) } // Panicf logging. func (l *Logger) Panicf(msg string, args ...interface{}) { + log.IncreasePanicCounter() l.loggerf.Panic().Msgf(msg, args...) } // Fatal logging. func (l *Logger) Fatal(args ...interface{}) { + log.IncreaseFatalCounter() l.logger.Fatal().Msg(fmt.Sprint(args...)) } // Fatalf logging. func (l *Logger) Fatalf(msg string, args ...interface{}) { + log.IncreaseFatalCounter() l.loggerf.Fatal().Msgf(msg, args...) } // Error logging. func (l *Logger) Error(args ...interface{}) { + log.IncreaseErrorCounter() l.logger.Error().Msg(fmt.Sprint(args...)) } // Errorf logging. func (l *Logger) Errorf(msg string, args ...interface{}) { + log.IncreaseErrorCounter() l.loggerf.Error().Msgf(msg, args...) } // Warn logging. func (l *Logger) Warn(args ...interface{}) { + log.IncreaseWarnCounter() l.logger.Warn().Msg(fmt.Sprint(args...)) } // Warnf logging. func (l *Logger) Warnf(msg string, args ...interface{}) { + log.IncreaseWarnCounter() l.loggerf.Warn().Msgf(msg, args...) } // Info logging. func (l *Logger) Info(args ...interface{}) { + log.IncreaseInfoCounter() l.logger.Info().Msg(fmt.Sprint(args...)) } // Infof logging. func (l *Logger) Infof(msg string, args ...interface{}) { + log.IncreaseInfoCounter() l.loggerf.Info().Msgf(msg, args...) } // Debug logging. func (l *Logger) Debug(args ...interface{}) { + log.IncreaseDebugCounter() l.logger.Debug().Msg(fmt.Sprint(args...)) } // Debugf logging. func (l *Logger) Debugf(msg string, args ...interface{}) { + log.IncreaseDebugCounter() l.loggerf.Debug().Msgf(msg, args...) } diff --git a/log/zerolog/logger_test.go b/log/zerolog/logger_test.go index 14d9c3165..ec636367e 100644 --- a/log/zerolog/logger_test.go +++ b/log/zerolog/logger_test.go @@ -7,6 +7,7 @@ import ( "testing" "github.com/beatlabs/patron/log" + "github.com/prometheus/client_golang/prometheus/testutil" "github.com/rs/zerolog" "github.com/stretchr/testify/assert" ) @@ -30,6 +31,42 @@ func init() { } } +func TestLogMetrics(t *testing.T) { + t.Parallel() + log.ResetLogCounter() + l := New(&zerolog.Logger{}, log.DebugLevel, nil) + tests := map[string]struct { + lvl log.Level + logfunc func(args ...interface{}) + logfuncf func(msg string, args ...interface{}) + }{ + "debug": {lvl: log.DebugLevel, logfunc: l.Debug, logfuncf: l.Debugf}, + "info": {lvl: log.InfoLevel, logfunc: l.Info, logfuncf: l.Infof}, + "warn": {lvl: log.WarnLevel, logfunc: l.Warn, logfuncf: l.Warnf}, + "error": {lvl: log.ErrorLevel, logfunc: l.Error, logfuncf: l.Errorf}, + "panic": {lvl: log.PanicLevel, logfunc: l.Panic, logfuncf: l.Panicf}, + } + for name, tt := range tests { + tt := tt + t.Run(name, func(t *testing.T) { + t.Parallel() + assert.Equal(t, 0.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + if tt.lvl == log.PanicLevel { + assert.Panics(t, func() { tt.logfunc(name) }) + } else { + tt.logfunc(name) + } + assert.Equal(t, 1.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + if tt.lvl == log.PanicLevel { + assert.Panics(t, func() { tt.logfuncf(name) }) + } else { + tt.logfuncf(name) + } + assert.Equal(t, 2.0, testutil.ToFloat64(log.LevelCount(string(tt.lvl)))) + }) + } +} + func TestNewLogger(t *testing.T) { tests := []struct { name string