Продолжение к предыдущему посту.
Итак, разработчик из Go team написал такую реализацию:
func (c *cronImpl) Run(ctx context.Context, action func(), next func() time.Duration) {
var t *time.Timer
t = time.AfterFunc(next(), func() {
select {
case <-ctx.Done():
return
default:
action()
t.Reset(next())
}
})
<-ctx.Done()
}
func main() {
ctx, cancel := context.WithTimeout(context.Background(), time.Second*10)
defer cancel()
c := cronImpl{}
c.Run(ctx,
func() {
fmt.Println("Hello, @igoroutine")
},
func() time.Duration {
return time.Second
},
)
}
Всё ожидаемо работает:
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Hello, @igoroutine
Program exited 0.
Мы, как ответственные люди, дополнительно написали тест. Более того, включили race detector при компиляции.
go test -v -race ./...
func TestCron(t *testing.T) {
synctest.Test(t, func(t *testing.T) {
c := New()
var n atomic.Int64
next := func() time.Duration {
if n.Add(1) <= 5 {
return 0
}
return 1 * time.Second
}
var calls atomic.Int64
ctx, cancel := context.WithCancel(t.Context())
done := make(chan struct{})
go func() {
defer close(done)
c.Run(ctx, func() {
calls.Add(1)
}, next)
}()
synctest.Wait()
require.Greater(t, calls.Load(), int64(0))
cancel()
synctest.Wait()
select {
case <-done:
default:
t.Fatalf("Run did not exit after cancel")
}
})
}
=== RUN TestCron
--- PASS: TestCron (0.00s)
PASS
😎😎 Всё успешно, выкатываем приложение на production и радуемся жизни.
🫡🫡Но, внезапно, раз в неделю появляется ошибка:
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x0 pc=0x1009927fc]
Пробуем дебагать и снова запускать тесты. Для надёжности прогоняем их с count=10000:
go test -v -count=10000 ./...
PASS
ok 0.787s
Попробуем запустить с race detector'ом и count=100:
go test -v -race -count=100 ./...
PASS
ok 4.079s
😳😳 Безумие!
От безысходности запускаем тесты с race detector'ом и
count=1000000 и видим вот это:
WARNING: DATA RACE
Read at 0x00c0000024a0 by goroutine 3543:
cron.go:30 +0x90 // t.Reset(next())
Previous write at 0x00c0000024a0 by goroutine 3541:
cron.go:24 +0x194 // t = time.AfterFunc(next() ...
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x0 pc=0x1050ae7fc]
Всё дело в том, что AfterFunc внутри создаёт отдельную горутину:
func AfterFunc(d Duration, f func()) *Timer {
return newTimer(when(d), 0, goFunc, f, nil)
}
func goFunc(arg any, seq uintptr, delta int64) {
go arg.(func())()
}
При очень маленьком
d в этом коде
t = time.AfterFunc(next(), func() {
...
t.Reset(next())
})
Горутина с t.Reset может начать исполняться раньше, чем значение будет сохранено в t. Соответственно, получается nil pointer dereference. На самом деле причина может быть в аппаратной реализации, например, t может находиться в кэше ядра. И таких «аппаратных» объяснений может быть очень много в зависимости от архитектуры.
С точки зрения Go memory model это не важно.
Важно, что мы пишем (t = ...) и читаем (t.Reset) общую переменную без синхронизации. Это data race по определению.
И race detector не всегда может тривиально обнаружить такие проблемы, это напрямую следует из его устройства.
Более того, эту реализацию можно переписать более эффективно, чтобы избежать создания лишней горутины.
Это как раз одно из многочисленных заданий на курсе The Nature of Go.
👉👉 Пишите в комментариях, какие интересные баги вы находили с помощью race detector'a!