How to properly capture zap logger output in unit tests

Based off the configurations for zap.NewDevelopmentConfig() and zap.NewProductionConfig(), I've assumed that zap writes logs to stderr. However, I can't seem to capture the output in unit tests.

I have the following captureOutput func:

func captureOutput(f func()) string {
    r, w, err := os.Pipe()
    if err != nil {
        panic(err)
    }

    stdout := os.Stdout
    os.Stdout = w
    defer func() {
        os.Stdout = stdout
    }()

    stderr := os.Stderr
    os.Stderr = w
    defer func() {
        os.Stderr = stderr
    }()

    f()
    w.Close()

    var buf bytes.Buffer
    io.Copy(&buf, r)

    return buf.String()
}

It fails to capture zap output but does manage to grab output from fmt.Println(...):

func TestZapCapture(t *testing.T) {
    auditor, _ := zap.NewProduction()
    output := captureOutput(func() {
        auditor.Info("hi")
    })

    assert.NotEmpty(t, output)
    //fails to captures output
}

func TestFmtCapture(t *testing.T) {
    output := captureOutput(func() {
        fmt.Println("hi")
    })

    assert.NotEmpty(t, output)
    //successfully captures output
}

I'm aware of using the zap observer for situations like this but my real use case is to test a highly modified zap logger so testing a new zap.Core would defeat the purpose. Whats the best way to capture that output?

Solution

Test that messages are logged at all

Use zapcore.NewTee. In your unit tests, you instantiate a logger whose core is comprised of your own highly modified core and the observed core tee'd together. The observed core will receive the log entries, so you can assert that single fields are what you expect (level, message, fields, etc.)

func main() {
    // some arbitrary custom core logger
    mycore := zapcore.NewCore(
        zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()),
        os.Stderr,
        zapcore.InfoLevel,
    )
    // test core
    observed, logs := observer.New(zapcore.InfoLevel)
    
    // new logger with the two cores tee'd together
    logger := zap.New(zapcore.NewTee(mycore, observed))

    logger.Error("foo")

    entry := logs.All()[0]
    fmt.Println(entry.Message == "foo")            // true
    fmt.Println(entry.Level == zapcore.ErrorLevel) // true
}

Test the final log format

In this case you want to pipe the logger output to arbitrary writers. You can achieve this with zap.CombineWriteSyncers and inject this as a dependency of your custom core.

// this would be placed in your main code
func NewCustomLogger(pipeTo io.Writer) zapcore.Core {
    return zapcore.NewCore(
        zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()),
        zap.CombineWriteSyncers(os.Stderr, zapcore.AddSync(pipeTo)),
        zapcore.InfoLevel,
    )
}

func TestLogger(t *testing.T) {
    b := &bytes.Buffer{}
    // call the constructor from your test code with the arbitrary writer
    mycore := NewCustomLogger(b)

    logger := zap.New(mycore)
    logger.Error("foo")

    fmt.Println(b.String()) // {"level":"error","ts":1639813360.853494,"msg":"foo"}
}