Use tracerr call traces in log

cli/node/main.go

@@ -8,6 +8,7 @@ import (
 	"github.com/hermeznetwork/hermez-node/config"
 	"github.com/hermeznetwork/hermez-node/log"
 	"github.com/hermeznetwork/hermez-node/node"
+	"github.com/hermeznetwork/tracerr"
 	"github.com/urfave/cli/v2"
 )
 
@@ -151,7 +152,7 @@ func main() {
 
 	err := app.Run(os.Args)
 	if err != nil {
-		fmt.Printf("\nError: %v\n", err)
+		fmt.Printf("\nError: %v\n", tracerr.Sprint(err))
 		os.Exit(1)
 	}
 }

go.mod

@@ -12,6 +12,7 @@ require (
 	github.com/gin-gonic/gin v1.5.0
 	github.com/go-sql-driver/mysql v1.5.0 // indirect
 	github.com/gobuffalo/packr/v2 v2.8.0
+	github.com/hermeznetwork/tracerr v0.3.1-0.20201126162137-de9930d0cf29
 	github.com/iden3/go-iden3-crypto v0.0.6-0.20201016142444-94e92e88fb4e
 	github.com/iden3/go-merkletree v0.0.0-20201103115630-ad30c8309b44
 	github.com/jinzhu/copier v0.0.0-20190924061706-b57f9002281a

go.sum

@@ -300,6 +300,8 @@ github.com/hashicorp/logutils v1.0.0/go.mod h1:QIAnNjmIWmVIIkWDTG1z5v++HQmx9WQRO
 github.com/hashicorp/mdns v1.0.0/go.mod h1:tL+uN++7HEJ6SQLQ2/p+z2pH24WQKWjBPkE0mNTz8vQ=
 github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2pPBoIllUwCN7I=
 github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc=
+github.com/hermeznetwork/tracerr v0.3.1-0.20201126162137-de9930d0cf29 h1:dlXz/aVJfCh/wvF6jjsrl/lqHJbOigQLG6vFF5zGuNs=
+github.com/hermeznetwork/tracerr v0.3.1-0.20201126162137-de9930d0cf29/go.mod h1:nsWC1+tc4qUEbUGRv4DcPJJTjLsedlPajlFmpJoohK4=
 github.com/holiman/uint256 v1.1.0 h1:Iye6ze0DW9s+7EMn8y6Q4ebegDzpu28JQHEVM1Bq+Wg=
 github.com/holiman/uint256 v1.1.0/go.mod h1:y4ga/t+u+Xwd7CpDgZESaRcWy0I7XMlTMA25ApIH5Jw=
 github.com/howeyc/fsnotify v0.9.0/go.mod h1:41HzSPxBGeFRQKEEwgh49TRw/nKBsYZ2cF1OzPjSJsA=
@@ -388,6 +390,8 @@ github.com/lib/pq v1.8.0 h1:9xohqzkUwzR4Ga4ivdTcawVS89YSDVxXMa3xJX3cGzg=
 github.com/lib/pq v1.8.0/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o=
 github.com/lightstep/lightstep-tracer-common/golang/gogo v0.0.0-20190605223551-bc2310a04743/go.mod h1:qklhhLq1aX+mtWk9cPHPzaBjWImj5ULL6C7HFJtXQMM=
 github.com/lightstep/lightstep-tracer-go v0.18.1/go.mod h1:jlF1pusYV4pidLvZ+XD0UBX0ZE6WURAspgAczcDHrL4=
+github.com/logrusorgru/aurora v0.0.0-20181002194514-a7b3b318ed4e h1:9MlwzLdW7QSDrhDjFlsEYmxpFyIoXmYRon3dt0io31k=
+github.com/logrusorgru/aurora v0.0.0-20181002194514-a7b3b318ed4e/go.mod h1:7rIyQOR62GCctdiQpZ/zOJlFyk6y+94wXzv6RNZgaR4=
 github.com/lyft/protoc-gen-validate v0.0.13/go.mod h1:XbGvPuh87YZc5TdIa2/I4pLk0QoUACkjt2znoq26NVQ=
 github.com/magiconair/properties v1.8.0/go.mod h1:PppfXfuXeibc/6YijjN8zIbojt8czPbwD3XqdrwzmxQ=
 github.com/markbates/errx v1.1.0 h1:QDFeR+UP95dO12JgW+tgi2UVfo0V8YBHiUIOaeBPiEI=

log/log.go

@@ -2,8 +2,10 @@ package log
 
 import (
 	"fmt"
+	"strings"
 	"time"
 
+	"github.com/hermeznetwork/tracerr"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 )
@@ -48,7 +50,8 @@ func Init(levelStr, logPath string) {
 			CallerKey:    "caller",
 			EncodeCaller: zapcore.ShortCallerEncoder,
 
-			StacktraceKey: "stacktrace",
+			// StacktraceKey: "stacktrace",
+			StacktraceKey: "",
 			LineEnding:    zapcore.DefaultLineEnding,
 		},
 	}
@@ -65,6 +68,27 @@ func Init(levelStr, logPath string) {
 	log.Infof("log level: %s", level)
 }
 
+func sprintStackTrace(st []tracerr.Frame) string {
+	builder := strings.Builder{}
+	for _, f := range st {
+		builder.WriteString(fmt.Sprintf("\n%s:%d %s()", f.Path, f.Line, f.Func))
+	}
+	builder.WriteString("\n")
+	return builder.String()
+}
+
+// appendStackTraceMaybeArgs will append the stacktrace to the args if one of them
+// is a tracerr.Error
+func appendStackTraceMaybeArgs(args []interface{}) []interface{} {
+	for i := range args {
+		if err, ok := args[i].(tracerr.Error); ok {
+			st := err.StackTrace()
+			return append(args, sprintStackTrace(st))
+		}
+	}
+	return args
+}
+
 // Debug calls log.Debug
 func Debug(args ...interface{}) {
 	log.Debug(args...)
@@ -77,16 +101,19 @@ func Info(args ...interface{}) {
 
 // Warn calls log.Warn
 func Warn(args ...interface{}) {
+	args = appendStackTraceMaybeArgs(args)
 	log.Warn(args...)
 }
 
 // Error calls log.Error
 func Error(args ...interface{}) {
+	args = appendStackTraceMaybeArgs(args)
 	log.Error(args...)
 }
 
 // Fatal calls log.Fatal
 func Fatal(args ...interface{}) {
+	args = appendStackTraceMaybeArgs(args)
 	log.Fatal(args...)
 }
 
@@ -115,6 +142,21 @@ func Errorf(template string, args ...interface{}) {
 	log.Errorf(template, args...)
 }
 
+// appendStackTraceMaybeKV will append the stacktrace to the KV if one of them
+// is a tracerr.Error
+func appendStackTraceMaybeKV(msg string, kv []interface{}) string {
+	for i := range kv {
+		if i%2 == 0 {
+			continue
+		}
+		if err, ok := kv[i].(tracerr.Error); ok {
+			st := err.StackTrace()
+			return fmt.Sprintf("%v: %v%v\n", msg, err, sprintStackTrace(st))
+		}
+	}
+	return msg
+}
+
 // Debugw calls log.Debugw
 func Debugw(template string, kv ...interface{}) {
 	log.Debugw(template, kv...)
@@ -127,15 +169,18 @@ func Infow(template string, kv ...interface{}) {
 
 // Warnw calls log.Warnw
 func Warnw(template string, kv ...interface{}) {
+	template = appendStackTraceMaybeKV(template, kv)
 	log.Warnw(template, kv...)
 }
 
 // Errorw calls log.Errorw
 func Errorw(template string, kv ...interface{}) {
+	template = appendStackTraceMaybeKV(template, kv)
 	log.Errorw(template, kv...)
 }
 
 // Fatalw calls log.Fatalw
 func Fatalw(template string, kv ...interface{}) {
+	template = appendStackTraceMaybeKV(template, kv)
 	log.Fatalw(template, kv...)
 }