Possible goroutine leak

[johejo]

Test may be flaky.

check script test.sh

#!/usr/bin/env bash

for i in $(seq 10); do
  echo "$i"
  go test ./... -race -count=1 || true
done

Result

$ ./test.sh
1
ok      github.com/Songmu/flextime      3.424s
2
ok      github.com/Songmu/flextime      3.468s
3
ok      github.com/Songmu/flextime      3.420s
4
ok      github.com/Songmu/flextime      3.422s
5
ok      github.com/Songmu/flextime      3.426s
6
ok      github.com/Songmu/flextime      3.418s
7
ok      github.com/Songmu/flextime      3.423s
8
--- FAIL: TestClock_NewTimer (0.11s)
    clock_test.go:42: channel of stopped Timer should be blocked
FAIL
FAIL    github.com/Songmu/flextime      3.456s
FAIL
9
ok      github.com/Songmu/flextime      3.462s
10
--- FAIL: TestClock_NewTimer (0.06s)
    clock_test.go:42: channel of stopped Timer should be blocked
FAIL
FAIL    github.com/Songmu/flextime      3.409s
FAIL

Often when testing 10 consecutive times without using the cache, it will fail once at least.

I suspected goroutine leak and used goleak.

diff --git a/flextime_test.go b/flextime_test.go
index 5bc4a9e..7a2fcd5 100644
--- a/flextime_test.go
+++ b/flextime_test.go
@@ -5,8 +5,14 @@ import (
        "time"

        "github.com/Songmu/flextime"
+       "go.uber.org/goleak"
 )

+func TestMain(m *testing.M) {
+       defer goleak.VerifyTestMain(m)
+       m.Run()
+}
+
 func TestRestore(t *testing.T) {
        flextime.Fix(baseDate)
        almostSameTime(t, flextime.Now(), baseDate)
diff --git a/go.mod b/go.mod
index 655e336..cc5bbf4 100644
--- a/go.mod
+++ b/go.mod
@@ -1,3 +1,5 @@
 module github.com/Songmu/flextime

 go 1.13
+
+require go.uber.org/goleak v1.1.10

Result

$ go test ./... -race -count=1
PASS
PASS
goleak: Errors on successful test run: found unexpected goroutines:
[Goroutine 27 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 27 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc0001465c0)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 200 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 200 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc00023c000)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 77 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 77 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc000430040)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 59 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 59 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc000146640)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 163 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 163 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc000430080)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 215 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 215 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc0003ac000)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 302 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 302 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc000430140)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191

 Goroutine 234 in state chan send, with github.com/Songmu/flextime.newFakeTicker.func1 on top of the stack:
goroutine 234 [chan send]:
github.com/Songmu/flextime.newFakeTicker.func1(0xc000430100)
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:37 +0xd7
created by github.com/Songmu/flextime.newFakeTicker
        /home/heijo/ghq/github.com/Songmu/flextime/faketicker.go:32 +0x191
]
FAIL    github.com/Songmu/flextime      7.357s
FAIL

Identify the suspected goroutine leaked test. goleak.sh

#!/usr/bin/env bash

go test -c -o tests

for test in $(go test -list . | grep -E "^(Test|Example)"); do 
  ./tests -test.run "^$test\$" &>/dev/null && echo "$test passed" || echo "$test failed"
done

rm tests

Result

$ ./goleak.sh
TestClock_NewTimer passed
TestFakeTicker_Reset failed
TestFakeTicker_Reset_panic passed
TestTimer_Stop passed
TestRestore passed
TestFix failed
TestSet failed
TestFix_NewTicker_withSleep failed
TestFix_fix passed
TestSet_slide passed
TestNowFunc passed
TestRealClock passed
TestClock_NewTimer failed
TestFakeTicker_Reset failed
TestFakeTicker_Reset_panic passed
TestTimer_Stop passed
TestRestore passed
TestFix failed
TestSet failed
TestFix_NewTicker_withSleep failed
TestFix_fix passed
TestSet_slide passed
TestNowFunc passed
TestRealClock passed

[Songmu]

Thanks for the report. It's difficult because it's a timing issue, but I recognize the problem. I would like to address it.