英文:
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
并发测试的答案
如果你的测试是并发运行的(例如,测试一个http
的Server
或Client
),你可能会遇到在写入缓冲区和从缓冲区读取之间的竞争条件。我们可以将输出重定向到一个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)
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库,让每个人都能够通过互相帮助和分享经验来进步。
评论