go testのtest.testlogfileフラグが時々便利
test.testlogfile
を付けてテストを実行すると、テスト中の以下が分かる。
- os.Stat()したファイル
- os.Open()したファイル
- os.Getenvした環境変数
これは、例えば、net/http.FileSystemが使われた様なテストなどで苦しめられたときに便利に働くことがある。
例
例えば、hello_test.goと以下のようなファイルがあったとして。
. ├── hello_test.go ├── testdata │ └── hello.json └── x.log 1 directory, 3 files
おもむろに以下の様な形でテストを実行してみる。
$ go test -v -test.testlogfile=x.log === RUN TestIt --- PASS: TestIt (0.01s) PASS ok github.com/podhmo/individual-sandbox/daily/20200821/example_go/04file 0.016s
このとき、-test.testlogfile
に渡したx.logを覗いてみると以下の様な行が書かれている。
# test log open testdata/hello.json open /etc/mime.types open /etc/apache2/mime.types open /etc/apache/mime.types
testdata/hello.json。。
そうそう、今回のテストではtestdataの中に書かれたhello.jsonを読み込む様なコードを書いていた。
実際のテストコード
ざっくり説明すると、以下の様な感じのテストコード。
GET /hello
にアクセスするHello()
というメソッドを持ったClient- testdataを見て、
/hello
に対してtestdata/hello.json
を見る様なHandler - net/http.HandlerからRoundTripperをTransportに指定するfake
- (実は、クライアントライブラリのテストにhttptest.Serverではなくhttptest.Recorderも使えるというコード例だったりもする)
package main import ( "bytes" "fmt" "io" "net/http" "net/http/httptest" "strings" "testing" "time" ) type Client struct { BaseURL string HTTPClient *http.Client } func (c *Client) Hello() (*http.Response, error) { hc := c.HTTPClient if hc == nil { hc = http.DefaultClient } return hc.Get(strings.TrimSuffix(c.BaseURL, "/") + "/hello") } type HandlerRoundTripper struct { Before func(*http.Request) Handler http.Handler After func(*http.Response, *http.Request) } func (t *HandlerRoundTripper) RoundTrip(r *http.Request) (*http.Response, error) { if t.Before != nil { t.Before(r) } w := httptest.NewRecorder() t.Handler.ServeHTTP(w, r) res := w.Result() if t.After != nil { t.After(res, r) } return res, nil } func TestIt(t *testing.T) { c := &Client{ HTTPClient: &http.Client{ Timeout: 100 * time.Millisecond, Transport: &HandlerRoundTripper{ Before: func(r *http.Request) { // /hello -> testdata/hello.json r.URL.Path = fmt.Sprintf("%s.json", strings.TrimSuffix(r.URL.Path, "/")) }, Handler: http.FileServer(http.Dir("testdata")), }, }, } res, err := c.Hello() if err != nil { t.Fatal(err) } defer res.Body.Close() var b bytes.Buffer io.Copy(&b, res.Body) if res.StatusCode != 200 { t.Errorf("unexpected: %s", res.Status) } if strings.TrimSpace(b.String()) != strings.TrimSpace(`{"message": "hello"}`) { t.Errorf("unmatch: %s", b.String()) } }
はい。
実際の実装
testing/testing.goを覗くと以下の様な記述がある。
testlog = flag.String("test.testlogfile", "", "write test action log to `file` (for use only by cmd/go)")
ここでtestlogというフラグをonにしている1。
これがonになると、testing.MのRun()
の中のbefore()
で、m.deps.StartTestLog(f)
が呼ばれる。
// before runs before all testing. func (m *M) before() { // ... (ちなみにここでcpuprofileやmemprofileの設定などをしていたりする) if *testlog != "" { // Note: Not using toOutputDir. // This file is for use by cmd/go, not users. var f *os.File var err error if m.numRun == 1 { f, err = os.Create(*testlog) } else { f, err = os.OpenFile(*testlog, os.O_WRONLY, 0) if err == nil { f.Seek(0, io.SeekEnd) } } if err != nil { fmt.Fprintf(os.Stderr, "testing: %s\n", err) os.Exit(2) } m.deps.StartTestLog(f) // <- これ testlogFile = f }
それでは m.deps
というものは何者かと言うと、こういうinterface。コメントに書いてある通り、go test
で生成されるコードのmainパッケージの中でimportされる。
// testDeps is an internal interface of functionality that is // passed into this package by a test's generated main package. // The canonical implementation of this interface is // testing/internal/testdeps's TestDeps. type testDeps interface { ImportPath() string MatchString(pat, str string) (bool, error) StartCPUProfile(io.Writer) error StopCPUProfile() StartTestLog(io.Writer) StopTestLog() error WriteProfileTo(string, io.Writer, int) error }
testing/internal/testdepsを覗いてみる。それっぽいhookが定義されてきつつありますね。
// testLog implements testlog.Interface, logging actions by package os. type testLog struct { mu sync.Mutex w *bufio.Writer set bool } func (l *testLog) Getenv(key string) { l.add("getenv", key) } func (l *testLog) Open(name string) { l.add("open", name) } func (l *testLog) Stat(name string) { l.add("stat", name) } func (l *testLog) Chdir(name string) { l.add("chdir", name) }
ここでおもむろにos.Stat()
あたりの実装を覗いてみましょう。
os/stat.go
import "internal/testlog" // Stat returns a FileInfo describing the named file. // If there is an error, it will be of type *PathError. func Stat(name string) (FileInfo, error) { testlog.Stat(name) return statNolog(name) }
そして internal/testlog/log.go
// logger is the current logger Interface. // We use an atomic.Value in case test startup // is racing with goroutines started during init. // That must not cause a race detector failure, // although it will still result in limited visibility // into exactly what those goroutines do. var logger atomic.Value // SetLogger sets the test logger implementation for the current process. // It must be called only once, at process startup. func SetLogger(impl Interface) { if logger.Load() != nil { panic("testlog: SetLogger must be called only once") } logger.Store(&impl) } // Stat calls Logger().Stat, if a logger has been set. func Stat(name string) { if log := Logger(); log != nil { log.Stat(name) } }
あらためて、testing/internal/testdeps/deps.goを
package testdeps import ( "bufio" "internal/testlog" "io" "regexp" "runtime/pprof" "strings" "sync" ) ... var log testLog func (TestDeps) StartTestLog(w io.Writer) { log.mu.Lock() log.w = bufio.NewWriter(w) if !log.set { // Tests that define TestMain and then run m.Run multiple times // will call StartTestLog/StopTestLog multiple times. // Checking log.set avoids calling testlog.SetLogger multiple times // (which will panic) and also avoids writing the header multiple times. log.set = true testlog.SetLogger(&log) // <- これ! log.w.WriteString("# test log\n") // known to cmd/go/internal/test/test.go } log.mu.Unlock() }
はい。つまりそういうわけでした。おしまい。
gist
-
go testの実行のされ方を追いかけてみると意外と参考になる部分があったりするのでおすすめ。injectされるコード自体は https://github.com/golang/go/blob/master/src/cmd/go/internal/load/test.go あたりにあります。injectするコードはもちろん
go test
に関連がある https://github.com/golang/go/blob/master/src/cmd/go/internal/test/test.go あたりですね。↩