How to check a log/output in go test?

Question

I have this function that logs the error in some cases:

func readByte(/*...*/){     // ...     if err != nil {         fmt.Println("ERROR")         log.Print("Couldn't read first byte")         return     }     // ... } 

Now, in the test file, I want to check the output error from this function:

    c.Assert(OUTPUT, check.Matches, "teste") 

How can I access the log? I tried to put a buffer but it didn't work. What is the right way to catch this log without change my readByte function code?

Answer 1

For example,

readbyte_test.go:

package main  import (     "bytes"     "fmt"     "io"     "log"     "os"     "testing" )  func readByte( /*...*/ ) {     // ...     err := io.EOF // force an error     if err != nil {         fmt.Println("ERROR")         log.Print("Couldn't read first byte")         return     }     // ... }  func TestReadByte(t *testing.T) {     var buf bytes.Buffer     log.SetOutput(&buf)     defer func() {         log.SetOutput(os.Stderr)     }()     readByte()     t.Log(buf.String()) } 

Output:

$ go test -v readbyte_test.go  === RUN   TestReadByte ERROR --- PASS: TestReadByte (0.00s)     readbyte_test.go:30: 2017/05/22 16:41:00 Couldn't read first byte PASS ok      command-line-arguments  0.004s $  

Answer 2

Answer for Concurrent Tests

If your test is running concurrently (for example, when testing an http Server or Client), you may encounter a race between writing to the buffer and reading from it. Instead of the buffer, we can redirect output to an os.Pipe and use a bufio.Scanner to block until output has been written by using the Scan() method.

Here is an example of creating an os.Pipe and setting the stdlib log package to use the pipe. Note my use of the testify/assert package here:

func mockLogger(t *testing.T) (*bufio.Scanner, *os.File, *os.File) {     reader, writer, err := os.Pipe()     if err != nil {         assert.Fail(t, "couldn't get os Pipe: %v", err)     }     log.SetOutput(writer)      return bufio.NewScanner(reader), reader, writer } 

The *os.File objects are returned so they can be properly closed with a deferred function. Here I'm just printing to stdout since if there was some strange error on close I personally wouldn't want to fail the test. However, this could easily be another call to t.Errorf or similar if you wanted:

func resetLogger(reader *os.File, writer *os.File) {     err := reader.Close()     if err != nil {         fmt.Println("error closing reader was ", err)     }     if err = writer.Close(); err != nil {         fmt.Println("error closing writer was ", err)     }     log.SetOutput(os.Stderr) } 

And then in your test you would have this pattern:

scanner, reader, writer := mockLogger(t) // turn this off when debugging or developing as you will miss output! defer resetLogger(reader, writer)  // other setup as needed, getting some value for thing below  go concurrentAction()   scanner.Scan() // blocks until a new line is written to the pipe   got := scanner.Text() // the last line written to the scanner msg := fmt.Sprintf("your log message with thing %v you care about", thing)  assert.Contains(t, got, msg)  

And finally, the concurrentAction() function is calling a log function (or method if using a log.logger, the package actually behaves the same way with log.SetOutput() call above either way) like:

// doing something, getting value for thing  log.Printf("your log message with the thing %v you care about", thing)