Skip to content

zaptest logger outputs logs with incorrect source file and line #1493

Open
@nathanperkins

Description

@nathanperkins

Describe the bug

When using zaptest.NewLogger(t), log lines incorrectly attribute their source to logger.go:146: rather than the actual line where the logger was called.

To Reproduce

Create `main_test.go

package main

import (
	"testing"

	"go.uber.org/zap/zaptest"
)

func TestLogger(t *testing.T) {
	logger := zaptest.NewLogger(t)
	logger.Info("Hello")
}

Run and observe output with incorrect source file and line attribution to logger.go:146:

$ go test . -test.v
=== RUN   TestLogger
    logger.go:146: 2025-03-20T14:15:44.658-0700 INFO    Hello
--- PASS: TestLogger (0.00s)
PASS
ok      <package_name> 0.012s

Expected behavior

Log output should have correct source file and line attribution. Something like this:

$ go test . -test.v
=== RUN   TestLogger
    main_test.go:11: 2025-03-20T14:15:44.658-0700 INFO    Hello
--- PASS: TestLogger (0.00s)
PASS
ok      <package_name> 0.012s

Additional context

The incorrect source attribution is pointing to the w.t.Logf(...) line here:

zap/zaptest/logger.go

Lines 139 to 152 in fcf8ee5

func (w TestingWriter) Write(p []byte) (n int, err error) {
n = len(p)
// Strip trailing newline because t.Log always adds one.
p = bytes.TrimRight(p, "\n")
// Note: t.Log is safe for concurrent use.
w.t.Logf("%s", p)
if w.markFailed {
w.t.Fail()
}
return n, nil
}

I tried adding w.t.Helper() to this function, but it pushed it up into the zapcore code, where there is no t available to push it further.

$ go test . -test.v
=== RUN   TestLogger
    core.go:99: 2025-03-20T14:27:46.011-0700    INFO    Hello
--- PASS: TestLogger (0.00s)
PASS
ok      <package_name> 0.018s

It's possible that making a zaptest specific core could allow us to mark w.t.Helper() further up the chain and get the attribution to the correct level.

If it's infeasible to fix this because of how t.Logf works, we should at least document the behavior as a known issue. I couldn't find any documentation that this is expected behavior.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions