From 3401fd97c3be836ee55b8263cce1b66aafb4c726 Mon Sep 17 00:00:00 2001 From: Jason Joo Date: Thu, 3 Feb 2022 18:18:59 +0800 Subject: [PATCH] Add stack trace after panic Signed-off-by: Jason Joo --- core/leader.go | 3 ++ core/worker/task_worker/executor_batch.go | 5 +++ core/worker/task_worker/executor_single.go | 5 +++ core/worker/task_worker/task_worker.go | 3 ++ log/log.go | 24 ++++++------ log/logrus.go | 16 ++++---- utils/trace.go | 43 ++++++++++++++++++++++ utils/trace_test.go | 33 +++++++++++++++++ 8 files changed, 112 insertions(+), 20 deletions(-) create mode 100644 utils/trace.go create mode 100644 utils/trace_test.go diff --git a/core/leader.go b/core/leader.go index 6316de5..b868eaa 100644 --- a/core/leader.go +++ b/core/leader.go @@ -262,6 +262,9 @@ func (manager *ScheduleManager) stopWorkers(strategy *definition.Strategy) error defer func() { if err := recover(); err != nil { log.Errorf("Stop worker %s failed: %v", strategy.ID, err) + traceData := utils.StackTraceData() + defer traceData.Recycle() + log.Error("Trace: ", traceData.String()) } }() w.Stop(strategy.ID, strategy.Parameter) diff --git a/core/worker/task_worker/executor_batch.go b/core/worker/task_worker/executor_batch.go index e44f94b..2ef7df7 100644 --- a/core/worker/task_worker/executor_batch.go +++ b/core/worker/task_worker/executor_batch.go @@ -8,7 +8,9 @@ import ( "sync" "time" + "github.com/jasonjoo2010/goschedule/log" "github.com/jasonjoo2010/goschedule/types" + "github.com/jasonjoo2010/goschedule/utils" "github.com/sirupsen/logrus" ) @@ -26,6 +28,9 @@ func (m *BatchExecutor) execute(items []interface{}) { defer func() { if r := recover(); r != nil { logrus.Error("Execute error: ", r) + traceData := utils.StackTraceData() + defer traceData.Recycle() + log.Error("Trace: ", traceData.String()) succ = false } m.worker.Statistics.Execute(succ, cost) diff --git a/core/worker/task_worker/executor_single.go b/core/worker/task_worker/executor_single.go index 2072cf0..f51c5e8 100644 --- a/core/worker/task_worker/executor_single.go +++ b/core/worker/task_worker/executor_single.go @@ -7,7 +7,9 @@ package task_worker import ( "time" + "github.com/jasonjoo2010/goschedule/log" "github.com/jasonjoo2010/goschedule/types" + "github.com/jasonjoo2010/goschedule/utils" "github.com/sirupsen/logrus" ) @@ -24,6 +26,9 @@ func (m *SingleExecutor) execute(item interface{}) { defer func() { if r := recover(); r != nil { logrus.Error("Execute error: ", r) + traceData := utils.StackTraceData() + defer traceData.Recycle() + log.Error("Trace: ", traceData.String()) succ = false } m.worker.Statistics.Execute(succ, cost) diff --git a/core/worker/task_worker/task_worker.go b/core/worker/task_worker/task_worker.go index 5eaff50..09e1b2e 100644 --- a/core/worker/task_worker/task_worker.go +++ b/core/worker/task_worker/task_worker.go @@ -240,6 +240,9 @@ func (w *TaskWorker) selectOnce() { defer func() { if r := recover(); r != nil { logrus.Error("Selecting error: ", r) + traceData := utils.StackTraceData() + defer traceData.Recycle() + log.Error("Trace: ", traceData.String()) } if utils.ContextDone(w.ctx) { // notify blocking routines diff --git a/log/log.go b/log/log.go index 3019ebf..db7c593 100644 --- a/log/log.go +++ b/log/log.go @@ -5,10 +5,10 @@ var inst = NewLogrusWrapper() // Wrapper defines the interface used in project to make it able to integrate with different loggers type Wrapper interface { Name() string - Debug(fmt string) - Info(fmt string) - Warn(fmt string) - Error(fmt string) + Debug(args ...interface{}) + Info(args ...interface{}) + Warn(args ...interface{}) + Error(args ...interface{}) Debugf(fmt string, args ...interface{}) Infof(fmt string, args ...interface{}) Warnf(fmt string, args ...interface{}) @@ -49,21 +49,21 @@ func Errorf(fmt string, args ...interface{}) { } // Debug is a convenient scaffold for debug logs -func Debug(fmt string) { - inst.Debug(fmt) +func Debug(args ...interface{}) { + inst.Debug(args...) } // Info is a convenient scaffold for information logs -func Info(fmt string) { - inst.Info(fmt) +func Info(args ...interface{}) { + inst.Info(args...) } // Warn is a convenient scaffold for warning logs -func Warn(fmt string) { - inst.Warn(fmt) +func Warn(args ...interface{}) { + inst.Warn(args...) } // Error is a convenient scaffold for error logs -func Error(fmt string) { - inst.Error(fmt) +func Error(args ...interface{}) { + inst.Error(args...) } diff --git a/log/logrus.go b/log/logrus.go index 41fc6dd..ea480b9 100644 --- a/log/logrus.go +++ b/log/logrus.go @@ -31,18 +31,18 @@ func (w *logrusWrapper) Errorf(fmt string, args ...interface{}) { logrus.Errorf(fmt, args...) } -func (w *logrusWrapper) Debug(fmt string) { - logrus.Debugf(fmt) +func (w *logrusWrapper) Debug(args ...interface{}) { + logrus.Debug(args...) } -func (w *logrusWrapper) Info(fmt string) { - logrus.Infof(fmt) +func (w *logrusWrapper) Info(args ...interface{}) { + logrus.Info(args...) } -func (w *logrusWrapper) Warn(fmt string) { - logrus.Warnf(fmt) +func (w *logrusWrapper) Warn(args ...interface{}) { + logrus.Warn(args...) } -func (w *logrusWrapper) Error(fmt string) { - logrus.Errorf(fmt) +func (w *logrusWrapper) Error(args ...interface{}) { + logrus.Error(args...) } diff --git a/utils/trace.go b/utils/trace.go new file mode 100644 index 0000000..d3180d0 --- /dev/null +++ b/utils/trace.go @@ -0,0 +1,43 @@ +package utils + +import ( + "runtime" + "sync" +) + +type TraceData struct { + data []byte + size int +} + +func (data *TraceData) Len() int { + return data.size +} + +func (data *TraceData) Data() []byte { + return data.data[:data.size] +} + +func (data *TraceData) String() string { + return string(data.Data()) +} + +// call this to reuse the memory +func (data *TraceData) Recycle() { + tracePool.Put(data) +} + +var tracePool = &sync.Pool{ + New: func() interface{} { + return &TraceData{ + data: make([]byte, 1024*64), + size: 0, + } + }, +} + +func StackTraceData() *TraceData { + data := tracePool.Get().(*TraceData) + data.size = runtime.Stack(data.data, false) + return data +} diff --git a/utils/trace_test.go b/utils/trace_test.go new file mode 100644 index 0000000..e63a95e --- /dev/null +++ b/utils/trace_test.go @@ -0,0 +1,33 @@ +package utils + +import ( + "fmt" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestTrace(t *testing.T) { + data := StackTraceData() + ptr := fmt.Sprintf("%p", data) + assert.True(t, data.Len() > 0) + data.Recycle() + + data1 := StackTraceData() + ptr1 := fmt.Sprintf("%p", data1) + assert.True(t, data1.Len() > 0) + data1.Recycle() + + data2 := StackTraceData() + ptr2 := fmt.Sprintf("%p", data2) + assert.True(t, data2.Len() > 0) + + data3 := StackTraceData() + ptr3 := fmt.Sprintf("%p", data3) + assert.True(t, data3.Len() > 0) + data2.Recycle() + data3.Recycle() + + assert.Equal(t, ptr, ptr1) + assert.NotEqual(t, ptr2, ptr3) +}