From 89ba602e17acbec740e5f27af7b490e539f2193b Mon Sep 17 00:00:00 2001
From: Vasiliy Tolstov <v.tolstov@unistack.org>
Date: Tue, 3 Mar 2020 11:07:38 +0300
Subject: [PATCH] logger fixes and improvements (#1285)

* fix helper fields
* add metadata output for default logger

Signed-off-by: Vasiliy Tolstov <v.tolstov@unistack.org>
---
 logger/default.go     | 25 +++++++++++++++++++++++--
 logger/helper.go      | 37 ++++++++++++++++++++++---------------
 logger/logger_test.go | 10 ++++++++--
 3 files changed, 53 insertions(+), 19 deletions(-)

diff --git a/logger/default.go b/logger/default.go
index ce4498ef..4eb0e1b6 100644
--- a/logger/default.go
+++ b/logger/default.go
@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 	"os"
+	"sort"
 	"sync"
 	"time"
 
@@ -59,14 +60,24 @@ func (l *defaultLogger) Log(level Level, v ...interface{}) {
 		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])
+	}
+
 	dlog.DefaultLog.Write(rec)
 
 	t := rec.Timestamp.Format("2006-01-02 15:04:05")
-	fmt.Printf("%s %v\n", t, rec.Message)
+	fmt.Printf("%s %s %v\n", t, metadata, rec.Message)
 }
 
 func (l *defaultLogger) Logf(level Level, format string, v ...interface{}) {
@@ -86,14 +97,24 @@ func (l *defaultLogger) Logf(level Level, format string, v ...interface{}) {
 		Message:   fmt.Sprintf(format, 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])
+	}
+
 	dlog.DefaultLog.Write(rec)
 
 	t := rec.Timestamp.Format("2006-01-02 15:04:05")
-	fmt.Printf("%s %v\n", t, rec.Message)
+	fmt.Printf("%s %s %v\n", t, metadata, rec.Message)
 }
 
 func (n *defaultLogger) Options() Options {
diff --git a/logger/helper.go b/logger/helper.go
index 5bc87d10..3ccd0cf0 100644
--- a/logger/helper.go
+++ b/logger/helper.go
@@ -2,64 +2,71 @@ package logger
 
 type Helper struct {
 	Logger
+	fields map[string]interface{}
 }
 
 func NewHelper(log Logger) *Helper {
-	return &Helper{log}
+	return &Helper{Logger: log}
 }
 
 func (h *Helper) Info(args ...interface{}) {
-	h.Logger.Log(InfoLevel, args...)
+	h.Logger.Fields(h.fields).Log(InfoLevel, args...)
 }
 
 func (h *Helper) Infof(template string, args ...interface{}) {
-	h.Logger.Logf(InfoLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(InfoLevel, template, args...)
 }
 
 func (h *Helper) Trace(args ...interface{}) {
-	h.Logger.Log(TraceLevel, args...)
+	h.Logger.Fields(h.fields).Log(TraceLevel, args...)
 }
 
 func (h *Helper) Tracef(template string, args ...interface{}) {
-	h.Logger.Logf(TraceLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(TraceLevel, template, args...)
 }
 
 func (h *Helper) Debug(args ...interface{}) {
-	h.Logger.Log(DebugLevel, args...)
+	h.Logger.Fields(h.fields).Log(DebugLevel, args...)
 }
 
 func (h *Helper) Debugf(template string, args ...interface{}) {
-	h.Logger.Logf(DebugLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(DebugLevel, template, args...)
 }
 
 func (h *Helper) Warn(args ...interface{}) {
-	h.Logger.Log(WarnLevel, args...)
+	h.Logger.Fields(h.fields).Log(WarnLevel, args...)
 }
 
 func (h *Helper) Warnf(template string, args ...interface{}) {
-	h.Logger.Logf(WarnLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(WarnLevel, template, args...)
 }
 
 func (h *Helper) Error(args ...interface{}) {
-	h.Logger.Log(ErrorLevel, args...)
+	h.Logger.Fields(h.fields).Log(ErrorLevel, args...)
 }
 
 func (h *Helper) Errorf(template string, args ...interface{}) {
-	h.Logger.Logf(ErrorLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(ErrorLevel, template, args...)
 }
 
 func (h *Helper) Fatal(args ...interface{}) {
-	h.Logger.Log(ErrorLevel, args...)
+	h.Logger.Fields(h.fields).Log(ErrorLevel, args...)
 }
 
 func (h *Helper) Fatalf(template string, args ...interface{}) {
-	h.Logger.Logf(ErrorLevel, template, args...)
+	h.Logger.Fields(h.fields).Logf(ErrorLevel, template, args...)
 }
 
 func (h *Helper) WithError(err error) *Helper {
-	return &Helper{h.Logger.Fields(map[string]interface{}{"error": err})}
+	fields := copyFields(h.fields)
+	fields["error"] = err
+	return &Helper{Logger: h.Logger, fields: fields}
 }
 
 func (h *Helper) WithFields(fields map[string]interface{}) *Helper {
-	return &Helper{h.Logger.Fields(copyFields(fields))}
+	nfields := copyFields(fields)
+	for k, v := range h.fields {
+		nfields[k] = v
+	}
+	return &Helper{Logger: h.Logger, fields: nfields}
 }
diff --git a/logger/logger_test.go b/logger/logger_test.go
index 95d9c388..70d559bb 100644
--- a/logger/logger_test.go
+++ b/logger/logger_test.go
@@ -4,6 +4,12 @@ import "testing"
 
 func TestLogger(t *testing.T) {
 	l := NewLogger(WithLevel(TraceLevel))
-	h := NewHelper(l)
-	h.Trace("trace level")
+	h1 := NewHelper(l).WithFields(map[string]interface{}{"key1": "val1"})
+	h1.Trace("trace_msg1")
+	h1.Warn("warn_msg1")
+
+	h2 := NewHelper(l).WithFields(map[string]interface{}{"key2": "val2"})
+	h2.Trace("trace_msg2")
+	h2.Warn("warn_msg2")
+
 }