Add call stack print for Error, Fatal and Panic

auxten · auxten · commit a628f19fd66f · 2018-11-03T15:36:30.000+08:00
diff --git a/utils/log/logwrapper.go b/utils/log/logwrapper.go
@@ -60,11 +60,28 @@ type Logger logrus.Logger
 type Fields logrus.Fields
 
 // CallerHook defines caller awareness hook for logrus.
-type CallerHook struct{}
+type CallerHook struct {
+	StackLevels []logrus.Level
+}
+
+// NewCallerHook creates new CallerHook
+func NewCallerHook(stackLevels []logrus.Level) *CallerHook {
+	return &CallerHook{
+		StackLevels: stackLevels,
+	}
+}
+
+// StandardCallerHook is a convenience initializer for LogrusStackHook{} with
+// default args.
+func StandardCallerHook() *CallerHook {
+	return NewCallerHook(
+		[]logrus.Level{logrus.PanicLevel, logrus.FatalLevel, logrus.ErrorLevel},
+	)
+}
 
 // Fire defines hook event handler.
 func (hook *CallerHook) Fire(entry *logrus.Entry) error {
-	funcDesc, caller := hook.caller()
+	funcDesc, caller := hook.caller(entry)
 	fields := strings.SplitN(funcDesc, ".", 2)
 	if len(fields) > 0 {
 		level, ok := PkgDebugLogFilter[fields[0]]
@@ -91,38 +108,61 @@ func (hook *CallerHook) Levels() []logrus.Level {
 	}
 }
 
-func (hook *CallerHook) caller() (relFuncName, caller string) {
-	var (
-		file     = "unknown"
-		line     = 0
-		funcName = "unknown"
-	)
+func (hook *CallerHook) caller(entry *logrus.Entry) (relFuncName, caller string) {
+	var skipFrames int
+	if len(entry.Data) == 0 {
+		// When WithField(s) is not used, we have 8 logrus frames to skip.
+		skipFrames = 8
+	} else {
+		// When WithField(s) is used, we have 6 logrus frames to skip.
+		skipFrames = 6
+	}
+
 	pcs := make([]uintptr, 12)
-	if runtime.Callers(6, pcs) > 0 {
-		frames := runtime.CallersFrames(pcs)
+	stacks := make([]runtime.Frame, 0, 12)
+	if runtime.Callers(skipFrames, pcs) > 0 {
+		var foundCaller bool
+		_frames := runtime.CallersFrames(pcs)
 		for {
-			f, more := frames.Next()
+			f, more := _frames.Next()
 			//fmt.Printf("%s:%d %s\n", f.File, f.Line, f.Function)
-			if strings.HasSuffix(f.File, "logwrapper.go") && more {
-				f, _ = frames.Next()
-				file = f.File
-				line = f.Line
-				funcName = f.Function
-				break
+			if !foundCaller && strings.HasSuffix(f.File, "logwrapper.go") && more {
+				f, _ = _frames.Next()
+				relFuncName = strings.TrimPrefix(f.Function, "github.com/CovenantSQL/CovenantSQL/")
+				caller = fmt.Sprintf("%s:%d %s", filepath.Base(f.File), f.Line, relFuncName)
+				foundCaller = true
+			}
+			if foundCaller {
+				stacks = append(stacks, f)
 			}
 			if !more {
 				break
 			}
 		}
 	}
 
-	relFuncName = strings.TrimPrefix(funcName, "github.com/CovenantSQL/CovenantSQL/")
-	funcLocation := fmt.Sprintf("%s:%d %s", filepath.Base(file), line, relFuncName)
-	return relFuncName, funcLocation
+	if len(stacks) > 0 {
+		for _, level := range hook.StackLevels {
+			if entry.Level == level {
+				stacksStr := make([]string, 0, len(stacks))
+				for i, s := range stacks {
+					if s.Line > 0 {
+						fName := strings.TrimPrefix(s.Function, "github.com/CovenantSQL/CovenantSQL/")
+						stackStr := fmt.Sprintf("#%d %s@%s:%d     ", i, fName, filepath.Base(s.File), s.Line)
+						stacksStr = append(stacksStr, stackStr)
+					}
+				}
+				entry.Data["stack"] = stacksStr
+				break
+			}
+		}
+	}
+
+	return relFuncName, caller
 }
 
 func init() {
-	AddHook(&CallerHook{})
+	AddHook(StandardCallerHook())
 }
 
 //var (
diff --git a/utils/log/logwrapper_test.go b/utils/log/logwrapper_test.go
@@ -21,6 +21,8 @@ import (
 	"testing"
 	"time"
 
+	"github.com/ethereum/go-ethereum/log"
+
 	"github.com/pkg/errors"
 
 	"github.com/sirupsen/logrus"
@@ -82,11 +84,27 @@ func TestStandardLogger(t *testing.T) {
 
 }
 
+func call0() {
+	call1()
+}
+
+func call1() {
+	call2()
+}
+
+func call2() {
+	WithField("k", "v").Error("Error")
+	log.Error("call2 error")
+}
+
 func TestWithField(t *testing.T) {
 	SetLevel(DebugLevel)
 	if GetLevel() != DebugLevel {
 		t.Fail()
 	}
+
+	call0()
+
 	f := new(Fields)
 	WithError(errors.New("new")).WithFields(*f).WithTime(time.Now()).Debug("Debug")
 
