fix #12: unquote eventually quoted keys generated by yaml.Marshall()

* finalized tests, made .With() work to create sub-loggers

Makefile

@@ -6,10 +6,12 @@
 #
 # no need to modify anything below
 
+VERSION   = $(shell grep VERSION handler.go | head -1 | cut -d '"' -f2)
+
 all: buildlocal
 
 buildlocal:
-	go build
+	go build  -o example/example example/example.go
 
 clean:
 	rm -rf $(tool) coverage.out testdata t/out example/example
@@ -30,3 +32,8 @@ goupdate:
 
 lint:
 	golangci-lint run -p bugs -p unused
+
+release: buildlocal test
+	gh release create v$(VERSION) --generate-notes
+
+

README.md

@@ -2,6 +2,7 @@
 [![Actions](https://github.com/tlinden/yadu/actions/workflows/ci.yaml/badge.svg)](https://github.com/tlinden/yadu/actions)
 [![Go Coverage](https://github.com/tlinden/yadu/wiki/coverage.svg)](https://raw.githack.com/wiki/tlinden/yadu/coverage.html)
 ![GitHub License](https://img.shields.io/github/license/tlinden/yadu)
+[![GoDoc](https://godoc.org/github.com/tlinden/yadu?status.svg)](https://godoc.org/github.com/tlinden/yadu)
 
 # yadu - a human readable yaml based slog.Handler
 
@@ -27,6 +28,8 @@ The log format generated by yadu looks like this:
 ```go
 logger := slog.New(yadu.NewHandler(os.Stdout, nil))
 
+type body string
+
 type Ammo struct {
         Forweapon string
         Impact    int
@@ -118,15 +121,12 @@ handler][humane]. Also helpfull was the  [guide to writing `slog` handlers][guid
 
 + [humane slog handler][humane]
 + [A Guide to Writing `slog` Handlers][guide]
-+ [`slog`: Golang's official structured logging package][sobyte]
 + [A Comprehensive Guide to Structured Logging in Go][betterstack]
 
 [humane]: https://github.com/telemachus/humane/tree/main
 [guide]: https://github.com/golang/example/tree/master/slog-handler-guide
-[mrkaran]: https://mrkaran.dev/posts/structured-logging-in-go-with-slog/
 [betterstack]: https://betterstack.com/community/guides/logging/logging-in-go/
 
-
 ## LICENSE
 
 This  module  is  published  under  the  terms  of  the  BSD  3-Clause

example/example.go

@@ -16,6 +16,12 @@ type Ammo struct {
 	Range     int
 }
 
+func (a *Ammo) LogValue() slog.Value {
+	return slog.GroupValue(
+		slog.String("Forweapon", a.Forweapon),
+	)
+}
+
 type Enemy struct {
 	Alive  bool
 	Health int
@@ -24,6 +30,12 @@ type Enemy struct {
 	Ammo   []Ammo
 }
 
+func (e *Enemy) LogValue() slog.Value {
+	return slog.GroupValue(
+		slog.String("name", e.Name),
+	)
+}
+
 func removeTime(_ []string, a slog.Attr) slog.Attr {
 	if a.Key == slog.TimeKey {
 		return slog.Attr{}
@@ -35,6 +47,7 @@ func main() {
 	opts := &yadu.Options{
 		Level:       slog.LevelDebug,
 		ReplaceAttr: removeTime,
+		AddSource:   true,
 	}
 
 	logger := slog.New(yadu.NewHandler(os.Stdout, opts))
@@ -46,6 +59,7 @@ func main() {
 	}
 
 	slog.Info("info", "enemy", e, "spawn", 199)
+	slog.Info("info", "ammo", &Ammo{Forweapon: "axe", Impact: 1})
 	slog.Info("connecting", "enemies", 100, "players", 2, "world", "600x800")
 	slog.Debug("debug text")
 	slog.Error("error")

handler.go

@@ -3,9 +3,11 @@ package yadu
 import (
 	"bytes"
 	"context"
+	"fmt"
 	"io"
 	"log/slog"
 	"regexp"
+	"runtime"
 	"slices"
 	"strings"
 	"sync"
@@ -15,22 +17,56 @@ import (
 	"github.com/fatih/color"
 )
 
+const VERSION = "0.1.3"
+
 // We use RFC datestring by default
 const DefaultTimeFormat = "2006-01-02T03:04.05 MST"
 
 // Default log level is INFO:
 const defaultLevel = slog.LevelInfo
 
+// holds attributes added with logger.With()
+type attributes map[string]interface{}
+
 type Handler struct {
 	writer      io.Writer
 	mu          *sync.Mutex
 	level       slog.Leveler
 	groups      []string
-	attrs       string
+	attrs       attributes
 	timeFormat  string
 	replaceAttr func(groups []string, a slog.Attr) slog.Attr
 	addSource   bool
 	indenter    *regexp.Regexp
+
+	/*
+		This is being used in Postprocess() to fix
+		https://github.com/go-yaml/yaml/issues/1020 and
+		https://github.com/TLINDEN/yadu/issues/12 respectively.
+
+		yaml.v3 follows the YAML standard and quotes all keys and values
+		matching this regex (see https://yaml.org/type/bool.html):
+		`y|Y|yes|Yes|YES|n|N|no|No|NO|true|True|TRUE|false|False|FALSE|on|On|ON|off|Off|OFF`
+
+		The problem is,  that the YAML "standard" does  not state wether
+		this  applies  to  values  or   keys  or  values&keys  and  most
+		implementors, as gopkg.in/yaml.v3, do it just for keys and values.
+
+		Therefore if  we dump a struct  containing a key "Y"  it ends up
+		being quoted, while any other  keys remain unquoted, which looks
+		pretty ugly, makes evaluating  the output harder,  especially in
+		game development where you have to dump coordinates, points etc,
+		all containing X,Y with X unquoted and Y quoted.
+
+		To fix  this utter nonsence,  I just  replace all quotes  in all
+		keys. Period. This is just a logging module, nobody will and can
+		use its output to postprocess  it with some yaml parser, because
+		we not only dump the structs as  yaml, we also write a one liner
+		in front of it with the  timestamp and the message. So, we don't
+		output  valid  YAML  anyway  and  we don't  give  a  shit  about
+		compliance because of this. AND because this rule is bullshit.
+	*/
+	yamlcleaner *regexp.Regexp
 }
 
 // Options are options for the Yadu [log/slog.Handler].
@@ -49,6 +85,7 @@ type Options struct {
 	ReplaceAttr func(groups []string, a slog.Attr) slog.Attr
 	TimeFormat  string
 	AddSource   bool
+	NoColor     bool
 }
 
 func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
@@ -67,11 +104,28 @@ func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
 
 	fields := make(map[string]interface{}, r.NumAttrs())
 	r.Attrs(func(a slog.Attr) bool {
-		fields[a.Key] = a.Value.Any()
+		//fields[a.Key] = a.Value.Any()
+		a.Value = a.Value.Resolve()
+		wa := make(map[string]interface{})
+		h.appendAttr(wa, a)
+		fields[a.Key] = wa[a.Key]
 		return true
 	})
 
-	tree := h.attrs
+	tree := ""
+	source := ""
+
+	if h.addSource && r.PC != 0 {
+		source = h.getSource(r.PC)
+	}
+
+	if len(h.attrs) > 0 {
+		bytetree, err := yaml.Marshal(h.attrs)
+		if err != nil {
+			return err
+		}
+		tree = h.Postprocess(bytetree)
+	}
 
 	if len(fields) > 0 {
 		bytetree, err := yaml.Marshal(&fields)
@@ -79,7 +133,7 @@ func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
 			return err
 		}
 
-		tree = h.Postprocess(bytetree)
+		tree += h.Postprocess(bytetree)
 	}
 
 	timeStr := ""
@@ -105,6 +159,8 @@ func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
 	buf.WriteString(" ")
 	buf.WriteString(msg)
 	buf.WriteString(" ")
+	buf.WriteString(source)
+	buf.WriteString(" ")
 	buf.WriteString(color.WhiteString(tree))
 	buf.WriteString("\n")
 
@@ -115,8 +171,17 @@ func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
 	return err
 }
 
+// report caller source+line as yaml string
+func (h *Handler) getSource(pc uintptr) string {
+	fs := runtime.CallersFrames([]uintptr{pc})
+	source, _ := fs.Next()
+	return fmt.Sprintf("%s: %d", source.File, source.Line)
+}
+
 func (h *Handler) Postprocess(yamlstr []byte) string {
-	return "\n    " + strings.TrimSpace(h.indenter.ReplaceAllString(string(yamlstr), "    "))
+	tree := string(yamlstr)
+	clean := h.yamlcleaner.ReplaceAllString(tree, "$1$2:")
+	return "\n    " + strings.TrimSpace(h.indenter.ReplaceAllString(clean, "    "))
 }
 
 // NewHandler returns a [log/slog.Handler] using the receiver's options.
@@ -134,6 +199,7 @@ func NewHandler(out io.Writer, opts *Options) *Handler {
 		replaceAttr: opts.ReplaceAttr,
 		addSource:   opts.AddSource,
 		indenter:    regexp.MustCompile(`(?m)^`),
+		yamlcleaner: regexp.MustCompile("(?m)^( *)\"([^\"]*)\":"),
 	}
 
 	if opts.Level == nil {
@@ -144,6 +210,10 @@ func NewHandler(out io.Writer, opts *Options) *Handler {
 		h.timeFormat = DefaultTimeFormat
 	}
 
+	if opts.NoColor {
+		color.NoColor = true
+	}
+
 	return h
 }
 
@@ -153,24 +223,59 @@ func (h *Handler) Enabled(_ context.Context, l slog.Level) bool {
 }
 
 // attributes plus attrs.
+func (h *Handler) appendAttr(wa map[string]interface{}, a slog.Attr) {
+	a.Value = a.Value.Resolve()
+
+	if a.Value.Kind() == slog.KindGroup {
+		attrs := a.Value.Group()
+		name := ""
+		if len(attrs) == 0 {
+			return
+		}
+
+		if a.Key != "" {
+			name = a.Key
+			h.groups = append(h.groups, a.Key)
+		}
+
+		innerwa := make(map[string]interface{})
+		for _, a := range attrs {
+			h.appendAttr(innerwa, a)
+		}
+		wa[name] = innerwa
+
+		if a.Key != "" && len(h.groups) > 0 {
+			h.groups = h.groups[:len(h.groups)-1]
+		}
+
+		return
+	}
+
+	if h.replaceAttr != nil {
+		a = h.replaceAttr(h.groups, a)
+	}
+
+	if !a.Equal(slog.Attr{}) {
+		wa[a.Key] = a.Value.Any()
+	}
+}
+
+// sub logger is to be created, possibly with attrs, add them to h.attrs
 func (h *Handler) WithAttrs(attrs []slog.Attr) slog.Handler {
 	if len(attrs) == 0 {
 		return h
 	}
 
-	fields := make(map[string]interface{}, len(attrs))
-	for _, a := range attrs {
-		fields[a.Key] = a.Value.Any()
-	}
-
-	bytetree, err := yaml.Marshal(&fields)
-	if err != nil {
-		panic(err)
-	}
-
 	h2 := h.clone()
 
-	h2.attrs += string(bytetree)
+	wa := make(map[string]interface{})
+
+	for _, a := range attrs {
+		h2.appendAttr(wa, a)
+	}
+
+	h2.attrs = wa
+
 	return h2
 }
 
@@ -195,5 +300,7 @@ func (h *Handler) clone() *Handler {
 		timeFormat:  h.timeFormat,
 		replaceAttr: h.replaceAttr,
 		addSource:   h.addSource,
+		indenter:    h.indenter,
+		yamlcleaner: h.yamlcleaner,
 	}
 }

handler_test.go

@@ -7,6 +7,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/fatih/color"
 	"github.com/tlinden/yadu"
 )
 
@@ -19,6 +20,12 @@ type Ammo struct {
 	Range     float32
 }
 
+func (a *Ammo) LogValue() slog.Value {
+	return slog.GroupValue(
+		slog.String("Forweapon", "Use weapon: "+a.Forweapon),
+	)
+}
+
 type Enemy struct {
 	Alive  bool
 	Health int
@@ -27,11 +34,17 @@ type Enemy struct {
 	Ammo   []Ammo
 }
 
+type Point struct {
+	y, Y, yes, n, N, no, True, False, on, off int
+}
+
 type Tests struct {
-	name   string
+	name    string
-	want   string
+	want    string
-	negate bool
+	negate  bool
-	opts   *yadu.Options
+	opts    yadu.Options
+	with    slog.Attr
+	haswith bool
 }
 
 const testTimeFormat = "03:04.05"
@@ -47,6 +60,16 @@ var tests = []Tests{
 		want:   "ammo:",
 		negate: false,
 	},
+	{
+		name:   "has-ammo-logvaluer",
+		want:   "Use weapon: Axe",
+		negate: false,
+	},
+	{
+		name:   "has-ammo-logvaluer-does-resolve",
+		want:   "impact: 50", // should NOT appear
+		negate: true,
+	},
 	{
 		name:   "has-alive",
 		want:   "alive: true",
@@ -65,7 +88,7 @@ var tests = []Tests{
 	{
 		name: "has-no-time",
 		want: time.Now().Format(yadu.DefaultTimeFormat),
-		opts: &yadu.Options{
+		opts: yadu.Options{
 			ReplaceAttr: removeTime,
 		},
 		negate: true,
@@ -73,21 +96,83 @@ var tests = []Tests{
 	{
 		name: "has-custom-time",
 		want: time.Now().Format(testTimeFormat),
-		opts: &yadu.Options{
+		opts: yadu.Options{
 			TimeFormat: testTimeFormat,
 		},
 		negate: false,
 	},
-	// FIXME: add WithGroup + WithAttr tests
+	{
+		name:   "with-group",
+		want:   "pid:",
+		negate: false,
+		with: slog.Group("program_info",
+			slog.Int("pid", 1923),
+			slog.Bool("alive", true),
+		),
+		haswith: true,
+	},
+	{
+		name:   "has-debug",
+		want:   "DEBUG",
+		negate: false,
+		opts: yadu.Options{
+			Level: slog.LevelDebug,
+		},
+	},
+	{
+		name:   "has-warn",
+		want:   "WARN",
+		negate: false,
+		opts: yadu.Options{
+			Level: slog.LevelWarn,
+		},
+	},
+	{
+		name:   "has-error",
+		want:   "ERROR",
+		negate: false,
+		opts: yadu.Options{
+			Level: slog.LevelError,
+		},
+	},
+	{
+		name:   "has-source",
+		want:   "handler_test.go",
+		negate: false,
+		opts: yadu.Options{
+			AddSource: true,
+		},
+	},
+	{
+		// check if output is NOT colored when disabling it
+		name:   "disable-color",
+		want:   "\x1b[0m",
+		negate: true,
+		opts: yadu.Options{
+			NoColor: true,
+		},
+	},
+	{
+		// check if output is colored
+		name:   "enable-color",
+		want:   "\x1b[0m",
+		negate: false,
+	},
 }
 
 func GetEnemy() *Enemy {
 	return &Enemy{Alive: true, Health: 10, Name: "Bodo", Body: "body\nbody\n",
 		Ammo: []Ammo{{Forweapon: "Railgun", Range: 400, Impact: 100, Cost: 100000}},
 	}
-
 }
 
+func GetAmmo() *Ammo {
+	return &Ammo{Forweapon: "Axe", Range: 50, Impact: 1, Cost: 50}
+}
+
+func GetPoint() *Point {
+	return &Point{}
+}
 func removeTime(_ []string, a slog.Attr) slog.Attr {
 	if a.Key == slog.TimeKey {
 		return slog.Attr{}
@@ -95,15 +180,35 @@ func removeTime(_ []string, a slog.Attr) slog.Attr {
 	return a
 }
 
-func Test(t *testing.T) {
+func TestLogger(t *testing.T) {
 	t.Parallel()
 
 	for _, tt := range tests {
 		var buf bytes.Buffer
 
-		logger := slog.New(yadu.NewHandler(&buf, tt.opts))
+		logger := slog.New(yadu.NewHandler(&buf, &tt.opts))
+
+		if !tt.with.Equal(slog.Attr{}) {
+			logger = logger.With(tt.with)
+		}
+
+		if !tt.opts.NoColor {
+			color.NoColor = false
+		}
+
+		slog.SetDefault(logger)
+
+		switch tt.opts.Level {
+		case slog.LevelDebug:
+			logger.Debug("attack", "enemy", GetEnemy(), "ammo", GetAmmo())
+		case slog.LevelWarn:
+			logger.Warn("attack", "enemy", GetEnemy(), "ammo", GetAmmo())
+		case slog.LevelError:
+			logger.Error("attack", "enemy", GetEnemy(), "ammo", GetAmmo())
+		default:
+			logger.Info("attack", "enemy", GetEnemy(), "ammo", GetAmmo())
+		}
 
-		logger.Info("attack", "enemy", GetEnemy())
 		got := buf.String()
 
 		if strings.Contains(got, tt.want) == tt.negate {
@@ -113,3 +218,22 @@ func Test(t *testing.T) {
 		buf.Reset()
 	}
 }
+
+func TestYamlCleaner(t *testing.T) {
+	t.Parallel()
+
+	var buf bytes.Buffer
+	logger := slog.New(yadu.NewHandler(&buf, &yadu.Options{}))
+	slog.SetDefault(logger)
+
+	logger.Info("got a point", "point", GetPoint())
+
+	got := buf.String()
+
+	bools := []string{"y:", "n:", "true:", "false:"}
+	for _, want := range bools {
+		if !strings.Contains(got, want) {
+			t.Errorf("test TestYamlCleaner failed.\n want: %s:\n got: %s\n", want, got)
+		}
+	}
+}