t.Cleanup()で並列に動かすことのできるテーブルドリブンテストを書く

最近は副業でGoを書いています。

最近よくテーブルドリブンテストを書いています。 テストの数が多くなってくるとテストを動かすだけでも長い時間がかかるので、t.Parallel()を使い、(DB等の同時にアクセスすると不整合が起きたりする場合などを除いては)できるだけ並列にテストを動かしています。

テーブルドリブンテストを並列で行うということについては、テストを変更してエラーが起きた際にテストコード起因なのか、それとも並列に動かしていることによって起因したものなのかがわかりづらいという論点があると思いますが、そこは考えずに今回は進めて行きます。

A, Bという2つのテスト用関数がある時、A, Bを並列にテストするというのはあると思いますが、この中でテーブルドリブンテストを動かす際には、テーブルの情報によって作られたサブテストも並列に動かしたくなると思います。

つまりはテーブルをfor文で回して1回ずつテストするのではなく、あらかじめテーブルの情報からサブテストを作成しておき、並列でサブテストを全て回すということです。

func TestFunctionA(t *testing.T){
    t.Parallel() // TestFunctionA を並列に動かす

    type testCase struct {
        name string
        title string
        expectStatusCode int
    }
    
    testCases := map[string]*testCase{
        "Yurine-sanはアクセス可能": &testCase {
            name: "Yurine",
            title: "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusOK,
        },
        "Medusa-sanはアクセス可能": &testCase {
            name: "Medusa",
            title: "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusOK,
        },
        "zyashin-changはアクセスできない": &testCase {
            name: "Zyashin",
            title: "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusBadRequest,
        },
    }
    
    for testName, tc := range testCases {
        tc := tc
        t.Run(testName, func(t *testing.T){
            t.Parallel()
            t.Log(tc)
        })
    } 
}

func TestFunctionB(t *testing.T){
    t.Parallel() // TestFunctionB を並列に動かす

    type testCase struct {
        name string
        title string
        expectStatusCode int
    }
    
    testCases := map[string]*testCase{
        "Rin-sanはアクセス可能": &testCase {
            name: "Rin",
            title: "Yurucamp",
            expectStatusCode: http.StatusOK,
        },
        "Ena-sanはアクセス可能": &testCase {
            name: "Ena",
            title: "Yurucamp",
            expectStatusCode: http.StatusOK,
        },
        "Nadeshiko-changはアクセスできない": &testCase {
            name: "Nadeshiko",
            title: "Yurucamp",
            expectStatusCode: http.StatusBadRequest,
        },
    }
    
    for testName, tc := range testCases {
        tc := tc
        t.Run(testName, func(t *testing.T){
            t.Parallel()
            t.Log(tc)
        })
    }  
}

このコードについては、特に何も意識せずに動くはずです。

実際に動くコード

動くとこうなるはずですね

=== RUN   TestFunctionA
=== PAUSE TestFunctionA
=== RUN   TestFunctionB
=== PAUSE TestFunctionB
=== CONT  TestFunctionA
=== RUN   TestFunctionA/zyashin-changはアクセスできない
=== PAUSE TestFunctionA/zyashin-changはアクセスできない
=== RUN   TestFunctionA/Yurine-sanはアクセス可能
=== PAUSE TestFunctionA/Yurine-sanはアクセス可能
=== RUN   TestFunctionA/Medusa-sanはアクセス可能
=== PAUSE TestFunctionA/Medusa-sanはアクセス可能
=== CONT  TestFunctionB
=== RUN   TestFunctionB/Rin-sanはアクセス可能
=== PAUSE TestFunctionB/Rin-sanはアクセス可能
=== RUN   TestFunctionB/Ena-sanはアクセス可能
=== PAUSE TestFunctionB/Ena-sanはアクセス可能
=== RUN   TestFunctionB/Nadeshiko-changはアクセスできない
=== PAUSE TestFunctionB/Nadeshiko-changはアクセスできない
=== CONT  TestFunctionB/Rin-sanはアクセス可能
    TestFunctionB/Rin-sanはアクセス可能: prog.go:75: &{Rin Yurucamp 200}
=== CONT  TestFunctionB/Nadeshiko-changはアクセスできない
    TestFunctionB/Nadeshiko-changはアクセスできない: prog.go:75: &{Nadeshiko Yurucamp 400}
=== CONT  TestFunctionA/Medusa-sanはアクセス可能
    TestFunctionA/Medusa-sanはアクセス可能: prog.go:39: &{Medusa DROPKICK ON MY DEVIL 200}
=== CONT  TestFunctionA/Yurine-sanはアクセス可能
    TestFunctionA/Yurine-sanはアクセス可能: prog.go:39: &{Yurine DROPKICK ON MY DEVIL 200}
=== CONT  TestFunctionB/Ena-sanはアクセス可能
    TestFunctionB/Ena-sanはアクセス可能: prog.go:75: &{Ena Yurucamp 200}
--- PASS: TestFunctionB (0.00s)
    --- PASS: TestFunctionB/Rin-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionB/Nadeshiko-changはアクセスできない (0.00s)
    --- PASS: TestFunctionB/Ena-sanはアクセス可能 (0.00s)
=== CONT  TestFunctionA/zyashin-changはアクセスできない
    TestFunctionA/zyashin-changはアクセスできない: prog.go:39: &{zyashin DROPKICK ON MY DEVIL 400}
--- PASS: TestFunctionA (0.00s)
    --- PASS: TestFunctionA/Medusa-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/Yurine-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/zyashin-changはアクセスできない (0.00s)
PASS

HTTPハンドラのテスト

カンが良い方ならテストケース等から「これはHTTPハンドラ周りのテストだな？」ということが解ると思いますが、実際にこのようなテストを書いてテストを書くとなると、どのような関数になるでしょうか？

特に考えずに書くとするなら、以下のような手順になりそうです。

• テストをするハンドラを書く
• テストの中でリクエストを待つようなサーバーを起動して待ち受ける
• for文の中で起動しておいたサーバーに向かってリクエストを投げつける
• responseに入っているステータスコードやBodyを使ってassertする

それでは実際に書いていきましょう。なお、今回の論点はサーバー周りの実装に対するものではないため、ある程度簡易的な実装までとします。

テストをするハンドラを書く

別ファイルでもいいですが、今回は実装を簡単にするためにとても簡素なものにします。

type Anime struct {
    Title string `json:"title"`
    Name string `json:"name"`
}

func getTestHandler() http.HandlerFunc {
    return func(w http.ResponseWriter, req *http.Request) {
        if req.Method != http.MethodPost {
            w.WriteHeader(http.StatusNotImplemented)
            return
        }

        b, err := ioutil.ReadAll(req.Body)
        if err != nil {
            w.WriteHeader(http.StatusInternalServerError)
            return
        }

        var anime Anime
        err = json.Unmarshal(b, &anime)
        if err != nil {
            w.WriteHeader(http.StatusInternalServerError)
            return
        }

        if anime.Title == "DROPKICK ON MY DEVIL" {
            if anime.Name == "Zyashin" {
                w.WriteHeader(http.StatusUnauthorized)
            } else {
                w.WriteHeader(http.StatusOK)
                w.Write([]byte(fmt.Sprintf("Hello %v San!", anime.Name)))
            }
        } else {
            w.WriteHeader(http.StatusBadRequest)
        }
        return
    }
}

getTestHandler() を呼べばハンドラが返ってきます。これをテストごとに動かせば良いはずです。いい感じに動かすとすればこうなるでしょう。

func TestFunctionA(t *testing.T) {
    t.Parallel() // TestFunctionA を並列に動かす

    type testCase struct {
        name             string
        title            string
        expectStatusCode int
    }

    testCases := map[string]*testCase{
        "Yurine-sanはアクセス可能": &testCase{
            name:             "Yurine",
            title:            "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusOK,
        },
        "Medusa-sanはアクセス可能": &testCase{
            name:             "Medusa",
            title:            "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusOK,
        },
        "zyashin-changはアクセスできない": &testCase{
            name:             "Zyashin",
            title:            "DROPKICK ON MY DEVIL",
            expectStatusCode: http.StatusUnauthorized,
        },
    }

    ts := httptest.NewServer(getTestHandler())
    defer ts.Close()

    for testName, tc := range testCases {
        tc := tc
        t.Run(testName, func(t *testing.T) {
            t.Parallel()

            var u bytes.Buffer
            u.WriteString(string(ts.URL))

            anime := &Anime{Title: tc.title, Name: tc.name}
            b, err := json.Marshal(anime)
            if err != nil {
                t.Fatalf("request json create failed: %v", err)
            }

            client := http.DefaultClient
            defer client.CloseIdleConnections()

            req, err := http.NewRequest(http.MethodPost, u.String(), bytes.NewBuffer(b))
            if err != nil {
                t.Fatalf("error occured at create new request : %v", err)
            }

            res, err := client.Do(req)
            if err != nil {
                t.Fatalf("test api request error: %v", err)
            }

            defer res.Body.Close()

            body, err := ioutil.ReadAll(res.Body)
            if err != nil {
                t.Fatalf("response read failed: %v", err)
            }

            if tc.expectStatusCode != res.StatusCode {
                t.Fatalf("unexpected response status code: want %v, but got %v, response body: %v", tc.expectStatusCode, res.StatusCode, string(body))
            }

            var resdata Anime
            err = json.NewDecoder(res.Body).Decode(&resdata)
            if reflect.DeepEqual(anime, &resdata) {
                t.Fatalf("unexpected server response want: %v but got %v, response body: %v", anime, &resdata, string(body))
            }
        })
    }
}

https://play.golang.org/p/ZWGY5JsTjvL

しかし、これで動かすと上手く動きません。

=== RUN   TestFunctionA
=== PAUSE TestFunctionA
=== CONT  TestFunctionA
=== RUN   TestFunctionA/Medusa-sanはアクセス可能
=== PAUSE TestFunctionA/Medusa-sanはアクセス可能
=== RUN   TestFunctionA/zyashin-changはアクセスできない
=== PAUSE TestFunctionA/zyashin-changはアクセスできない
=== RUN   TestFunctionA/Yurine-sanはアクセス可能
=== PAUSE TestFunctionA/Yurine-sanはアクセス可能
=== CONT  TestFunctionA/Medusa-sanはアクセス可能
=== CONT  TestFunctionA/Yurine-sanはアクセス可能
=== CONT  TestFunctionA/zyashin-changはアクセスできない
    prog.go:108: test api request error: Post "http://127.0.0.1:30426": dial tcp 127.0.0.1:30426: connect: connection refused
=== CONT  TestFunctionA/Yurine-sanはアクセス可能
    prog.go:108: test api request error: Post "http://127.0.0.1:30426": dial tcp 127.0.0.1:30426: connect: connection refused
=== CONT  TestFunctionA/Medusa-sanはアクセス可能
    prog.go:108: test api request error: Post "http://127.0.0.1:30426": dial tcp 127.0.0.1:30426: connect: connection refused
--- FAIL: TestFunctionA (0.00s)
    --- FAIL: TestFunctionA/zyashin-changはアクセスできない (0.00s)
    --- FAIL: TestFunctionA/Yurine-sanはアクセス可能 (0.00s)
    --- FAIL: TestFunctionA/Medusa-sanはアクセス可能 (0.00s)
FAIL

全部 connection refused エラーになります。つまりクエストが上手く出来ていません。

一度並列に動かすのをやめてみましょう。

テーブルからサブテストを生成する

   for testName, tc := range testCases {
        //tc := tc
        t.Run(testName, func(t *testing.T) {
            //t.Parallel()

この部分をコメントアウトします。

=== RUN   TestFunctionA
=== PAUSE TestFunctionA
=== CONT  TestFunctionA
=== RUN   TestFunctionA/Yurine-sanはアクセス可能
=== RUN   TestFunctionA/Medusa-sanはアクセス可能
=== RUN   TestFunctionA/zyashin-changはアクセスできない
--- PASS: TestFunctionA (0.00s)
    --- PASS: TestFunctionA/Yurine-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/Medusa-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/zyashin-changはアクセスできない (0.00s)
PASS
ok      command-line-arguments  0.004s

コメントアウトする、つまり並列にテストをしなくなるといい感じに動いているようです。

並列にしたいけれど、並列にすると何故か connection refused になるという状況です。

connection refusedの原因として、一番に考えられるのはサーバーが立ち上がっていないという状況です。どうやら

 ts := httptest.NewServer(getTestHandler())
    defer ts.Close()

このあたりで起動したサーバーが死んでいるようです。 どうもdeferあたりが怪しいですね。

どうもサブテストが回る前にdeferが実行され、サーバーが落ちている可能性があります。

というわけで簡単なテストのためのテストを書きました。

package main

import (
    "log"
    "testing"
)

func TestDefer(t *testing.T) {
    tcs := map[string]string{
        "a": "あ",
        "b": "い",
        "c": "う",
    }

    defer log.Printf("えお")

    for tn, tc := range tcs {
        tc := tc
        t.Run(tn, func(t *testing.T) {
            t.Parallel()
            log.Println(tc)
        })
    }
}

https://play.golang.org/p/VY0h5gl86zX

ここで問題、上のようなparallelな環境下で、deferはどのタイミングで呼ばれるでしょうか？

普通に考えれば出力としては

あ
い
う
えお

となりそうです。これは defer が最後の最後に実行されるということからも自然であると言えます。

しかし、実際の出力はこうでした

=== RUN   TestDefer
=== RUN   TestDefer/a
=== PAUSE TestDefer/a
=== RUN   TestDefer/b
=== PAUSE TestDefer/b
=== RUN   TestDefer/c
=== PAUSE TestDefer/c
2009/11/10 23:00:00 えお
=== CONT  TestDefer/a
2009/11/10 23:00:00 あ
=== CONT  TestDefer/b
2009/11/10 23:00:00 い
=== CONT  TestDefer/c
2009/11/10 23:00:00 う
--- PASS: TestDefer (0.00s)
    --- PASS: TestDefer/a (0.00s)
    --- PASS: TestDefer/b (0.00s)
    --- PASS: TestDefer/c (0.00s)

？？？？？？？？？？？？？？？？？？

どうもdeferがサブテストに入る前に実行されているらしい。調べていると、同じようなことが issueに上がっているのが確認できました。

https://github.com/golang/go/issues/17791

作成者は同様なテストを書いていて、deferが先に呼ばれている問題に遭遇していた模様。 その中でなされていた会話の一部で

t.Parallel is making the t.Run itself a parallel subtest of TestBug. There is no parallel subtest of the t.Run subtest. TestBug will not complete until the parallel test completes. But TestBug's body has to finish because that is what triggers running the parallel tests in the first place.

とある。サブテストが起動する前にdeferが呼ばれるのはどうも仕様らしい。

deferも上手く使えないみたいだし、どうしようと思っていたら大学の先輩が書いた記事がヒットした。どうやら t.Cleanup() を使うことで解消することができるようです。

https://syfm.hatenablog.com/entry/2020/05/17/161842

https://godoc.org/testing#T.Cleanup

Cleanup registers a function to be called when the test and all its subtests complete. Cleanup functions will be called in last added, first called order.

t.Cleanup() はサブテストが終わってからLIFOで呼び出されるらしい。この周りはdeferと同じ挙動をしているようです。

書き換えてみました。

https://play.golang.org/p/e_K7M5VqJJI

package main

import (
    "log"
    "testing"
)

func TestDefer(t *testing.T) {
    tcs := map[string]string{
        "a": "あ",
        "b": "い",
        "c": "う",
    }

    t.Cleanup(func() {
        log.Printf("えお")
    })

    for tn, tc := range tcs {
        tc := tc
        t.Run(tn, func(t *testing.T) {
            t.Parallel()
            log.Println(tc)
        })
    }
}

=== RUN   TestDefer
=== RUN   TestDefer/a
=== PAUSE TestDefer/a
=== RUN   TestDefer/b
=== PAUSE TestDefer/b
=== RUN   TestDefer/c
=== PAUSE TestDefer/c
=== CONT  TestDefer/a
=== CONT  TestDefer/b
=== CONT  TestDefer/c
2009/11/10 23:00:00 あ
2009/11/10 23:00:00 い
2009/11/10 23:00:00 う
2009/11/10 23:00:00 えお
--- PASS: TestDefer (0.00s)
    --- PASS: TestDefer/a (0.00s)
    --- PASS: TestDefer/b (0.00s)
    --- PASS: TestDefer/c (0.00s)
PASS

確かにdeferのときとは違い、サブテストが終了してから えお が出力されており、期待していた挙動をしています。

これを元に、上のe2eテストっぽいものを書き換えてみましょう。

https://play.golang.org/p/-buH40moEg4

=== RUN   TestFunctionA
=== PAUSE TestFunctionA
=== CONT  TestFunctionA
=== RUN   TestFunctionA/Yurine-sanはアクセス可能
=== PAUSE TestFunctionA/Yurine-sanはアクセス可能
=== RUN   TestFunctionA/Medusa-sanはアクセス可能
=== PAUSE TestFunctionA/Medusa-sanはアクセス可能
=== RUN   TestFunctionA/zyashin-changはアクセスできない
=== PAUSE TestFunctionA/zyashin-changはアクセスできない
=== CONT  TestFunctionA/Yurine-sanはアクセス可能
=== CONT  TestFunctionA/zyashin-changはアクセスできない
=== CONT  TestFunctionA/Medusa-sanはアクセス可能
--- PASS: TestFunctionA (0.00s)
    --- PASS: TestFunctionA/Yurine-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/Medusa-sanはアクセス可能 (0.00s)
    --- PASS: TestFunctionA/zyashin-changはアクセスできない (0.00s)
PASS

t.Cleanup()は1.14から入った機能で、割りと新しめのものとなっているがかゆいところに手が届く感じでとてもいいと思いました。