如何在Go的测试中检查日志/输出?

huangapple go评论83阅读模式
英文:

How to check a log/output in go test?

问题

我有一个在某些情况下记录错误的函数:

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

现在,在测试文件中,我想检查这个函数的输出错误:

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

我该如何访问日志?我尝试使用缓冲区,但没有成功。在不更改readByte函数代码的情况下,有什么正确的方法可以捕获这个日志?

英文:

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?

答案1

得分: 56

例如,

readbyte_test.go

package main

import (
	"bytes"
	"fmt"
	"io"
	"log"
	"os"
	"testing"
)

func readByte( /*...*/ ) {
	// ...
	err := io.EOF // 强制出错
	if err != nil {
		fmt.Println("ERROR")
		log.Print("无法读取第一个字节")
		return
	}
	// ...
}

func TestReadByte(t *testing.T) {
	var buf bytes.Buffer
	log.SetOutput(&buf)
	defer func() {
		log.SetOutput(os.Stderr)
	}()
	readByte()
	t.Log(buf.String())
}

输出:

$ go test -v readbyte_test.go 
=== RUN   TestReadByte
ERROR
--- PASS: TestReadByte (0.00s)
	readbyte_test.go:30: 2017/05/22 16:41:00 无法读取第一个字节
PASS
ok  	command-line-arguments	0.004s
$
英文:

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
$ 

答案2

得分: 9

并发测试的答案

如果你的测试是并发运行的(例如,测试一个httpServerClient),你可能会遇到在写入缓冲区和从缓冲区读取之间的竞争条件。我们可以将输出重定向到一个os.Pipe,并使用bufio.Scanner来阻塞,直到输出被写入,使用Scan()方法。

下面是一个创建os.Pipe并设置stdlib log包使用该管道的示例。注意我在这里使用了testify/assert包

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
}

返回*os.File对象,以便可以使用延迟函数正确关闭它们。在这里,我只是打印到stdout,因为如果在关闭时出现一些奇怪的错误,我个人不想使测试失败。然而,如果你愿意,这可以很容易地改为另一个对t.Errorf的调用或类似的调用:

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)
}

然后在你的测试中,你会有这个模式:

scanner, reader, writer := mockLogger(t) // 调试或开发时关闭此功能,否则会错过输出!
defer resetLogger(reader, writer)

// 其他设置,根据需要获取一些thing的值

go concurrentAction()

scanner.Scan() // 阻塞,直到有新的一行被写入到管道中

got := scanner.Text() // 最后一行写入到scanner的内容
msg := fmt.Sprintf("your log message with thing %v you care about", thing)
assert.Contains(t, got, msg)

最后,concurrentAction()函数调用一个log函数(或者如果使用log.logger的话,使用一个方法,无论哪种方式,该包在上面的log.SetOutput()调用中的行为都是相同的),例如:

// 做一些事情,获取thing的值
log.Printf("your log message with the thing %v you care about", thing)
英文:

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)

huangapple
  • 本文由 发表于 2017年5月23日 02:40:48
  • 转载请务必保留本文链接:https://go.coder-hub.com/44119951.html
匿名

发表评论

匿名网友

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定