From 02f7767e321cc3518e99b5a91b21a7ad29b36064 Mon Sep 17 00:00:00 2001 From: Justin Hammond Date: Mon, 19 Apr 2021 13:10:47 +0800 Subject: [PATCH 1/3] feat: Implement a LogRus Logger --- examples/schedule-logs/README.md | 55 +++++++++++++++++++++ examples/schedule-logs/main.go | 63 ++++++++++++++++++++++++ logrus.go | 83 ++++++++++++++++++++++++++++++++ 3 files changed, 201 insertions(+) create mode 100644 examples/schedule-logs/README.md create mode 100644 examples/schedule-logs/main.go create mode 100644 logrus.go diff --git a/examples/schedule-logs/README.md b/examples/schedule-logs/README.md new file mode 100644 index 0000000..d908c65 --- /dev/null +++ b/examples/schedule-logs/README.md @@ -0,0 +1,55 @@ +# 4 Logging with Other logrus + +1. Cron Every Minute +2. Cron Every 5 Minutes +3. Fixed Interval Every 30 Secs +4. *Once* after 10 Secs from schedule start. + +Started and Stopped using `StartAll()` and `StopAll()` + +## Output + +```json +INFO[0000] Job Schedule Started From=sched id=cronEvery5Minute +INFO[0000] Job Schedule Started From=sched id=fixedTimer30second +INFO[0000] Job Schedule Started From=sched id=onceAfter10s +INFO[0000] Job Schedule Started From=sched id=cronEveryMinute +INFO[0000] Job Next Run Scheduled After=10s At="2021-04-19T13:09:08+08:00" From=sched id=onceAfter10s +INFO[0000] Job Next Run Scheduled After=30s At="2021-04-19T13:09:28+08:00" From=sched id=fixedTimer30second +INFO[0000] Job Next Run Scheduled After=2s At="2021-04-19T13:09:00+08:00" From=sched id=cronEveryMinute +INFO[0000] Job Next Run Scheduled After=1m2s At="2021-04-19T13:10:00+08:00" From=sched id=cronEvery5Minute +INFO[0001] Job Next Run Scheduled After=1m0s At="2021-04-19T13:10:00+08:00" From=sched id=cronEveryMinute +INFO[0001] Job Run Starting From=sched Instance=2c114df6-e795-419a-8bf3-e4aada560a37 id=cronEveryMinute +2021/04/19 13:09:00 every-minute-cron Doing some work... +2021/04/19 13:09:01 every-minute-cron Finished Work. +INFO[0002] Job Finished Duration=1s From=sched Instance=2c114df6-e795-419a-8bf3-e4aada560a37 State=FINISHED id=cronEveryMinute +INFO[0002] timer sched.run_actual_elapsed_time From=metrics id=cronEveryMinute interval=1.0004944s name=sched.run_actual_elapsed_time tags="map[id:cronEveryMinute]" +INFO[0002] timer sched.run_total_elapsed_time From=metrics id=cronEveryMinute interval=1.0006126s name=sched.run_total_elapsed_time tags="map[id:cronEveryMinute]" +INFO[0010] No more Jobs will be scheduled From=sched id=onceAfter10s +INFO[0010] Stopping Schedule... From=sched id=onceAfter10s +INFO[0010] Waiting for '1' active jobs still running... From=sched id=onceAfter10s +INFO[0010] Job Run Starting From=sched Instance=80691c48-8468-4029-9bc8-0264698a1cc2 id=onceAfter10s +2021/04/19 13:09:08 onceAfter10s Doing some work... +2021/04/19 13:09:09 onceAfter10s Finished Work. +INFO[0011] Job Finished Duration=1s From=sched Instance=80691c48-8468-4029-9bc8-0264698a1cc2 State=FINISHED id=onceAfter10s +INFO[0011] timer sched.run_actual_elapsed_time From=metrics id=onceAfter10s interval=1.0004959s name=sched.run_actual_elapsed_time tags="map[id:onceAfter10s]" +INFO[0011] timer sched.run_total_elapsed_time From=metrics id=onceAfter10s interval=1.0006474s name=sched.run_total_elapsed_time tags="map[id:onceAfter10s]" +INFO[0011] Job Schedule Stopped From=sched id=onceAfter10s +INFO[0011] Job Schedule Finished From=sched id=onceAfter10s +INFO[0030] Job Next Run Scheduled After=30s At="2021-04-19T13:09:58+08:00" From=sched id=fixedTimer30second +INFO[0030] Job Run Starting From=sched Instance=eded3660-2b7c-46b0-8dcc-8a393102771b id=fixedTimer30second +2021/04/19 13:09:28 fixedEvery30Second Doing some work... +2021/04/19 13:09:29 fixedEvery30Second Finished Work. +INFO[0031] Job Finished Duration=1.001s From=sched Instance=eded3660-2b7c-46b0-8dcc-8a393102771b State=FINISHED id=fixedTimer30second +INFO[0031] timer sched.run_actual_elapsed_time From=metrics id=fixedTimer30second interval=1.0006731s name=sched.run_actual_elapsed_time tags="map[id:fixedTimer30second]" +INFO[0031] timer sched.run_total_elapsed_time From=metrics id=fixedTimer30second interval=1.0008061s name=sched.run_total_elapsed_time tags="map[id:fixedTimer30second]" +^CINFO[0052] Stopping Schedule... From=sched id=cronEveryMinute +INFO[0052] Job Schedule Stopped From=sched id=cronEveryMinute +INFO[0052] Job Next Run Canceled At="2021-04-19T13:10:00+08:00" From=sched id=cronEveryMinute +INFO[0052] Stopping Schedule... From=sched id=cronEvery5Minute +INFO[0052] Job Schedule Stopped From=sched id=cronEvery5Minute +INFO[0052] Job Next Run Canceled At="2021-04-19T13:10:00+08:00" From=sched id=cronEvery5Minute +INFO[0052] Stopping Schedule... From=sched id=fixedTimer30second +INFO[0052] Job Schedule Stopped From=sched id=fixedTimer30second +``` + diff --git a/examples/schedule-logs/main.go b/examples/schedule-logs/main.go new file mode 100644 index 0000000..94efbc7 --- /dev/null +++ b/examples/schedule-logs/main.go @@ -0,0 +1,63 @@ +package main + +import ( + "fmt" + "github.com/sherifabdlnaby/sched" + "log" + "os" + "os/signal" + "syscall" + "time" +) + +func main() { + + job := func(id string) func() { + return func() { + log.Println(id + "\t Doing some work...") + time.Sleep(1 * time.Second) + log.Println(id + "\t Finished Work.") + } + } + + cronTimer, err := sched.NewCron("* * * * *") + if err != nil { + panic(fmt.Sprintf("invalid cron expression: %s", err.Error())) + } + + cronTimer5, err := sched.NewCron("*/5 * * * *") + if err != nil { + panic(fmt.Sprintf("invalid cron expression: %s", err.Error())) + } + + fixedTimer30second, err := sched.NewFixed(30 * time.Second) + if err != nil { + panic(fmt.Sprintf("invalid interval: %s", err.Error())) + } + + onceAfter10s, err := sched.NewOnce(10 * time.Second) + if err != nil { + panic(fmt.Sprintf("invalid delay: %s", err.Error())) + } + + // Create Schedule + scheduler := sched.NewScheduler(sched.WithLogger(sched.LogrusLogger()), + sched.WithConsoleMetrics(1*time.Minute)) + + _ = scheduler.Add("cronEveryMinute", cronTimer, job("every-minute-cron")) + _ = scheduler.Add("cronEvery5Minute", cronTimer5, job("every-five-minute-cron")) + _ = scheduler.Add("fixedTimer30second", fixedTimer30second, job("fixedEvery30Second")) + _ = scheduler.Add("onceAfter10s", onceAfter10s, job("onceAfter10s")) + + scheduler.StartAll() + + // Listen to CTRL + C + signalChan := make(chan os.Signal, 1) + signal.Notify(signalChan, syscall.SIGTERM, syscall.SIGINT, syscall.SIGQUIT) + _ = <-signalChan + + // Stop before shutting down. + scheduler.StopAll() + + return +} diff --git a/logrus.go b/logrus.go new file mode 100644 index 0000000..6f56e11 --- /dev/null +++ b/logrus.go @@ -0,0 +1,83 @@ +package sched + +import ( + "github.com/sirupsen/logrus" +) + +type LruLogger struct { + jl *logrus.Entry +} + +func (l *LruLogger) Debugw(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Debug(msg) +} +func (l LruLogger) Errorw(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Error(msg) +} +func (l LruLogger) Fatalw(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Fatal(msg) +} +func (l LruLogger) Infow(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Info(msg) +} +func (l LruLogger) Panicw(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Panic(msg) +} +func (l LruLogger) Warnw(msg string, keysAndValues ...interface{}) { + logger := l.jl + for i := 0; i < len(keysAndValues); i++ { + if i%2 == 0 { + logger = logger.WithField(keysAndValues[i].(string), keysAndValues[i+1]) + } + } + logger.Warn(msg) +} +func (l *LruLogger) With(args ...interface{}) Logger { + for i := 0; i < len(args)/2; i++ { + l.jl = l.jl.WithField(args[i].(string), args[i+1].(string)) + } + return l +} +func (l LruLogger) Named(name string) Logger { + logger := l.jl.WithField("From", name) + return &LruLogger{jl: logger} +} +func (l *LruLogger) Sync() error { + return nil +} + +//DefaultLogger Return Default Sched Logger based on Zap's sugared logger +func LogrusLogger() Logger { + // TODO control verbosity + return &LruLogger{jl: logrus.NewEntry(logrus.New())} +} From d4131b3b78b9c62bd7265872a76ca65c37ff4e25 Mon Sep 17 00:00:00 2001 From: Justin Hammond Date: Mon, 19 Apr 2021 13:15:23 +0800 Subject: [PATCH 2/3] fix: tidy up logrus logger --- go.mod | 1 + go.sum | 5 +++++ logrus.go | 8 +++++--- 3 files changed, 11 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 46844ca..9e11f34 100644 --- a/go.mod +++ b/go.mod @@ -12,6 +12,7 @@ require ( github.com/m3db/prometheus_common v0.1.0 // indirect github.com/m3db/prometheus_procfs v0.8.1 // indirect github.com/matttproud/golang_protobuf_extensions v1.0.1 // indirect + github.com/sirupsen/logrus v1.8.1 github.com/uber-go/tally v3.3.17+incompatible go.uber.org/zap v1.16.0 golang.org/x/lint v0.0.0-20201208152925-83fdc39ff7b5 // indirect diff --git a/go.sum b/go.sum index ccc60b7..6a93133 100644 --- a/go.sum +++ b/go.sum @@ -34,7 +34,10 @@ github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINE github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= +github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE= +github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0 h1:2E4SXV/wtOkTonXsotYi4li6zVWxYlZuYNCXe9XRJyk= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= @@ -68,7 +71,9 @@ golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4 h1:myAQVi0cGEoqQVR5POX+8RR2mrocKqNN1hmeMqhX27k= golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= diff --git a/logrus.go b/logrus.go index 6f56e11..852fda6 100644 --- a/logrus.go +++ b/logrus.go @@ -63,8 +63,10 @@ func (l LruLogger) Warnw(msg string, keysAndValues ...interface{}) { logger.Warn(msg) } func (l *LruLogger) With(args ...interface{}) Logger { - for i := 0; i < len(args)/2; i++ { - l.jl = l.jl.WithField(args[i].(string), args[i+1].(string)) + for i := 0; i < len(args); i++ { + if i%2 == 0 { + l.jl = l.jl.WithField(args[i].(string), args[i+1]) + } } return l } @@ -76,7 +78,7 @@ func (l *LruLogger) Sync() error { return nil } -//DefaultLogger Return Default Sched Logger based on Zap's sugared logger +//LogrusLogger Return logger Sched Logger based on logrus func LogrusLogger() Logger { // TODO control verbosity return &LruLogger{jl: logrus.NewEntry(logrus.New())} From 7adc9ad6d40e08b7762461b61f7358fda376a852 Mon Sep 17 00:00:00 2001 From: Justin Hammond Date: Tue, 20 Apr 2021 08:01:27 +0800 Subject: [PATCH 3/3] fix: make the LruLogger private, and either a Default Logrus logger, or pass in a existing logger --- examples/schedule-logs/main.go | 2 +- logrus.go | 34 ++++++++++++++++++++-------------- 2 files changed, 21 insertions(+), 15 deletions(-) diff --git a/examples/schedule-logs/main.go b/examples/schedule-logs/main.go index 94efbc7..b852495 100644 --- a/examples/schedule-logs/main.go +++ b/examples/schedule-logs/main.go @@ -41,7 +41,7 @@ func main() { } // Create Schedule - scheduler := sched.NewScheduler(sched.WithLogger(sched.LogrusLogger()), + scheduler := sched.NewScheduler(sched.WithLogger(sched.LogrusDefaultLogger()), sched.WithConsoleMetrics(1*time.Minute)) _ = scheduler.Add("cronEveryMinute", cronTimer, job("every-minute-cron")) diff --git a/logrus.go b/logrus.go index 852fda6..96aa010 100644 --- a/logrus.go +++ b/logrus.go @@ -4,11 +4,11 @@ import ( "github.com/sirupsen/logrus" ) -type LruLogger struct { +type lruLogger struct { jl *logrus.Entry } -func (l *LruLogger) Debugw(msg string, keysAndValues ...interface{}) { +func (l *lruLogger) Debugw(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -17,7 +17,7 @@ func (l *LruLogger) Debugw(msg string, keysAndValues ...interface{}) { } logger.Debug(msg) } -func (l LruLogger) Errorw(msg string, keysAndValues ...interface{}) { +func (l lruLogger) Errorw(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -26,7 +26,7 @@ func (l LruLogger) Errorw(msg string, keysAndValues ...interface{}) { } logger.Error(msg) } -func (l LruLogger) Fatalw(msg string, keysAndValues ...interface{}) { +func (l lruLogger) Fatalw(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -35,7 +35,7 @@ func (l LruLogger) Fatalw(msg string, keysAndValues ...interface{}) { } logger.Fatal(msg) } -func (l LruLogger) Infow(msg string, keysAndValues ...interface{}) { +func (l lruLogger) Infow(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -44,7 +44,7 @@ func (l LruLogger) Infow(msg string, keysAndValues ...interface{}) { } logger.Info(msg) } -func (l LruLogger) Panicw(msg string, keysAndValues ...interface{}) { +func (l lruLogger) Panicw(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -53,7 +53,7 @@ func (l LruLogger) Panicw(msg string, keysAndValues ...interface{}) { } logger.Panic(msg) } -func (l LruLogger) Warnw(msg string, keysAndValues ...interface{}) { +func (l lruLogger) Warnw(msg string, keysAndValues ...interface{}) { logger := l.jl for i := 0; i < len(keysAndValues); i++ { if i%2 == 0 { @@ -62,7 +62,7 @@ func (l LruLogger) Warnw(msg string, keysAndValues ...interface{}) { } logger.Warn(msg) } -func (l *LruLogger) With(args ...interface{}) Logger { +func (l *lruLogger) With(args ...interface{}) Logger { for i := 0; i < len(args); i++ { if i%2 == 0 { l.jl = l.jl.WithField(args[i].(string), args[i+1]) @@ -70,16 +70,22 @@ func (l *LruLogger) With(args ...interface{}) Logger { } return l } -func (l LruLogger) Named(name string) Logger { +func (l lruLogger) Named(name string) Logger { logger := l.jl.WithField("From", name) - return &LruLogger{jl: logger} + return &lruLogger{jl: logger} } -func (l *LruLogger) Sync() error { +func (l *lruLogger) Sync() error { return nil } -//LogrusLogger Return logger Sched Logger based on logrus -func LogrusLogger() Logger { +//LogrusDefaultLogger Return Logger based on logrus with new instance +func LogrusDefaultLogger() Logger { // TODO control verbosity - return &LruLogger{jl: logrus.NewEntry(logrus.New())} + return &lruLogger{jl: logrus.NewEntry(logrus.New())} +} + +//LogrusLogger Return Return Logger based on logrus with existing instance +func LogrusLogger(log *logrus.Logger) Logger { + // TODO control verbosity + return &lruLogger{jl: logrus.NewEntry(log)} }