log/slog: log.Fatal() reports wrong source location when both log.Lshortfile or log.Llongfile and slog with source is enabled #67362
Description
Go version
go version go1.21.5 darwin/arm64
Output of go env in your module/workspace:
GO111MODULE=''
GOARCH='arm64'
GOBIN=''
GOCACHE='/Users/andrew/Library/Caches/go-build'
GOENV='/Users/andrew/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/andrew/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='darwin'
GOPATH='/Users/andrew/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/homebrew/Cellar/go/1.21.5/libexec'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/homebrew/Cellar/go/1.21.5/libexec/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.21.5'
GCCGO='gccgo'
AR='ar'
CC='cc'
CXX='c++'
CGO_ENABLED='1'
GOMOD='/Users/andrew/src/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/8b/qq9znh551qv_r0lhlj8bs0hr0000gn/T/go-build2100671700=/tmp/go-build -gno-record-gcc-switches -fno-common'What did you do?
Our applications have log.Lshortfile set and while migrating to log/slog, we noticed that in a few spots where we call log.Fatal() that the source line information points to inside the standard library as opposed to the line where the log was called.
Other package-level functions such as log.Print() report the correct source line location.
log.Llongfile exhibits the same bug.
Playground: https://go.dev/play/p/k-eOzUuhr1f
package main
import (
"log"
"log/slog"
"os"
)
func main() {
log.SetFlags(log.Lshortfile)
slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
AddSource: true,
})))
log.Print("hello")
log.Fatal("world")
}What did you see happen?
When slog is enabled with source location, we see the following:
time=2009-11-10T23:00:00.000Z level=INFO source=/tmp/sandbox1731373776/prog.go:14 msg=hello
time=2009-11-10T23:00:00.000Z level=INFO source=/usr/local/go-faketime/src/log/log.go:412 msg=world
What did you expect to see?
When slog is disabled, we see the following:
prog.go:12: hello
prog.go:13: world
I would expect with slog enabled, we should see the following:
time=2009-11-10T23:00:00.000Z level=INFO source=/tmp/sandbox1731373776/prog.go:14 msg=hello
time=2009-11-10T23:00:00.000Z level=INFO source=/tmp/sandbox1731373776/prog.go:15 msg=world