gogo-zap

Capture zap logger output when I can't alter the way logger created


I need to write unit tests for Zap logger, to check it's output. There're a plenty tutorials in the internet how to capture zap log output but they suppose that I can create logger with custom X, Y, Z... In my case I receive logger object that I can't change anything in a way it initiated, and it prints logs to stdout. How can I still check output of this logger?

Some code for reference:

I create logger by following code. Once again, it's a wrapper and I need to test its behavior, so I can't change it.

logger, err := NewCustomLogger(context.Background(), zapcore.DebugLevel, "unit tests")
if err != nil {
    assert.Fail(s.T(), "couldn't initialize logger")
    return
}

I can't change NewCustomLogger and it returns *zap.Logger, is there any workaround that I can use?

P.S. I tried to use this answer and catch stdout, but it didn't work for me:

In Go, how do I capture stdout of a function into a string?

old := os.Stdout // keep backup of the real stdout
    r, w, _ := os.Pipe()
    os.Stdout = w

    logger.Warn("This log will be intercepted")

    outC := make(chan string)
    // copy the output in a separate goroutine so printing can't block indefinitely
    go func() {
        var buf bytes.Buffer
        io.Copy(&buf, r)
        outC <- buf.String()
    }()

    // back to normal state
    w.Close()
    os.Stdout = old // restoring the real stdout
    out := <-outC

    // reading our temp stdout
    fmt.Println("previous output:")
    fmt.Print(out)

fmt.Print(out) prints empty string string.

P.P.S.

I tried this answer too and it partially worked: How to properly capture zap logger output in unit tests

logger, err := NewLogger(context.Background(), zapcore.DebugLevel, "unit tests")
    if err != nil {
        assert.Fail(s.T(), "couldn't initialize logger")
        return
    }

    observed, logs := observer.New(zapcore.InfoLevel)
    observedLogger := zap.New(zapcore.NewTee(logger.Core(), observed))

    observedLogger.Warn("This log will be intercepted by the custom core")

    entry := logs.All()[0]

    fmt.Print(entry)

But it doesn't print InitialFields: https://pkg.go.dev/go.uber.org/zap#Config.InitialFields

see foo_env field:

{"level":"warn","ts":1710415413.844058,"msg":"This log will be intercepted by the custom core","foo_env":"test_env_foo"}
{{warn 2024-03-14 13:23:33.844058 +0200 IST m=+0.003122709  This log will be intercepted by the custom core undefined } []}

UPDATE:

The logger created in this way, but as I say I can't change this implementation:

func NewLogger(level zapcore.Level, serviceName string) (*zap.Logger, error) {
    productionCfg := zap.NewProductionConfig()
    productionCfg.Level = zap.NewAtomicLevelAt(level)
    productionCfg.InitialFields = map[string]interface{}{
        "INITIAL_FIELD":"INITIAL_FIELD_VALUE",  //example, initial fields populated from env variables
    }

    logger, err := productionCfg.Build(zap.AddStacktrace(zap.ErrorLevel))
    if err != nil {
        return nil, errors.Wrap(err, "failed to build logger")
    }

    logger = logger.Named(serviceName)

    return logger, nil
}

Solution

  • You can route stderr output to a temp file and then read the content of the temp file to get the log output and match it against the expected output.

    Example:

    func TestNewLogger(t *testing.T) {
        // create a temporary file to redirect stderr
        file, err := os.CreateTemp(".", "temp")
        assert.NoError(t, err)
        defer os.Remove(file.Name())
        os.Stderr = file
    
        // init the logger as normal
        logger, err := NewLogger(zapcore.DebugLevel, "test")
        assert.NoError(t, err)
        logger.Info("test")
    
        // read the file content for testing
        logOut, err := os.ReadFile(file.Name())
        assert.NoError(t, err)
    
        assert.Regexp(t, `{"level":"info","ts":.*,"logger":"test","caller":".*","msg":"test","INITIAL_FIELD":"INITIAL_FIELD_VALUE"}`, string(logOut))
    }