Take the console location from the record (closes #36)
ConsoleHandler found the file and line it prints by walking a fixed number of stack frames up from itself, which only fit a record logged through a slog.Logger and delivered through MultiplexHandler. It now reads them from the record's PC, the call site slog stores, so a ConsoleHandler used with slog.New and a record passed to Handle directly print the right location too. A record whose PC is zero prints ???:0 as before. The README drops its warning about the wrong location and says how to set PC instead. Model: opus-5-5
This commit is contained in:
@@ -126,8 +126,9 @@ error away. That is how `log/slog` works, and simplelog cannot change it.
|
|||||||
To find out whether a record was delivered, build a `slog.Record` and pass
|
To find out whether a record was delivered, build a `slog.Record` and pass
|
||||||
it to the handler yourself, for example
|
it to the handler yourself, for example
|
||||||
`slog.Default().Handler().Handle(ctx, record)`, then check the error it
|
`slog.Default().Handler().Handle(ctx, record)`, then check the error it
|
||||||
returns. A record passed to `Handle` directly gets the wrong file and
|
returns. Console output takes the file and line from the record's `PC`,
|
||||||
line in console output.
|
which you set with `runtime.Callers` as the `log/slog` documentation
|
||||||
|
shows. A record whose `PC` is zero prints `???:0` instead.
|
||||||
|
|
||||||
## Entrypoints
|
## Entrypoints
|
||||||
|
|
||||||
|
|||||||
@@ -24,6 +24,10 @@ files it depends on: .golangci.yml, REPO_POLICIES.md, .editorconfig,
|
|||||||
|
|
||||||
# Completed Steps
|
# Completed Steps
|
||||||
|
|
||||||
|
* 2026-10-06: the console handler takes the file and line it prints from
|
||||||
|
the record's `PC` instead of counting stack frames, so they name the
|
||||||
|
call site whether the record came through a `slog.Logger` or straight
|
||||||
|
to `Handle`
|
||||||
* 2026-10-06: the tests run under the race detector, in Docker:
|
* 2026-10-06: the tests run under the race detector, in Docker:
|
||||||
`script/test` builds the `test` stage of the `Dockerfile`, which runs
|
`script/test` builds the `test` stage of the `Dockerfile`, which runs
|
||||||
`go test -race`, and a new final stage makes a plain `docker build`
|
`go test -race`, and a new final stage makes a plain `docker build`
|
||||||
|
|||||||
+7
-9
@@ -12,10 +12,6 @@ import (
|
|||||||
"github.com/fatih/color"
|
"github.com/fatih/color"
|
||||||
)
|
)
|
||||||
|
|
||||||
// callerSkipFrames is the number of stack frames between runtime.Caller
|
|
||||||
// and the slog call site that produced the record.
|
|
||||||
const callerSkipFrames = 4
|
|
||||||
|
|
||||||
// ConsoleHandler writes human-readable, colored log lines to stdout.
|
// ConsoleHandler writes human-readable, colored log lines to stdout.
|
||||||
type ConsoleHandler struct {
|
type ConsoleHandler struct {
|
||||||
// out is where records are written. Nil means os.Stdout, looked up on
|
// out is where records are written. Nil means os.Stdout, looked up on
|
||||||
@@ -53,11 +49,13 @@ func (c *ConsoleHandler) Handle(
|
|||||||
colorFunc = color.New(color.FgWhite).SprintfFunc()
|
colorFunc = color.New(color.FgWhite).SprintfFunc()
|
||||||
}
|
}
|
||||||
|
|
||||||
// Get the caller information
|
// The file and line come from the record's PC, the call site; a record
|
||||||
_, file, line, ok := runtime.Caller(callerSkipFrames)
|
// without one prints a placeholder.
|
||||||
if !ok {
|
file, line := "???", 0
|
||||||
file = "???"
|
|
||||||
line = 0
|
if record.PC != 0 {
|
||||||
|
frame, _ := runtime.CallersFrames([]uintptr{record.PC}).Next()
|
||||||
|
file, line = frame.File, frame.Line
|
||||||
}
|
}
|
||||||
|
|
||||||
out := c.out
|
out := c.out
|
||||||
|
|||||||
@@ -0,0 +1,102 @@
|
|||||||
|
package simplelog
|
||||||
|
|
||||||
|
import (
|
||||||
|
"bytes"
|
||||||
|
"context"
|
||||||
|
"fmt"
|
||||||
|
"log/slog"
|
||||||
|
"runtime"
|
||||||
|
"strings"
|
||||||
|
"testing"
|
||||||
|
"time"
|
||||||
|
)
|
||||||
|
|
||||||
|
// These tests sit inside the package so they can read the console line
|
||||||
|
// from a buffer instead of from stdout.
|
||||||
|
|
||||||
|
// lineOf calls logCall and returns "file:line" for the line lineOf was
|
||||||
|
// called from. Each test writes its log call inside logCall on that same
|
||||||
|
// line, so the result is the location the console line must name.
|
||||||
|
func lineOf(logCall func()) string {
|
||||||
|
_, file, line, _ := runtime.Caller(1)
|
||||||
|
|
||||||
|
logCall()
|
||||||
|
|
||||||
|
return fmt.Sprintf("%s:%d", file, line)
|
||||||
|
}
|
||||||
|
|
||||||
|
// wantLocation fails the test unless the console line names location as
|
||||||
|
// where the record "casting" was logged.
|
||||||
|
func wantLocation(t *testing.T, output, location string) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
if !strings.Contains(output, location+": casting") {
|
||||||
|
t.Fatalf("console line %q does not name %s", output, location)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// The default handler as simplelog installs it when stdout is a terminal:
|
||||||
|
// a MultiplexHandler holding a ConsoleHandler.
|
||||||
|
func TestConsoleHandlerNamesCallSiteThroughDefaultHandler(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var output bytes.Buffer
|
||||||
|
|
||||||
|
logger := slog.New(&MultiplexHandler{handlers: []ExtendedHandler{
|
||||||
|
&ConsoleHandler{out: &output},
|
||||||
|
}})
|
||||||
|
|
||||||
|
want := lineOf(func() { logger.Info("casting") })
|
||||||
|
|
||||||
|
wantLocation(t, output.String(), want)
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestConsoleHandlerNamesCallSiteUsedWithSlogNew(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var output bytes.Buffer
|
||||||
|
|
||||||
|
logger := slog.New(&ConsoleHandler{out: &output})
|
||||||
|
|
||||||
|
want := lineOf(func() { logger.Info("casting") })
|
||||||
|
|
||||||
|
wantLocation(t, output.String(), want)
|
||||||
|
}
|
||||||
|
|
||||||
|
// The record is built as the log/slog package documentation shows for a
|
||||||
|
// function that logs on its caller's behalf: runtime.Callers supplies the
|
||||||
|
// PC.
|
||||||
|
func TestConsoleHandlerNamesCallSiteOfRecordPassedToHandle(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var (
|
||||||
|
output bytes.Buffer
|
||||||
|
pcs [1]uintptr
|
||||||
|
)
|
||||||
|
|
||||||
|
want := lineOf(func() { runtime.Callers(1, pcs[:]) })
|
||||||
|
|
||||||
|
record := slog.NewRecord(time.Now(), slog.LevelInfo, "casting", pcs[0])
|
||||||
|
|
||||||
|
err := (&ConsoleHandler{out: &output}).Handle(context.Background(), record)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("Handle: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
wantLocation(t, output.String(), want)
|
||||||
|
}
|
||||||
|
|
||||||
|
func TestConsoleHandlerPrintsPlaceholderWithoutPC(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var output bytes.Buffer
|
||||||
|
|
||||||
|
record := slog.NewRecord(time.Now(), slog.LevelInfo, "casting", 0)
|
||||||
|
|
||||||
|
err := (&ConsoleHandler{out: &output}).Handle(context.Background(), record)
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("Handle: %v", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
wantLocation(t, output.String(), "???:0")
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user