From 924a38ee88f7d816d6e430e2d75b5601bed60e5a Mon Sep 17 00:00:00 2001 From: Anmol Sethi Date: Mon, 24 Jan 2022 14:47:13 -0800 Subject: [PATCH 1/4] Update go.mod --- go.mod | 1 + go.sum | 2 ++ 2 files changed, 3 insertions(+) diff --git a/go.mod b/go.mod index a2bccae..3c20162 100644 --- a/go.mod +++ b/go.mod @@ -6,6 +6,7 @@ require ( cloud.google.com/go v0.99.0 github.com/alecthomas/chroma v0.9.4 github.com/fatih/color v1.13.0 + github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da // indirect github.com/google/go-cmp v0.5.6 go.opencensus.io v0.23.0 golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9 diff --git a/go.sum b/go.sum index 63dfe9d..b7cc46c 100644 --- a/go.sum +++ b/go.sum @@ -85,6 +85,8 @@ github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4er github.com/golang/groupcache v0.0.0-20191227052852-215e87163ea7/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e h1:1r7pUrabqp18hOBcwBwiTsbnFeTZHV9eER/QT5JVZxY= github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= +github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da h1:oI5xCqsCo564l8iNU+DwB5epxmsaqB+rhGL0m5jtYqE= +github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/mock v1.1.1/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A= github.com/golang/mock v1.2.0/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A= github.com/golang/mock v1.3.1/go.mod h1:sBzyDLLjw3U8JLTeZvSv8jJB+tU5PVekmnlKIyFUx0Y= From 2f71a40d9a90628be637114da1241a0fb9ee7076 Mon Sep 17 00:00:00 2001 From: Anmol Sethi Date: Mon, 24 Jan 2022 14:47:25 -0800 Subject: [PATCH 2/4] Reset color before each line Some tools like modd (https://github.com/cortesi/modd) will try to color noncolored text but we don't want them to and so we reset at the beginning of each line to make sure they aren't playing with our output. --- internal/entryhuman/entry.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index d17f80a..8bfe3dc 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -50,7 +50,7 @@ func c(w io.Writer, attrs ...color.Attribute) *color.Color { // for extra lines in a log so if we did it here, the fields would be indented // twice in test logs. So the Stderr logger indents all the fields itself. func Fmt(w io.Writer, ent slog.SinkEntry) string { - var ents string + ents := c(w, color.Reset).Sprint("") ts := ent.Time.Format(TimeFormat) ents += ts + " " @@ -127,7 +127,7 @@ func Fmt(w io.Writer, ent slog.SinkEntry) string { lines := strings.Split(multilineVal, "\n") for i, line := range lines[1:] { if line != "" { - lines[i+1] = strings.Repeat(" ", len(multilineKey)+4) + line + lines[i+1] = c(w, color.Reset).Sprint("") + strings.Repeat(" ", len(multilineKey)+4) + line } } multilineVal = strings.Join(lines, "\n") From 69ae538e8bd9f250c76703e2b67a53c91affc93d Mon Sep 17 00:00:00 2001 From: Anmol Sethi Date: Mon, 24 Jan 2022 17:57:13 -0800 Subject: [PATCH 3/4] entryhuman: Log the caller's relative module path and function Instead of just their file's basename. --- internal/entryhuman/entry.go | 65 +++++++++++++++++++++++++++++++++++- 1 file changed, 64 insertions(+), 1 deletion(-) diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index 8bfe3dc..f1b1f78 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -9,6 +9,7 @@ import ( "io" "os" "path/filepath" + "runtime/debug" "strconv" "strings" "time" @@ -64,7 +65,8 @@ func Fmt(w io.Writer, ent slog.SinkEntry) string { ents += fmt.Sprintf("%v\t", loggerName) } - loc := fmt.Sprintf("<%v:%v>", filepath.Base(ent.File), ent.Line) + hpath, hfn := humanPathAndFunc(ent.File, ent.Func) + loc := fmt.Sprintf("<%v:%v> %v", hpath, ent.Line, hfn) loc = c(w, color.FgCyan).Sprint(loc) ents += fmt.Sprintf("%v\t", loc) @@ -194,3 +196,64 @@ func quoteKey(key string) string { // Replace spaces in the map keys with underscores. return strings.ReplaceAll(key, " ", "_") } + +var mainPackagePath string +var mainModulePath string + +func init() { + // Unfortunately does not work for tests yet :( + // See https://github.com/golang/go/issues/33976 + bi, ok := debug.ReadBuildInfo() + if !ok { + return + } + mainPackagePath = bi.Path + mainModulePath = bi.Main.Path +} + +// humanPathAndFunc takes the absolute path to a file and an absolute module path to a +// function in that file and returns the module path to the file. It also returns +// the path to the function stripped of its module prefix. +// +// If the file is in the main Go module then its path is returned +// relative to the main Go module's root. +// +// fn is from https://pkg.go.dev/runtime#Func.Name +func humanPathAndFunc(filename, fn string) (hpath, hfn string) { + // pkgDir is the dir of the pkg. + // e.g. cdr.dev/slog/internal + // base is the package name and the function name separated by a period. + // e.g. entryhuman.humanPathAndFunc + // There can be multiple periods when methods of types are involved. + pkgDir, base := filepath.Split(fn) + s := strings.Split(base, ".") + pkg := s[0] + hfn = strings.Join(s[1:], ".") + + if pkg == "main" { + // This happens with go build main.go + if mainPackagePath == "command-line-arguments" { + // Without a real mainPath, we can't find the path to the file + // relative to the module. So we just return the base. + return filepath.Base(filename), hfn + } + // Go doesn't return the full main path in runtime.Func.Name() + // It just returns the path "main" + // Only runtime.ReadBuildInfo returns it so we have to check and replace. + pkgDir = mainPackagePath + // pkg main isn't reflected on the disk so we should not add it + // into the pkgpath. + pkg = "" + } + + hpath = filepath.Join(pkgDir, pkg, filepath.Base(filename)) + + if mainModulePath != "" { + relhpath, err := filepath.Rel(mainModulePath, hpath) + if err == nil { + hpath = "./" + relhpath + } + } + + return hpath, hfn +} From d1ee8506d5e3d0281399c8d1e512676fc9d19a3f Mon Sep 17 00:00:00 2001 From: Anmol Sethi Date: Mon, 24 Jan 2022 18:09:28 -0800 Subject: [PATCH 4/4] Fix tests --- go.sum | 1 - internal/entryhuman/entry.go | 2 +- internal/entryhuman/entry_test.go | 14 +++++++------- s_test.go | 2 +- sloggers/sloghuman/sloghuman_test.go | 2 +- 5 files changed, 10 insertions(+), 11 deletions(-) diff --git a/go.sum b/go.sum index b7cc46c..890bb51 100644 --- a/go.sum +++ b/go.sum @@ -83,7 +83,6 @@ github.com/go-gl/glfw/v3.3/glfw v0.0.0-20200222043503-6f7a984d4dc4/go.mod h1:tQ2 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/groupcache v0.0.0-20191227052852-215e87163ea7/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= -github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e h1:1r7pUrabqp18hOBcwBwiTsbnFeTZHV9eER/QT5JVZxY= github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da h1:oI5xCqsCo564l8iNU+DwB5epxmsaqB+rhGL0m5jtYqE= github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index f1b1f78..4e741c9 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -66,7 +66,7 @@ func Fmt(w io.Writer, ent slog.SinkEntry) string { } hpath, hfn := humanPathAndFunc(ent.File, ent.Func) - loc := fmt.Sprintf("<%v:%v> %v", hpath, ent.Line, hfn) + loc := fmt.Sprintf("<%v:%v>\t%v", hpath, ent.Line, hfn) loc = c(w, color.FgCyan).Sprint(loc) ents += fmt.Sprintf("%v\t", loc) diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 8530bd7..f7fc596 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -32,8 +32,8 @@ func TestEntry(t *testing.T) { File: "myfile", Line: 100, - Func: "ignored", - }, `2000-02-05 04:04:04.000 [DEBUG] "wowowow\tizi"`) + Func: "mypkg.ignored", + }, `2000-02-05 04:04:04.000 [DEBUG] ignored "wowowow\tizi"`) }) t.Run("multilineMessage", func(t *testing.T) { @@ -42,7 +42,7 @@ func TestEntry(t *testing.T) { test(t, slog.SinkEntry{ Message: "line1\nline2", Level: slog.LevelInfo, - }, `0001-01-01 00:00:00.000 [INFO] <.:0> ... + }, `0001-01-01 00:00:00.000 [INFO] <.:0> ... "msg": line1 line2`) }) @@ -54,7 +54,7 @@ func TestEntry(t *testing.T) { Message: "msg", Level: slog.LevelInfo, Fields: slog.M(slog.F("field", "line1\nline2")), - }, `0001-01-01 00:00:00.000 [INFO] <.:0> msg ... + }, `0001-01-01 00:00:00.000 [INFO] <.:0> msg ... "field": line1 line2`) }) @@ -65,7 +65,7 @@ func TestEntry(t *testing.T) { test(t, slog.SinkEntry{ Level: slog.LevelWarn, LoggerNames: []string{"named", "meow"}, - }, `0001-01-01 00:00:00.000 [WARN] (named.meow) <.:0> ""`) + }, `0001-01-01 00:00:00.000 [WARN] (named.meow) <.:0> ""`) }) t.Run("trace", func(t *testing.T) { @@ -77,7 +77,7 @@ func TestEntry(t *testing.T) { SpanID: trace.SpanID{0, 1, 2, 3, 4, 5, 6, 7}, TraceID: trace.TraceID{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15}, }, - }, `0001-01-01 00:00:00.000 [ERROR] <.:0> "" {"trace": "000102030405060708090a0b0c0d0e0f", "span": "0001020304050607"}`) + }, `0001-01-01 00:00:00.000 [ERROR] <.:0> "" {"trace": "000102030405060708090a0b0c0d0e0f", "span": "0001020304050607"}`) }) t.Run("color", func(t *testing.T) { @@ -89,6 +89,6 @@ func TestEntry(t *testing.T) { slog.F("hey", "hi"), ), }) - assert.Equal(t, "entry", "0001-01-01 00:00:00.000 \x1b[91m[CRITICAL]\x1b[0m\t\x1b[36m<.:0>\x1b[0m\t\"\"\t{\x1b[34m\"hey\"\x1b[0m: \x1b[32m\"hi\"\x1b[0m}", act) + assert.Equal(t, "entry", "\x1b[0m\x1b[0m0001-01-01 00:00:00.000 \x1b[91m[CRITICAL]\x1b[0m\t\x1b[36m<.:0> \x1b[0m\t\"\"\t{\x1b[34m\"hey\"\x1b[0m: \x1b[32m\"hi\"\x1b[0m}", act) }) } diff --git a/s_test.go b/s_test.go index 7ca9fa9..4e3b9e1 100644 --- a/s_test.go +++ b/s_test.go @@ -23,5 +23,5 @@ func TestStdlib(t *testing.T) { et, rest, err := entryhuman.StripTimestamp(b.String()) assert.Success(t, "strip timestamp", err) assert.False(t, "timestamp", et.IsZero()) - assert.Equal(t, "entry", " [INFO]\t(stdlib)\t\tstdlib\t{\"hi\": \"we\"}\n", rest) + assert.Equal(t, "entry", " [INFO]\t(stdlib)\t\tTestStdlib\tstdlib\t{\"hi\": \"we\"}\n", rest) } diff --git a/sloggers/sloghuman/sloghuman_test.go b/sloggers/sloghuman/sloghuman_test.go index a315ca7..1c26631 100644 --- a/sloggers/sloghuman/sloghuman_test.go +++ b/sloggers/sloghuman/sloghuman_test.go @@ -24,5 +24,5 @@ func TestMake(t *testing.T) { et, rest, err := entryhuman.StripTimestamp(b.String()) assert.Success(t, "strip timestamp", err) assert.False(t, "timestamp", et.IsZero()) - assert.Equal(t, "entry", " [INFO]\t\t...\t{\"wowow\": \"me\\nyou\"}\n \"msg\": line1\n\n line2\n", rest) + assert.Equal(t, "entry", " [INFO]\t\tTestMake\t...\t{\"wowow\": \"me\\nyou\"}\n \"msg\": line1\n\n line2\n", rest) }