Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix timer failure #27006

Merged
merged 10 commits into from
Jul 22, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 13 additions & 6 deletions heartbeat/scheduler/timerqueue/queue.go
Original file line number Diff line number Diff line change
Expand Up @@ -88,7 +88,7 @@ func (tq *TimerQueue) Start() {
if tq.th.Len() > 0 {
nr := tq.th[0].runAt
tq.nextRunAt = &nr
tq.timer.Reset(nr.Sub(time.Now()))
tq.timer = time.NewTimer(time.Until(nr))
} else {
tq.timer.Stop()
tq.nextRunAt = nil
Expand All @@ -104,14 +104,21 @@ func (tq *TimerQueue) pushInternal(tt *timerTask) {
heap.Push(&tq.th, tt)

if tq.nextRunAt == nil || tq.nextRunAt.After(tt.runAt) {
// Stop and drain the timer prior to reset per https://golang.org/pkg/time/#Timer.Reset
// Only drain if nextRunAt is set, otherwise the timer channel has already been stopped the
// channel is empty (and thus would block)
if tq.nextRunAt != nil && !tq.timer.Stop() {
<-tq.timer.C
}
tq.timer.Reset(tt.runAt.Sub(time.Now()))

// Originally the line below this comment was
//
// tq.timer.Reset(time.Until(tt.runAt))
//
// however this broke in go1.16rc1, specifically on the commit b4b014465216790e01aa66f9120d03230e4aff46
//, specifically on this line:
// https://github.com/golang/go/commit/b4b014465216790e01aa66f9120d03230e4aff46#diff-73699b6edfe5dbb3f6824e66bb3566bce9405e9a8c810cac55c8199459f0ac19R652
// where some nice new optimizations don't actually work reliably
// This can be worked around by instantiating a new timer rather than resetting the timer.
// since that internally calls deltimer in runtime/timer.go rather than modtimer,
// I suspect that the problem is in modtimer's setting of &pp.timerModifiedEarliest
tq.timer = time.NewTimer(time.Until(tt.runAt))
tq.nextRunAt = &tt.runAt
}
}
Expand Down
33 changes: 28 additions & 5 deletions heartbeat/scheduler/timerqueue/queue_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,18 +20,41 @@ package timerqueue
import (
"context"
"math/rand"
"os"
"runtime/pprof"
"sort"
"testing"
"time"

"github.com/stretchr/testify/require"
)

func TestQueueRunsInOrder(t *testing.T) {
t.Skip("flaky test on windows: https://github.com/elastic/beats/issues/26205")
// Bugs can show up only occasionally
for i := 0; i < 100; i++ {
testQueueRunsInOrderOnce(t)
func TestRunsInOrder(t *testing.T) {
testQueueRunsInOrderOnce(t)
}

// TestStress tries to figure out if we have any deadlocks that show up under concurrency
func TestStress(t *testing.T) {
for i := 0; i < 120000; i++ {
failed := make(chan bool)
succeeded := make(chan bool)

watchdog := time.AfterFunc(time.Second*5, func() {
failed <- true
})

go func() {
testQueueRunsInOrderOnce(t)
succeeded <- true
}()

select {
case <-failed:
pprof.Lookup("goroutine").WriteTo(os.Stdout, 1)
require.FailNow(t, "Scheduler test iteration timed out, deadlock issue?")
case <-succeeded:
watchdog.Stop()
}
}
}

Expand Down