Fix log levels and enable ethereum-go logger (#256)

cmd/statusd/main.go

@@ -7,6 +7,7 @@ import (
 	"runtime"
 
 	"github.com/status-im/status-go/geth/api"
+	"github.com/status-im/status-go/geth/log"
 	"github.com/status-im/status-go/geth/params"
 	"gopkg.in/urfave/cli.v1"
 )
@@ -85,7 +86,7 @@ var (
 	// LogLevelFlag defines a log reporting level
 	LogLevelFlag = cli.StringFlag{
 		Name:  "log",
-		Usage: `Log level, one of: ""ERROR", "WARNING", "INFO", "DEBUG", and "TRACE"`,
+		Usage: `Log level, one of: "ERROR", "WARN", "INFO", "DEBUG", and "TRACE"`,
 		Value: "INFO",
 	}
 )
@@ -153,6 +154,7 @@ func makeNodeConfig(ctx *cli.Context) (*params.NodeConfig, error) {
 	if logLevel := ctx.GlobalString(LogLevelFlag.Name); len(logLevel) > 0 {
 		nodeConfig.LogEnabled = true
 		nodeConfig.LogLevel = logLevel
+		log.SetLevel(logLevel)
 	}
 
 	return nodeConfig, nil

geth/api/backend_jail_test.go

@@ -13,7 +13,6 @@ import (
 	"github.com/ethereum/go-ethereum/crypto"
 	whisper "github.com/ethereum/go-ethereum/whisper/whisperv5"
 	"github.com/status-im/status-go/geth/common"
-	"github.com/status-im/status-go/geth/jail"
 	"github.com/status-im/status-go/geth/log"
 	"github.com/status-im/status-go/geth/node"
 	"github.com/status-im/status-go/geth/params"

geth/log/log.go

@@ -1,75 +1,68 @@
 package log
 
 import (
+	"fmt"
+	"strings"
+
 	"github.com/ethereum/go-ethereum/log"
 )
 
-// Logger is wrapper for go-ethereum log
-type Logger struct {
-	output log.Logger
+// logger is package scope instance of log.Logger
+var logger = log.New("geth", "StatusIM")
+
+func init() {
+	SetLevel("INFO")
 }
 
-// Instance to a logger struct
-var logger *Logger
+// SetLevel inits status and ethereum-go logging packages,
+// enabling logging and setting up proper log level.
+//
+// Our log levels are in form "DEBUG|ERROR|WARN|etc", while
+// ethereum-go expects names in lower case: "debug|error|warn|etc".
+func SetLevel(level string) {
+	lvl, err := log.LvlFromString(strings.ToLower(level))
+	if err != nil {
+		fmt.Printf("Incorrect log level: %s, using defaults\n", level)
+		lvl = log.LvlInfo
+	}
 
-// Trace is a convenient alias for Root().Trace
+	setHandler(lvl, log.StdoutHandler)
+}
+
+// setHandler is a init helper that allows (re)initialization
+// with different handler. Useful for testing.
+func setHandler(lvl log.Lvl, handler log.Handler) {
+	h := log.LvlFilterHandler(lvl, handler)
+	logger.SetHandler(h)
+	log.Root().SetHandler(h) // ethereum-go logger
+}
+
+// Trace is a package scope alias for logger.Trace
 func Trace(msg string, ctx ...interface{}) {
-	printLog(log.LvlTrace, msg, ctx...)
+	logger.Trace(msg, ctx...)
 }
 
-// Debug is a convenient alias for Root().Debug
+// Debug is a package scope for logger.Debug
 func Debug(msg string, ctx ...interface{}) {
-	printLog(log.LvlDebug, msg, ctx...)
+	logger.Debug(msg, ctx...)
 }
 
-// Info is a convenient alias for Root().Info
+// Info is a package scope for logger.Info
 func Info(msg string, ctx ...interface{}) {
-	printLog(log.LvlInfo, msg, ctx...)
+	logger.Info(msg, ctx...)
 }
 
-// Warn is a convenient alias for Root().Warn
+// Warn is a package scope for logger.Warn
 func Warn(msg string, ctx ...interface{}) {
-	printLog(log.LvlWarn, msg, ctx...)
+	logger.Warn(msg, ctx...)
 }
 
-// Error is a convenient alias for Root().Error
+// Error is a package scope for logger.Error
 func Error(msg string, ctx ...interface{}) {
-	printLog(log.LvlError, msg, ctx...)
+	logger.Error(msg, ctx...)
 }
 
-// Crit is a convenient alias for Root().Crit
+// Crit is a package scope for logger.Crit
 func Crit(msg string, ctx ...interface{}) {
-	printLog(log.LvlCrit, msg, ctx...)
-}
-
-// outputs the log to a given log config level
-func printLog(lvl log.Lvl, msg string, ctx ...interface{}) {
-	if logger == nil {
-		logger = &Logger{
-			output: log.New("geth", "StatusIM"),
-		}
-		logger.output.SetHandler(log.StdoutHandler)
-	}
-
-	switch lvl {
-
-	case log.LvlError:
-		logger.output.Error(msg, ctx...)
-
-	case log.LvlWarn:
-		logger.output.Warn(msg, ctx...)
-
-	case log.LvlInfo:
-		logger.output.Info(msg, ctx...)
-
-	case log.LvlDebug:
-		logger.output.Debug(msg, ctx...)
-
-	case log.LvlTrace:
-		logger.output.Trace(msg, ctx...)
-
-	default:
-		logger.output.Info(msg, ctx...)
-
-	}
+	logger.Crit(msg, ctx...)
 }

geth/log/log_test.go

@@ -1,18 +1,51 @@
-// log_test
 package log
 
 import (
+	"bytes"
 	"testing"
+
+	"github.com/ethereum/go-ethereum/log"
 )
 
-func TestLogger(t *testing.T) {
+const (
+	trace = "trace log message\n"
+	debug = "debug log message\n"
+	info  = "info log message\n"
+	warn  = "warning log message\n"
+	err   = "error log message\n"
+)
 
-	t.Log("Testing log package..")
+func TestLogLevels(t *testing.T) {
+	var tests = []struct {
+		lvl log.Lvl
+		out string
+	}{
+		{log.LvlTrace, trace + debug + info + warn + err},
+		{log.LvlDebug, debug + info + warn + err},
+		{log.LvlInfo, info + warn + err},
+		{log.LvlWarn, warn + err},
+		{log.LvlError, err},
+	}
 
-	Trace("Trace Message")
-	Debug("Debug Message")
-	Info("Info Message")
-	Warn("Warn Message")
-	Error("Error Message")
-	Crit("Crit Message")
+	var buf bytes.Buffer
+	// log-comaptible handler that writes log in the buffer
+	handler := log.FuncHandler(func(r *log.Record) error {
+		_, err := buf.Write([]byte(r.Msg))
+		return err
+	})
+	for _, test := range tests {
+		buf.Reset()
+
+		setHandler(test.lvl, handler)
+
+		Trace(trace)
+		Debug(debug)
+		Info(info)
+		Warn(warn)
+		Error(err)
+
+		if buf.String() != test.out {
+			t.Errorf("Expecting log output to be '%s', got '%s'", test.out, buf.String())
+		}
+	}
 }

geth/testing/testing.go

@@ -11,6 +11,7 @@ import (
 
 	gethcommon "github.com/ethereum/go-ethereum/common"
 	"github.com/status-im/status-go/geth/common"
+	"github.com/status-im/status-go/geth/log"
 	"github.com/status-im/status-go/geth/params"
 	assertions "github.com/stretchr/testify/require"
 	"github.com/stretchr/testify/suite"
@@ -53,6 +54,8 @@ func init() {
 	if err != nil {
 		panic(err)
 	}
+
+	log.SetLevel("ERROR")
 }
 
 // BaseTestSuite defines a base tests suit which others suites can embedded to