Add stack trace after panic

Signed-off-by: Jason Joo <[email protected]>

Author: jasonjoo2010

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)

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)

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)

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

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...)
 }

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...)
 }

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
+}

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)
+}