rewrite logger

Signed-off-by: Vasiliy Tolstov <v.tolstov@unistack.org>

api/handler/rpc/rpc.go

@@ -224,7 +224,7 @@ func requestPayload(r *http.Request) ([]byte, error) {
 	case strings.Contains(ct, "application/json-rpc"):
 		msg := codec.Message{
 			Type:   codec.Request,
-			Header: make(map[string]string),
+			Header: metadata.New(0),
 		}
 		c := jsonrpc.NewCodec(&buffer{r.Body})
 		if err = c.ReadHeader(&msg, codec.Request); err != nil {
@@ -238,7 +238,7 @@ func requestPayload(r *http.Request) ([]byte, error) {
 	case strings.Contains(ct, "application/proto-rpc"), strings.Contains(ct, "application/octet-stream"):
 		msg := codec.Message{
 			Type:   codec.Request,
-			Header: make(map[string]string),
+			Header: metadata.New(0),
 		}
 		c := protorpc.NewCodec(&buffer{r.Body})
 		if err = c.ReadHeader(&msg, codec.Request); err != nil {
@@ -253,7 +253,7 @@ func requestPayload(r *http.Request) ([]byte, error) {
 		r.ParseForm()
 
 		// generate a new set of values from the form
-		vals := make(map[string]string)
+		vals := make(map[string]string, len(r.Form))
 		for k, v := range r.Form {
 			vals[k] = strings.Join(v, ",")
 		}
@@ -268,7 +268,7 @@ func requestPayload(r *http.Request) ([]byte, error) {
 	// dont user metadata.FromContext as it mangles names
 	md, ok := metadata.FromContext(ctx)
 	if !ok {
-		md = make(map[string]string)
+		md = metadata.New(0)
 	}
 
 	// allocate maximum
@@ -445,7 +445,7 @@ func writeError(w http.ResponseWriter, r *http.Request, err error) {
 	_, werr := w.Write([]byte(ce.Error()))
 	if werr != nil {
 		if logger.V(logger.ErrorLevel) {
-			logger.Error(werr)
+			logger.Error(werr.Error())
 		}
 	}
 }
@@ -471,7 +471,7 @@ func writeResponse(w http.ResponseWriter, r *http.Request, rsp []byte) {
 	_, err := w.Write(rsp)
 	if err != nil {
 		if logger.V(logger.ErrorLevel) {
-			logger.Error(err)
+			logger.Error(err.Error())
 		}
 	}
 

api/handler/rpc/stream.go

@@ -50,7 +50,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 	payload, err := requestPayload(r)
 	if err != nil {
 		if logger.V(logger.ErrorLevel) {
-			logger.Error(err)
+			logger.Error(err.Error())
 		}
 		return
 	}
@@ -73,7 +73,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 	conn, rw, _, err := upgrader.Upgrade(r, w)
 	if err != nil {
 		if logger.V(logger.ErrorLevel) {
-			logger.Error(err)
+			logger.Error(err.Error())
 		}
 		return
 	}
@@ -81,7 +81,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 	defer func() {
 		if err := conn.Close(); err != nil {
 			if logger.V(logger.ErrorLevel) {
-				logger.Error(err)
+				logger.Error(err.Error())
 			}
 			return
 		}
@@ -117,7 +117,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 	stream, err := c.Stream(ctx, req, callOpt)
 	if err != nil {
 		if logger.V(logger.ErrorLevel) {
-			logger.Error(err)
+			logger.Error(err.Error())
 		}
 		return
 	}
@@ -125,7 +125,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 	if request != nil {
 		if err = stream.Send(request); err != nil {
 			if logger.V(logger.ErrorLevel) {
-				logger.Error(err)
+				logger.Error(err.Error())
 			}
 			return
 		}
@@ -151,7 +151,7 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 					return
 				}
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 				return
 			}
@@ -159,13 +159,13 @@ func serveWebsocket(ctx context.Context, w http.ResponseWriter, r *http.Request,
 			// write the response
 			if err := wsutil.WriteServerMessage(rw, op, buf); err != nil {
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 				return
 			}
 			if err = rw.Flush(); err != nil {
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 				return
 			}
@@ -196,7 +196,7 @@ func writeLoop(rw io.ReadWriter, stream client.Stream) {
 					}
 				}
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 				return
 			}
@@ -213,7 +213,7 @@ func writeLoop(rw io.ReadWriter, stream client.Stream) {
 			request := &raw.Frame{Data: buf}
 			if err := stream.Send(request); err != nil {
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 				return
 			}

api/resolver/subdomain/subdomain.go

@@ -55,7 +55,7 @@ func (r *Resolver) Domain(req *http.Request) string {
 	domain, err := publicsuffix.EffectiveTLDPlusOne(host)
 	if err != nil {
 		if logger.V(logger.DebugLevel) {
-			logger.Debugf("Unable to extract domain from %v", host)
+			logger.Debug("Unable to extract domain from %v", host)
 		}
 		return ""
 	}

api/server/acme/autocert/autocert.go

@@ -36,7 +36,7 @@ func (a *autocertProvider) TLSConfig(hosts ...string) (*tls.Config, error) {
 	dir := cacheDir()
 	if err := os.MkdirAll(dir, 0700); err != nil {
 		if logger.V(logger.InfoLevel) {
-			logger.Infof("warning: autocert not using a cache: %v", err)
+			logger.Info("warning: autocert not using a cache: %v", err)
 		}
 	} else {
 		m.Cache = autocert.DirCache(dir)

api/server/http/http.go

@@ -15,7 +15,7 @@ type httpServer struct {
 	mux  *http.ServeMux
 	opts server.Options
 
-	mtx     sync.RWMutex
+	sync.RWMutex
 	address string
 	exit    chan chan error
 }
@@ -30,8 +30,8 @@ func NewServer(address string, opts ...server.Option) server.Server {
 }
 
 func (s *httpServer) Address() string {
-	s.mtx.RLock()
+	s.RLock()
-	defer s.mtx.RUnlock()
+	defer s.RUnlock()
 	return s.address
 }
 
@@ -57,6 +57,9 @@ func (s *httpServer) Start() error {
 	var l net.Listener
 	var err error
 
+	s.RLock()
+	config := s.opts
+	s.RUnlock()
 	if s.opts.EnableACME && s.opts.ACMEProvider != nil {
 		// should we check the address to make sure its using :443?
 		l, err = s.opts.ACMEProvider.Listen(s.opts.ACMEHosts...)
@@ -70,19 +73,19 @@ func (s *httpServer) Start() error {
 		return err
 	}
 
-	if logger.V(logger.InfoLevel) {
+	if config.Logger.V(logger.InfoLevel) {
-		logger.Infof("HTTP API Listening on %s", l.Addr().String())
+		config.Logger.Info("HTTP API Listening on %s", l.Addr().String())
 	}
 
-	s.mtx.Lock()
+	s.Lock()
 	s.address = l.Addr().String()
-	s.mtx.Unlock()
+	s.Unlock()
 
 	go func() {
 		if err := http.Serve(l, s.mux); err != nil {
 			// temporary fix
-			if logger.V(logger.ErrorLevel) {
+			if config.Logger.V(logger.ErrorLevel) {
-				logger.Errorf("serve err: %v", err)
+				config.Logger.Error("serve err: %v", err)
 			}
 			s.Stop()
 		}

api/server/options.go

@@ -6,6 +6,7 @@ import (
 
 	"github.com/unistack-org/micro/v3/api/resolver"
 	"github.com/unistack-org/micro/v3/api/server/acme"
+	"github.com/unistack-org/micro/v3/logger"
 )
 
 // Option func
@@ -21,11 +22,14 @@ type Options struct {
 	TLSConfig    *tls.Config
 	Resolver     resolver.Resolver
 	Wrappers     []Wrapper
+	Logger       logger.Logger
 }
 
 // NewOptions returns new Options
 func NewOptions(opts ...Option) Options {
-	options := Options{}
+	options := Options{
+		Logger: logger.DefaultLogger,
+	}
 	for _, o := range opts {
 		o(&options)
 	}
@@ -81,3 +85,9 @@ func Resolver(r resolver.Resolver) Option {
 		o.Resolver = r
 	}
 }
+
+func Logger(l logger.Logger) Option {
+	return func(o *Options) {
+		o.Logger = l
+	}
+}

client/noop.go

@@ -162,7 +162,7 @@ func (n *noopClient) Publish(ctx context.Context, p Message, opts ...PublishOpti
 
 	md, ok := metadata.FromContext(ctx)
 	if !ok {
-		md = make(map[string]string)
+		md = metadata.New(0)
 	}
 	md["Content-Type"] = p.ContentType()
 	md["Micro-Topic"] = p.Topic()

debug/log/memory/memory.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 
 	"github.com/unistack-org/micro/v3/debug/log"
+	"github.com/unistack-org/micro/v3/metadata"
 	"github.com/unistack-org/micro/v3/util/ring"
 )
 
@@ -94,7 +95,7 @@ func (l *memoryLog) Stream() (log.Stream, error) {
 			records <- log.Record{
 				Timestamp: entry.Timestamp,
 				Message:   entry.Value,
-				Metadata:  make(map[string]string),
+				Metadata:  metadata.New(0),
 			}
 		}
 		// now stream continuously
@@ -102,7 +103,7 @@ func (l *memoryLog) Stream() (log.Stream, error) {
 			records <- log.Record{
 				Timestamp: entry.Timestamp,
 				Message:   entry.Value,
-				Metadata:  make(map[string]string),
+				Metadata:  metadata.New(0),
 			}
 		}
 	}()

logger/helper.go

@@ -1,114 +0,0 @@
-package logger
-
-import (
-	"os"
-)
-
-type Helper struct {
-	Logger
-	fields map[string]interface{}
-}
-
-func NewHelper(log Logger) *Helper {
-	return &Helper{Logger: log}
-}
-
-func (h *Helper) Info(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(InfoLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(InfoLevel, args...)
-}
-
-func (h *Helper) Infof(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(InfoLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(InfoLevel, template, args...)
-}
-
-func (h *Helper) Trace(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(TraceLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(TraceLevel, args...)
-}
-
-func (h *Helper) Tracef(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(TraceLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(TraceLevel, template, args...)
-}
-
-func (h *Helper) Debug(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(DebugLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(DebugLevel, args...)
-}
-
-func (h *Helper) Debugf(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(DebugLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(DebugLevel, template, args...)
-}
-
-func (h *Helper) Warn(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(WarnLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(WarnLevel, args...)
-}
-
-func (h *Helper) Warnf(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(WarnLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(WarnLevel, template, args...)
-}
-
-func (h *Helper) Error(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(ErrorLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(ErrorLevel, args...)
-}
-
-func (h *Helper) Errorf(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(ErrorLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(ErrorLevel, template, args...)
-}
-
-func (h *Helper) Fatal(args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(FatalLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Log(FatalLevel, args...)
-	os.Exit(1)
-}
-
-func (h *Helper) Fatalf(template string, args ...interface{}) {
-	if !h.Logger.Options().Level.Enabled(FatalLevel) {
-		return
-	}
-	h.Logger.Fields(h.fields).Logf(FatalLevel, template, args...)
-	os.Exit(1)
-}
-
-func (h *Helper) WithError(err error) *Helper {
-	fields := copyFields(h.fields)
-	fields["error"] = err
-	return &Helper{Logger: h.Logger, fields: fields}
-}
-
-func (h *Helper) WithFields(fields map[string]interface{}) *Helper {
-	nfields := copyFields(fields)
-	for k, v := range h.fields {
-		nfields[k] = v
-	}
-	return &Helper{Logger: h.Logger, fields: nfields}
-}

logger/level.go

@@ -2,7 +2,6 @@ package logger
 
 import (
 	"fmt"
-	"os"
 )
 
 type Level int8
@@ -19,7 +18,7 @@ const (
 	WarnLevel
 	// ErrorLevel level. Logs. Used for errors that should definitely be noted.
 	ErrorLevel
-	// FatalLevel level. Logs and then calls `logger.Exit(1)`. highest level of severity.
+	// FatalLevel level. Logs and then calls `os.Exit(1)`. highest level of severity.
 	FatalLevel
 )
 
@@ -63,60 +62,5 @@ func GetLevel(levelStr string) (Level, error) {
 	case FatalLevel.String():
 		return FatalLevel, nil
 	}
-	return InfoLevel, fmt.Errorf("Unknown Level String: '%s', defaulting to InfoLevel", levelStr)
+	return InfoLevel, fmt.Errorf("unknown Level String: '%s', use InfoLevel", levelStr)
-}
-
-func Info(args ...interface{}) {
-	DefaultLogger.Log(InfoLevel, args...)
-}
-
-func Infof(template string, args ...interface{}) {
-	DefaultLogger.Logf(InfoLevel, template, args...)
-}
-
-func Trace(args ...interface{}) {
-	DefaultLogger.Log(TraceLevel, args...)
-}
-
-func Tracef(template string, args ...interface{}) {
-	DefaultLogger.Logf(TraceLevel, template, args...)
-}
-
-func Debug(args ...interface{}) {
-	DefaultLogger.Log(DebugLevel, args...)
-}
-
-func Debugf(template string, args ...interface{}) {
-	DefaultLogger.Logf(DebugLevel, template, args...)
-}
-
-func Warn(args ...interface{}) {
-	DefaultLogger.Log(WarnLevel, args...)
-}
-
-func Warnf(template string, args ...interface{}) {
-	DefaultLogger.Logf(WarnLevel, template, args...)
-}
-
-func Error(args ...interface{}) {
-	DefaultLogger.Log(ErrorLevel, args...)
-}
-
-func Errorf(template string, args ...interface{}) {
-	DefaultLogger.Logf(ErrorLevel, template, args...)
-}
-
-func Fatal(args ...interface{}) {
-	DefaultLogger.Log(FatalLevel, args...)
-	os.Exit(1)
-}
-
-func Fatalf(template string, args ...interface{}) {
-	DefaultLogger.Logf(FatalLevel, template, args...)
-	os.Exit(1)
-}
-
-// Returns true if the given level is at or lower the current logger level
-func V(lvl Level) bool {
-	return DefaultLogger.Options().Level <= lvl
 }

logger/logger.go

@@ -3,7 +3,7 @@ package logger
 
 var (
 	// DefaultLogger variable
-	DefaultLogger Logger = NewHelper(NewLogger())
+	DefaultLogger Logger = NewLogger()
 )
 
 // Logger is a generic logging interface
@@ -16,14 +16,50 @@ type Logger interface {
 	Options() Options
 	// Fields set fields to always be logged
 	Fields(fields map[string]interface{}) Logger
-	// Log writes a log entry
+	// Info level message
-	Log(level Level, v ...interface{})
+	Info(msg string, args ...interface{})
-	// Logf writes a formatted log entry
+	// Trace level message
-	Logf(level Level, format string, v ...interface{})
+	Trace(msg string, args ...interface{})
+	// Debug level message
+	Debug(msg string, args ...interface{})
+	// Warn level message
+	Warn(msg string, args ...interface{})
+	// Error level message
+	Error(msg string, args ...interface{})
+	// Fatal level message
+	Fatal(msg string, args ...interface{})
 	// String returns the name of logger
 	String() string
 }
 
+func Info(msg string, args ...interface{}) {
+	DefaultLogger.Info(msg, args...)
+}
+
+func Error(msg string, args ...interface{}) {
+	DefaultLogger.Error(msg, args...)
+}
+
+func Debug(msg string, args ...interface{}) {
+	DefaultLogger.Debug(msg, args...)
+}
+
+func Warn(msg string, args ...interface{}) {
+	DefaultLogger.Warn(msg, args...)
+}
+
+func Trace(msg string, args ...interface{}) {
+	DefaultLogger.Trace(msg, args...)
+}
+
+func Fatal(msg string, args ...interface{}) {
+	DefaultLogger.Fatal(msg, args...)
+}
+
+func V(level Level) bool {
+	return DefaultLogger.V(level)
+}
+
 // Init initialize logger
 func Init(opts ...Option) error {
 	return DefaultLogger.Init(opts...)
@@ -33,18 +69,3 @@ func Init(opts ...Option) error {
 func Fields(fields map[string]interface{}) Logger {
 	return DefaultLogger.Fields(fields)
 }
-
-// Log writes log with specific level
-func Log(level Level, v ...interface{}) {
-	DefaultLogger.Log(level, v...)
-}
-
-// Logf writes formatted log with specific level
-func Logf(level Level, format string, v ...interface{}) {
-	DefaultLogger.Logf(level, format, v...)
-}
-
-// String return logger name
-func String() string {
-	return DefaultLogger.String()
-}

logger/logger_test.go

@@ -6,13 +6,10 @@ import (
 
 func TestLogger(t *testing.T) {
 	l := NewLogger(WithLevel(TraceLevel))
-	h1 := NewHelper(l).WithFields(map[string]interface{}{"key1": "val1"})
+	if err := l.Init(); err != nil {
-	h1.Trace("trace_msg1")
+		t.Fatal(err)
-	h1.Warn("warn_msg1")
+	}
-
+	l.Trace("trace_msg1")
-	h2 := NewHelper(l).WithFields(map[string]interface{}{"key2": "val2"})
+	l.Warn("warn_msg1")
-	h2.Trace("trace_msg2")
+	l.Fields(map[string]interface{}{"error": "test"}).Info("error message")
-	h2.Warn("warn_msg2")
-
-	l.Fields(map[string]interface{}{"key3": "val4"}).Log(InfoLevel, "test_msg")
 }

logger/micro.go

@@ -1,16 +1,13 @@
 package logger
 
 import (
-	"context"
+	"encoding/json"
 	"fmt"
 	"os"
 	"runtime"
-	"sort"
 	"strings"
 	"sync"
 	"time"
-
-	dlog "github.com/unistack-org/micro/v3/debug/log"
 )
 
 func init() {
@@ -19,31 +16,33 @@ func init() {
 		lvl = InfoLevel
 	}
 
-	DefaultLogger = NewHelper(NewLogger(WithLevel(lvl)))
+	DefaultLogger = NewLogger(WithLevel(lvl))
 }
 
 type defaultLogger struct {
 	sync.RWMutex
 	opts Options
+	enc  *json.Encoder
 }
 
 // Init(opts...) should only overwrite provided options
 func (l *defaultLogger) Init(opts ...Option) error {
+	l.Lock()
+	defer l.Unlock()
+
 	for _, o := range opts {
 		o(&l.opts)
 	}
+	l.enc = json.NewEncoder(l.opts.Out)
 	return nil
 }
 
 func (l *defaultLogger) String() string {
-	return "default"
+	return "micro"
 }
 
 func (l *defaultLogger) V(level Level) bool {
-	if l.opts.Level.Enabled(level) {
+	return l.opts.Level.Enabled(level)
-		return true
-	}
-	return false
 }
 
 func (l *defaultLogger) Fields(fields map[string]interface{}) Logger {
@@ -85,45 +84,32 @@ func logCallerfilePath(loggingFilePath string) string {
 	return loggingFilePath[idx+1:]
 }
 
-func (l *defaultLogger) Log(level Level, v ...interface{}) {
+func (l *defaultLogger) Info(msg string, args ...interface{}) {
-	if !l.V(level) {
+	l.log(InfoLevel, msg, args...)
-		return
-	}
-
-	l.RLock()
-	fields := copyFields(l.opts.Fields)
-	l.RUnlock()
-
-	fields["level"] = level.String()
-
-	if _, file, line, ok := runtime.Caller(l.opts.CallerSkipCount); ok {
-		fields["file"] = fmt.Sprintf("%s:%d", logCallerfilePath(file), line)
-	}
-
-	rec := dlog.Record{
-		Timestamp: time.Now(),
-		Message:   fmt.Sprint(v...),
-		Metadata:  make(map[string]string, len(fields)),
-	}
-
-	keys := make([]string, 0, len(fields))
-	for k, v := range fields {
-		keys = append(keys, k)
-		rec.Metadata[k] = fmt.Sprintf("%v", v)
-	}
-
-	sort.Strings(keys)
-	metadata := ""
-
-	for _, k := range keys {
-		metadata += fmt.Sprintf(" %s=%v", k, fields[k])
-	}
-
-	t := rec.Timestamp.Format("2006-01-02 15:04:05")
-	fmt.Printf("%s %s %v\n", t, metadata, rec.Message)
 }
 
-func (l *defaultLogger) Logf(level Level, format string, v ...interface{}) {
+func (l *defaultLogger) Error(msg string, args ...interface{}) {
+	l.log(ErrorLevel, msg, args...)
+}
+
+func (l *defaultLogger) Debug(msg string, args ...interface{}) {
+	l.log(DebugLevel, msg, args...)
+}
+
+func (l *defaultLogger) Warn(msg string, args ...interface{}) {
+	l.log(WarnLevel, msg, args...)
+}
+
+func (l *defaultLogger) Trace(msg string, args ...interface{}) {
+	l.log(TraceLevel, msg, args...)
+}
+
+func (l *defaultLogger) Fatal(msg string, args ...interface{}) {
+	l.log(FatalLevel, msg, args...)
+	os.Exit(1)
+}
+
+func (l *defaultLogger) log(level Level, msg string, args ...interface{}) {
 	if !l.V(level) {
 		return
 	}
@@ -135,30 +121,20 @@ func (l *defaultLogger) Logf(level Level, format string, v ...interface{}) {
 	fields["level"] = level.String()
 
 	if _, file, line, ok := runtime.Caller(l.opts.CallerSkipCount); ok {
-		fields["file"] = fmt.Sprintf("%s:%d", logCallerfilePath(file), line)
+		fields["caller"] = fmt.Sprintf("%s:%d", logCallerfilePath(file), line)
 	}
 
-	rec := dlog.Record{
+	fields["timestamp"] = time.Now().Format("2006-01-02 15:04:05")
-		Timestamp: time.Now(),
+	if len(msg) > 0 {
-		Message:   fmt.Sprintf(format, v...),
+		if len(args) > 0 {
-		Metadata:  make(map[string]string, len(fields)),
+			fields["msg"] = fmt.Sprintf(msg, args...)
+		} else {
+			fields["msg"] = msg
 		}
-
-	keys := make([]string, 0, len(fields))
-	for k, v := range fields {
-		keys = append(keys, k)
-		rec.Metadata[k] = fmt.Sprintf("%v", v)
 	}
-
+	l.RLock()
-	sort.Strings(keys)
+	_ = l.enc.Encode(fields)
-	metadata := ""
+	l.RUnlock()
-
-	for _, k := range keys {
-		metadata += fmt.Sprintf(" %s=%v", k, fields[k])
-	}
-
-	t := rec.Timestamp.Format("2006-01-02 15:04:05")
-	fmt.Printf("%s %s %v\n", t, metadata, rec.Message)
 }
 
 func (l *defaultLogger) Options() Options {
@@ -172,19 +148,7 @@ func (l *defaultLogger) Options() Options {
 
 // NewLogger builds a new logger based on options
 func NewLogger(opts ...Option) Logger {
-	// Default options
+	l := &defaultLogger{opts: NewOptions(opts...)}
-	options := Options{
+	l.enc = json.NewEncoder(l.opts.Out)
-		Level:           InfoLevel,
-		Fields:          make(map[string]interface{}),
-		Out:             os.Stderr,
-		CallerSkipCount: 2,
-		Context:         context.Background(),
-	}
-
-	l := &defaultLogger{opts: options}
-	if err := l.Init(opts...); err != nil {
-		l.Log(FatalLevel, err)
-	}
-
 	return l
 }

logger/options.go

@@ -3,6 +3,7 @@ package logger
 import (
 	"context"
 	"io"
+	"os"
 )
 
 type Option func(*Options)
@@ -21,7 +22,13 @@ type Options struct {
 }
 
 func NewOptions(opts ...Option) Options {
-	options := Options{}
+	options := Options{
+		Level:           InfoLevel,
+		Fields:          make(map[string]interface{}),
+		Out:             os.Stderr,
+		CallerSkipCount: 2,
+		Context:         context.Background(),
+	}
 	for _, o := range opts {
 		o(&options)
 	}

network/tunnel/broker/broker.go

@@ -113,11 +113,11 @@ func (t *tunSubscriber) run() {
 		m := new(transport.Message)
 		if err := c.Recv(m); err != nil {
 			if logger.V(logger.ErrorLevel) {
-				logger.Error(err)
+				logger.Error(err.Error())
 			}
 			if err = c.Close(); err != nil {
 				if logger.V(logger.ErrorLevel) {
-					logger.Error(err)
+					logger.Error(err.Error())
 				}
 			}
 			continue

registry/extractor.go

@@ -4,6 +4,8 @@ import (
 	"fmt"
 	"reflect"
 	"strings"
+
+	"github.com/unistack-org/micro/v3/metadata"
 )
 
 // Extract *Value from reflect.Type
@@ -94,7 +96,7 @@ func ExtractEndpoint(method reflect.Method) *Endpoint {
 		Name:     method.Name,
 		Request:  request,
 		Response: response,
-		Metadata: make(map[string]string),
+		Metadata: metadata.New(0),
 	}
 
 	if stream {

server/noop.go

@@ -187,8 +187,8 @@ func (n *noopServer) Register() error {
 	n.RUnlock()
 
 	if !registered {
-		if logger.V(logger.InfoLevel) {
+		if config.Logger.V(logger.InfoLevel) {
-			logger.Infof("Registry [%s] Registering node: %s", config.Registry.String(), service.Nodes[0].Id)
+			config.Logger.Info("Registry [%s] Registering node: %s", config.Registry.String(), service.Nodes[0].Id)
 		}
 	}
 
@@ -220,8 +220,8 @@ func (n *noopServer) Register() error {
 
 		opts = append(opts, broker.SubscribeContext(cx), broker.SubscribeAutoAck(sb.Options().AutoAck))
 
-		if logger.V(logger.InfoLevel) {
+		if config.Logger.V(logger.InfoLevel) {
-			logger.Infof("Subscribing to topic: %s", sb.Topic())
+			config.Logger.Info("Subscribing to topic: %s", sb.Topic())
 		}
 		sub, err := config.Broker.Subscribe(cx, sb.Topic(), handler, opts...)
 		if err != nil {
@@ -250,8 +250,8 @@ func (n *noopServer) Deregister() error {
 		return err
 	}
 
-	if logger.V(logger.InfoLevel) {
+	if config.Logger.V(logger.InfoLevel) {
-		logger.Infof("Deregistering node: %s", service.Nodes[0].Id)
+		config.Logger.Info("deregistering node: %s", service.Nodes[0].Id)
 	}
 
 	if err := DefaultDeregisterFunc(service, config); err != nil {
@@ -280,12 +280,12 @@ func (n *noopServer) Deregister() error {
 			wg.Add(1)
 			go func(s broker.Subscriber) {
 				defer wg.Done()
-				if logger.V(logger.InfoLevel) {
+				if config.Logger.V(logger.InfoLevel) {
-					logger.Infof("Unsubscribing from topic: %s", s.Topic())
+					config.Logger.Info("unsubscribing from topic: %s", s.Topic())
 				}
 				if err := s.Unsubscribe(cx); err != nil {
-					if logger.V(logger.ErrorLevel) {
+					if config.Logger.V(logger.ErrorLevel) {
-						logger.Errorf("Unsubscribing from topic: %s err: %v", s.Topic(), err)
+						config.Logger.Error("unsubscribing from topic: %s err: %v", s.Topic(), err)
 					}
 				}
 			}(sub)
@@ -307,8 +307,8 @@ func (n *noopServer) Start() error {
 	config := n.Options()
 	n.RUnlock()
 
-	if logger.V(logger.InfoLevel) {
+	if config.Logger.V(logger.InfoLevel) {
-		logger.Infof("Server [noop] Listening on %s", config.Address)
+		config.Logger.Info("Server [noop] Listening on %s", config.Address)
 	}
 	n.Lock()
 	if len(config.Advertise) == 0 {
@@ -320,27 +320,27 @@ func (n *noopServer) Start() error {
 	if len(n.subscribers) > 0 {
 		// connect to the broker
 		if err := config.Broker.Connect(config.Context); err != nil {
-			if logger.V(logger.ErrorLevel) {
+			if config.Logger.V(logger.ErrorLevel) {
-				logger.Errorf("Broker [%s] connect error: %v", config.Broker.String(), err)
+				config.Logger.Error("Broker [%s] connect error: %v", config.Broker.String(), err)
 			}
 			return err
 		}
 
-		if logger.V(logger.InfoLevel) {
+		if config.Logger.V(logger.InfoLevel) {
-			logger.Infof("Broker [%s] Connected to %s", config.Broker.String(), config.Broker.Address())
+			config.Logger.Info("Broker [%s] Connected to %s", config.Broker.String(), config.Broker.Address())
 		}
 	}
 
 	// use RegisterCheck func before register
 	if err := config.RegisterCheck(config.Context); err != nil {
-		if logger.V(logger.ErrorLevel) {
+		if config.Logger.V(logger.ErrorLevel) {
-			logger.Errorf("Server %s-%s register check error: %s", config.Name, config.Id, err)
+			config.Logger.Error("Server %s-%s register check error: %s", config.Name, config.Id, err)
 		}
 	} else {
 		// announce self to the world
 		if err := n.Register(); err != nil {
-			if logger.V(logger.ErrorLevel) {
+			if config.Logger.V(logger.ErrorLevel) {
-				logger.Errorf("Server register error: %v", err)
+				config.Logger.Error("Server register error: %v", err)
 			}
 		}
 	}
@@ -367,24 +367,24 @@ func (n *noopServer) Start() error {
 				n.RUnlock()
 				rerr := config.RegisterCheck(config.Context)
 				if rerr != nil && registered {
-					if logger.V(logger.ErrorLevel) {
+					if config.Logger.V(logger.ErrorLevel) {
-						logger.Errorf("Server %s-%s register check error: %s, deregister it", config.Name, config.Id, rerr)
+						config.Logger.Error("Server %s-%s register check error: %s, deregister it", config.Name, config.Id, rerr)
 					}
 					// deregister self in case of error
 					if err := n.Deregister(); err != nil {
-						if logger.V(logger.ErrorLevel) {
+						if config.Logger.V(logger.ErrorLevel) {
-							logger.Errorf("Server %s-%s deregister error: %s", config.Name, config.Id, err)
+							config.Logger.Error("Server %s-%s deregister error: %s", config.Name, config.Id, err)
 						}
 					}
 				} else if rerr != nil && !registered {
-					if logger.V(logger.ErrorLevel) {
+					if config.Logger.V(logger.ErrorLevel) {
-						logger.Errorf("Server %s-%s register check error: %s", config.Name, config.Id, rerr)
+						config.Logger.Error("Server %s-%s register check error: %s", config.Name, config.Id, rerr)
 					}
 					continue
 				}
 				if err := n.Register(); err != nil {
-					if logger.V(logger.ErrorLevel) {
+					if config.Logger.V(logger.ErrorLevel) {
-						logger.Errorf("Server %s-%s register error: %s", config.Name, config.Id, err)
+						config.Logger.Error("Server %s-%s register error: %s", config.Name, config.Id, err)
 					}
 				}
 			// wait for exit
@@ -395,8 +395,8 @@ func (n *noopServer) Start() error {
 
 		// deregister self
 		if err := n.Deregister(); err != nil {
-			if logger.V(logger.ErrorLevel) {
+			if config.Logger.V(logger.ErrorLevel) {
-				logger.Error("Server deregister error: ", err)
+				config.Logger.Error("Server deregister error: ", err)
 			}
 		}
 
@@ -419,13 +419,13 @@ func (n *noopServer) Start() error {
 		// close transport
 		ch <- nil
 
-		if logger.V(logger.InfoLevel) {
+		if config.Logger.V(logger.InfoLevel) {
-			logger.Infof("Broker [%s] Disconnected from %s", config.Broker.String(), config.Broker.Address())
+			config.Logger.Info("Broker [%s] Disconnected from %s", config.Broker.String(), config.Broker.Address())
 		}
 		// disconnect broker
 		if err := config.Broker.Disconnect(config.Context); err != nil {
-			if logger.V(logger.ErrorLevel) {
+			if config.Logger.V(logger.ErrorLevel) {
-				logger.Errorf("Broker [%s] disconnect error: %v", config.Broker.String(), err)
+				config.Logger.Error("Broker [%s] disconnect error: %v", config.Broker.String(), err)
 			}
 		}
 	}()

server/subscriber.go

@@ -189,9 +189,12 @@ func (n *noopServer) createSubHandler(sb *subscriber, opts Options) broker.Handl
 	return func(p broker.Event) (err error) {
 		defer func() {
 			if r := recover(); r != nil {
-				if logger.V(logger.ErrorLevel) {
+				n.RLock()
-					logger.Error("panic recovered: ", r)
+				config := n.opts
-					logger.Error(string(debug.Stack()))
+				n.RUnlock()
+				if config.Logger.V(logger.ErrorLevel) {
+					config.Logger.Error("panic recovered: ", r)
+					config.Logger.Error(string(debug.Stack()))
 				}
 				err = errors.InternalServerError(n.opts.Name+".subscriber", "panic recovered: %v", r)
 			}

service.go

@@ -17,6 +17,7 @@ import (
 type service struct {
 	opts Options
 
+	sync.RWMutex
 	once sync.Once
 }
 
@@ -128,8 +129,13 @@ func (s *service) String() string {
 
 func (s *service) Start() error {
 	var err error
-	if logger.V(logger.InfoLevel) {
+
-		logger.Infof("Starting [service] %s", s.Name())
+	s.RLock()
+	config := s.opts
+	s.RUnlock()
+
+	if config.Logger.V(logger.InfoLevel) {
+		config.Logger.Info("Starting [service] %s", s.Name())
 	}
 
 	for _, fn := range s.opts.BeforeStart {
@@ -174,8 +180,12 @@ func (s *service) Start() error {
 }
 
 func (s *service) Stop() error {
-	if logger.V(logger.InfoLevel) {
+	s.RLock()
-		logger.Infof("Stoppping [service] %s", s.Name())
+	config := s.opts
+	s.RUnlock()
+
+	if config.Logger.V(logger.InfoLevel) {
+		config.Logger.Info("Stoppping [service] %s", s.Name())
 	}
 
 	var err error

util/auth/auth.go

@@ -26,7 +26,7 @@ func Verify(a auth.Auth) error {
 			return err
 		}
 		if logger.V(logger.DebugLevel) {
-			logger.Debugf("Auth [%v] Generated an auth account", a.String())
+			logger.Debug("Auth [%v] Generated an auth account: %s", a.String())
 		}
 
 		accID = acc.ID
@@ -68,7 +68,7 @@ func Verify(a auth.Auth) error {
 			)
 			if err != nil {
 				if logger.V(logger.WarnLevel) {
-					logger.Warnf("[Auth] Error refreshing token: %v", err)
+					logger.Warn("[Auth] Error refreshing token: %v", err)
 				}
 				continue
 			}

util/kubernetes/api/request.go

@@ -219,7 +219,7 @@ func (r *Request) Do() *Response {
 		}
 	}
 
-	logger.Debugf("[Kubernetes] %v %v", req.Method, req.URL.String())
+	logger.Debug("[Kubernetes] %v %v", req.Method, req.URL.String())
 	res, err := r.client.Do(req)
 	if err != nil {
 		return &Response{

util/kubernetes/client/client.go

@@ -228,7 +228,7 @@ func (c *client) Watch(r *Resource, opts ...WatchOption) (Watcher, error) {
 // NewService returns default micro kubernetes service definition
 func NewService(name, version, typ, namespace string) *Service {
 	if logger.V(logger.TraceLevel) {
-		logger.Tracef("kubernetes default service: name: %s, version: %s", name, version)
+		logger.Trace("kubernetes default service: name: %s, version: %s", name, version)
 	}
 
 	Labels := map[string]string{
@@ -271,7 +271,7 @@ func NewService(name, version, typ, namespace string) *Service {
 // NewService returns default micro kubernetes deployment definition
 func NewDeployment(name, version, typ, namespace string) *Deployment {
 	if logger.V(logger.TraceLevel) {
-		logger.Tracef("kubernetes default deployment: name: %s, version: %s", name, version)
+		logger.Trace("kubernetes default deployment: name: %s, version: %s", name, version)
 	}
 
 	Labels := map[string]string{
@@ -363,21 +363,21 @@ func NewClusterClient() *client {
 
 	s, err := os.Stat(serviceAccountPath)
 	if err != nil {
-		logger.Fatal(err)
+		logger.Fatal(err.Error())
 	}
 	if s == nil || !s.IsDir() {
-		logger.Fatal(errors.New("service account not found"))
+		logger.Fatal("service account not found")
 	}
 
 	token, err := ioutil.ReadFile(path.Join(serviceAccountPath, "token"))
 	if err != nil {
-		logger.Fatal(err)
+		logger.Fatal(err.Error())
 	}
 	t := string(token)
 
 	crt, err := CertPoolFromFile(path.Join(serviceAccountPath, "ca.crt"))
 	if err != nil {
-		logger.Fatal(err)
+		logger.Fatal(err.Error())
 	}
 
 	c := &http.Client{

util/mdns/server.go

@@ -9,7 +9,7 @@ import (
 	"time"
 
 	"github.com/miekg/dns"
-	log "github.com/unistack-org/micro/v3/logger"
+	"github.com/unistack-org/micro/v3/logger"
 	"golang.org/x/net/ipv4"
 	"golang.org/x/net/ipv6"
 )
@@ -196,7 +196,7 @@ func (s *Server) recv(c *net.UDPConn) {
 			continue
 		}
 		if err := s.parsePacket(buf[:n], from); err != nil {
-			log.Errorf("[ERR] mdns: Failed to handle query: %v", err)
+			logger.Error("[ERR] mdns: Failed to handle query: %v", err)
 		}
 	}
 }
@@ -205,7 +205,7 @@ func (s *Server) recv(c *net.UDPConn) {
 func (s *Server) parsePacket(packet []byte, from net.Addr) error {
 	var msg dns.Msg
 	if err := msg.Unpack(packet); err != nil {
-		log.Errorf("[ERR] mdns: Failed to unpack packet: %v", err)
+		logger.Error("[ERR] mdns: Failed to unpack packet: %v", err)
 		return err
 	}
 	// TODO: This is a bit of a hack
@@ -384,7 +384,7 @@ func (s *Server) probe() {
 
 	for i := 0; i < 3; i++ {
 		if err := s.SendMulticast(q); err != nil {
-			log.Errorf("[ERR] mdns: failed to send probe:", err.Error())
+			logger.Error("[ERR] mdns: failed to send probe: %v", err)
 		}
 		time.Sleep(time.Duration(randomizer.Intn(250)) * time.Millisecond)
 	}
@@ -410,7 +410,7 @@ func (s *Server) probe() {
 	timer := time.NewTimer(timeout)
 	for i := 0; i < 3; i++ {
 		if err := s.SendMulticast(resp); err != nil {
-			log.Errorf("[ERR] mdns: failed to send announcement:", err.Error())
+			logger.Error("[ERR] mdns: failed to send announcement:", err.Error())
 		}
 		select {
 		case <-timer.C:

util/router/parse.go

@@ -103,20 +103,20 @@ type parser struct {
 // topLevelSegments is the target of this parser.
 func (p *parser) topLevelSegments() ([]segment, error) {
 	if logger.V(logger.TraceLevel) {
-		logger.Debugf("Parsing %q", p.tokens)
+		logger.Debug("Parsing %q", p.tokens)
 	}
 	segs, err := p.segments()
 	if err != nil {
 		return nil, err
 	}
 	if logger.V(logger.TraceLevel) {
-		logger.Tracef("accept segments: %q; %q", p.accepted, p.tokens)
+		logger.Trace("accept segments: %q; %q", p.accepted, p.tokens)
 	}
 	if _, err := p.accept(typeEOF); err != nil {
 		return nil, fmt.Errorf("unexpected token %q after segments %q", p.tokens[0], strings.Join(p.accepted, ""))
 	}
 	if logger.V(logger.TraceLevel) {
-		logger.Tracef("accept eof: %q; %q", p.accepted, p.tokens)
+		logger.Trace("accept eof: %q; %q", p.accepted, p.tokens)
 	}
 	return segs, nil
 }
@@ -128,7 +128,7 @@ func (p *parser) segments() ([]segment, error) {
 	}
 
 	if logger.V(logger.TraceLevel) {
-		logger.Tracef("accept segment: %q; %q", p.accepted, p.tokens)
+		logger.Trace("accept segment: %q; %q", p.accepted, p.tokens)
 	}
 	segs := []segment{s}
 	for {
@@ -141,7 +141,7 @@ func (p *parser) segments() ([]segment, error) {
 		}
 		segs = append(segs, s)
 		if logger.V(logger.TraceLevel) {
-			logger.Tracef("accept segment: %q; %q", p.accepted, p.tokens)
+			logger.Trace("accept segment: %q; %q", p.accepted, p.tokens)
 		}
 	}
 }

util/router/parse_test.go

@@ -316,6 +316,6 @@ func TestParseSegmentsWithErrors(t *testing.T) {
 			t.Errorf("parser{%q}.segments() succeeded; want InvalidTemplateError; accepted %#v", spec.tokens, segs)
 			continue
 		}
-		logger.Info(err)
+		logger.Info(err.Error())
 	}
 }

util/router/runtime.go

@@ -63,7 +63,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 
 	if version != 1 {
 		if logger.V(logger.DebugLevel) {
-			logger.Debugf("unsupported version: %d", version)
+			logger.Debug("unsupported version: %d", version)
 		}
 		return Pattern{}, ErrInvalidPattern
 	}
@@ -71,7 +71,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 	l := len(ops)
 	if l%2 != 0 {
 		if logger.V(logger.DebugLevel) {
-			logger.Debugf("odd number of ops codes: %d", l)
+			logger.Debug("odd number of ops codes: %d", l)
 		}
 		return Pattern{}, ErrInvalidPattern
 	}
@@ -105,7 +105,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 		case OpLitPush:
 			if op.operand < 0 || len(pool) <= op.operand {
 				if logger.V(logger.TraceLevel) {
-					logger.Tracef("negative literal index: %d", op.operand)
+					logger.Trace("negative literal index: %d", op.operand)
 				}
 				return Pattern{}, ErrInvalidPattern
 			}
@@ -116,7 +116,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 		case OpConcatN:
 			if op.operand <= 0 {
 				if logger.V(logger.TraceLevel) {
-					logger.Tracef("negative concat size: %d", op.operand)
+					logger.Trace("negative concat size: %d", op.operand)
 				}
 				return Pattern{}, ErrInvalidPattern
 			}
@@ -131,7 +131,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 		case OpCapture:
 			if op.operand < 0 || len(pool) <= op.operand {
 				if logger.V(logger.TraceLevel) {
-					logger.Tracef("variable name index out of bound: %d", op.operand)
+					logger.Trace("variable name index out of bound: %d", op.operand)
 				}
 				return Pattern{}, ErrInvalidPattern
 			}
@@ -147,7 +147,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 			}
 		default:
 			if logger.V(logger.DebugLevel) {
-				logger.Tracef("invalid opcode: %d", op.code)
+				logger.Trace("invalid opcode: %d", op.code)
 			}
 			return Pattern{}, ErrInvalidPattern
 		}
@@ -172,7 +172,7 @@ func NewPattern(version int, ops []int, pool []string, verb string, opts ...Patt
 func MustPattern(p Pattern, err error) Pattern {
 	if err != nil {
 		if logger.V(logger.FatalLevel) {
-			logger.Fatalf("Pattern initialization failed: %v", err)
+			logger.Fatal("Pattern initialization failed: %v", err)
 		}
 	}
 	return p
@@ -235,7 +235,7 @@ func (p Pattern) Match(components []string, verb string) (map[string]string, err
 	if pos < l {
 		return nil, ErrNotMatch
 	}
-	bindings := make(map[string]string)
+	bindings := make(map[string]string, len(captured))
 	for i, val := range captured {
 		bindings[p.vars[i]] = val
 	}