xtaci / smux

A Stream Multiplexing Library for golang with least memory usage(TDMA)
MIT License
1.31k stars 196 forks source link

TestGetDieCh() strange behaviour seems cause by racing #88

Open cs8425 opened 2 years ago

cs8425 commented 2 years ago

run test with: go test -coverprofile=coverage.txt -covermode=atomic -v -run=TestGetDieCh .

in session_test.go:

func TestGetDieCh(t *testing.T) {
    cs, ss, err := getSmuxStreamPair()
    if err != nil {
        t.Fatal(err)
    }
    defer ss.Close()
    dieCh := ss.GetDieCh()
    go func() {
        t.Log("start")
        select {
        case <-dieCh:
        case <-time.Tick(time.Second):
            t.Fatal("wait die chan timeout")
        }
        t.Log("end")
    }()
    cs.Close()
    t.Log("wait")
}

will got:

=== RUN   TestGetDieCh
    session_test.go:298: start
    session_test.go:307: wait
--- PASS: TestGetDieCh (0.00s)
PASS
coverage: 32.5% of statements
ok      github.com/xtaci/smux   0.004s  coverage: 32.5% of statements

and

=== RUN   TestGetDieCh
    session_test.go:307: wait
--- PASS: TestGetDieCh (0.00s)
PASS
panic: Log in goroutine after TestGetDieCh has completed: end

goroutine 27 [running]:
testing.(*common).logDepth(0xc000121380, {0xc00021c030, 0x4}, 0x3)
    /usr/local/go/src/testing/testing.go:779 +0x4c9
testing.(*common).log(...)
    /usr/local/go/src/testing/testing.go:761
testing.(*common).Log(0xc000215fb0, {0xc000215fa0, 0x0, 0x0})
    /usr/local/go/src/testing/testing.go:800 +0x45
github.com/xtaci/smux.TestGetDieCh.func1()
    /path-to-code/smux/session_test.go:304 +0x11f
created by github.com/xtaci/smux.TestGetDieCh
    /path-to-code/smux/session_test.go:297 +0x112
FAIL    github.com/xtaci/smux   0.006s
FAIL

if we change to this, be sure that test exit after goroutine:

func TestGetDieCh(t *testing.T) {
    cs, ss, err := getSmuxStreamPair()
    if err != nil {
        t.Fatal(err)
    }
    defer ss.Close()
    dieCh := ss.GetDieCh()

    var wg sync.WaitGroup
    wg.Add(1)
    go func() {
        defer wg.Done()

        t.Log("start")
        select {
        case <-dieCh:
            t.Log("end")
        case <-time.Tick(time.Second):
            t.Fatal("wait die chan timeout")
        }
    }()
    cs.Close()

    t.Log("wait...")
    wg.Wait()
}

the test will fail with:

=== RUN   TestGetDieCh
    session_test.go:313: wait...
    session_test.go:303: start
    session_test.go:308: wait die chan timeout
--- FAIL: TestGetDieCh (1.00s)
FAIL
coverage: 32.5% of statements
FAIL    github.com/xtaci/smux   1.005s
FAIL