1
0
mirror of https://github.com/golang/go synced 2024-11-23 11:30:06 -07:00

context: deflake time-sensitive tests

Many of tests in this package assumed reasonable scheduling latency.
Unfortunately, scheduling latency on builders and CI systems is not
always reasonable.

Rather than expecting that a timeout is detected within a fixed short
interval, we can use (*testing.T).Deadline to portably scale the time
we're willing to wait to something appropriate to the builder.

Some of the tests also included arbitrary-duration sleeps, which are
no longer needed after CL 196521; we can remove those instead of
extending them.

Promptness of timeouts is also an important property, but testing that
property is better suited to benchmarks than to tests proper: unlike
tests, we generally expect benchmarks to be run in a quiet,
low-contention environment.

Fixes #13956

Change-Id: I0797e2267fb778c8ad94add56d797de9e2c885e5
Reviewed-on: https://go-review.googlesource.com/c/go/+/223019
Run-TryBot: Bryan C. Mills <bcmills@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
This commit is contained in:
Bryan C. Mills 2020-03-11 15:14:38 -04:00
parent b851e51160
commit e8ecda8a38

View File

@ -15,6 +15,7 @@ import (
)
type testingT interface {
Deadline() (time.Time, bool)
Error(args ...interface{})
Errorf(format string, args ...interface{})
Fail()
@ -39,6 +40,23 @@ type otherContext struct {
Context
}
const (
shortDuration = 1 * time.Millisecond // a reasonable duration to block in a test
veryLongDuration = 1000 * time.Hour // an arbitrary upper bound on the test's running time
)
// quiescent returns an arbitrary duration by which the program should have
// completed any remaining work and reached a steady (idle) state.
func quiescent(t testingT) time.Duration {
deadline, ok := t.Deadline()
if !ok {
return 5 * time.Second
}
const arbitraryCleanupMargin = 1 * time.Second
return time.Until(deadline) - arbitraryCleanupMargin
}
func XTestBackground(t testingT) {
c := Background()
if c == nil {
@ -95,9 +113,7 @@ func XTestWithCancel(t testingT) {
}
}
cancel()
time.Sleep(100 * time.Millisecond) // let cancellation propagate
cancel() // Should propagate synchronously.
for i, c := range contexts {
select {
case <-c.Done():
@ -123,7 +139,7 @@ func XTestParentFinishesChild(t testingT) {
cancelChild, stop := WithCancel(parent)
defer stop()
valueChild := WithValue(parent, "key", "value")
timerChild, stop := WithTimeout(valueChild, 10000*time.Hour)
timerChild, stop := WithTimeout(valueChild, veryLongDuration)
defer stop()
select {
@ -252,11 +268,14 @@ func XTestChildFinishesFirst(t testingT) {
}
}
func testDeadline(c Context, name string, failAfter time.Duration, t testingT) {
func testDeadline(c Context, name string, t testingT) {
t.Helper()
d := quiescent(t)
timer := time.NewTimer(d)
defer timer.Stop()
select {
case <-time.After(failAfter):
t.Fatalf("%s: context should have timed out", name)
case <-timer.C:
t.Fatalf("%s: context not timed out after %v", name, d)
case <-c.Done():
}
if e := c.Err(); e != DeadlineExceeded {
@ -265,51 +284,50 @@ func testDeadline(c Context, name string, failAfter time.Duration, t testingT) {
}
func XTestDeadline(t testingT) {
c, _ := WithDeadline(Background(), time.Now().Add(50*time.Millisecond))
c, _ := WithDeadline(Background(), time.Now().Add(shortDuration))
if got, prefix := fmt.Sprint(c), "context.Background.WithDeadline("; !strings.HasPrefix(got, prefix) {
t.Errorf("c.String() = %q want prefix %q", got, prefix)
}
testDeadline(c, "WithDeadline", time.Second, t)
testDeadline(c, "WithDeadline", t)
c, _ = WithDeadline(Background(), time.Now().Add(50*time.Millisecond))
c, _ = WithDeadline(Background(), time.Now().Add(shortDuration))
o := otherContext{c}
testDeadline(o, "WithDeadline+otherContext", time.Second, t)
testDeadline(o, "WithDeadline+otherContext", t)
c, _ = WithDeadline(Background(), time.Now().Add(50*time.Millisecond))
c, _ = WithDeadline(Background(), time.Now().Add(shortDuration))
o = otherContext{c}
c, _ = WithDeadline(o, time.Now().Add(4*time.Second))
testDeadline(c, "WithDeadline+otherContext+WithDeadline", 2*time.Second, t)
c, _ = WithDeadline(o, time.Now().Add(veryLongDuration))
testDeadline(c, "WithDeadline+otherContext+WithDeadline", t)
c, _ = WithDeadline(Background(), time.Now().Add(-time.Millisecond))
testDeadline(c, "WithDeadline+inthepast", time.Second, t)
c, _ = WithDeadline(Background(), time.Now().Add(-shortDuration))
testDeadline(c, "WithDeadline+inthepast", t)
c, _ = WithDeadline(Background(), time.Now())
testDeadline(c, "WithDeadline+now", time.Second, t)
testDeadline(c, "WithDeadline+now", t)
}
func XTestTimeout(t testingT) {
c, _ := WithTimeout(Background(), 50*time.Millisecond)
c, _ := WithTimeout(Background(), shortDuration)
if got, prefix := fmt.Sprint(c), "context.Background.WithDeadline("; !strings.HasPrefix(got, prefix) {
t.Errorf("c.String() = %q want prefix %q", got, prefix)
}
testDeadline(c, "WithTimeout", time.Second, t)
testDeadline(c, "WithTimeout", t)
c, _ = WithTimeout(Background(), 50*time.Millisecond)
c, _ = WithTimeout(Background(), shortDuration)
o := otherContext{c}
testDeadline(o, "WithTimeout+otherContext", time.Second, t)
testDeadline(o, "WithTimeout+otherContext", t)
c, _ = WithTimeout(Background(), 50*time.Millisecond)
c, _ = WithTimeout(Background(), shortDuration)
o = otherContext{c}
c, _ = WithTimeout(o, 3*time.Second)
testDeadline(c, "WithTimeout+otherContext+WithTimeout", 2*time.Second, t)
c, _ = WithTimeout(o, veryLongDuration)
testDeadline(c, "WithTimeout+otherContext+WithTimeout", t)
}
func XTestCanceledTimeout(t testingT) {
c, _ := WithTimeout(Background(), time.Second)
o := otherContext{c}
c, cancel := WithTimeout(o, 2*time.Second)
cancel()
time.Sleep(100 * time.Millisecond) // let cancellation propagate
c, cancel := WithTimeout(o, veryLongDuration)
cancel() // Should propagate synchronously.
select {
case <-c.Done():
default:
@ -467,14 +485,20 @@ func XTestSimultaneousCancels(t testingT) {
wg.Done()
}(cancel)
}
d := quiescent(t)
stuck := make(chan struct{})
timer := time.AfterFunc(d, func() { close(stuck) })
defer timer.Stop()
// Wait on all the contexts in a random order.
for ctx := range m {
select {
case <-ctx.Done():
case <-time.After(1 * time.Second):
case <-stuck:
buf := make([]byte, 10<<10)
n := runtime.Stack(buf, true)
t.Fatalf("timed out waiting for <-ctx.Done(); stacks:\n%s", buf[:n])
t.Fatalf("timed out after %v waiting for <-ctx.Done(); stacks:\n%s", d, buf[:n])
}
}
// Wait for all the cancel functions to return.
@ -485,10 +509,10 @@ func XTestSimultaneousCancels(t testingT) {
}()
select {
case <-done:
case <-time.After(1 * time.Second):
case <-stuck:
buf := make([]byte, 10<<10)
n := runtime.Stack(buf, true)
t.Fatalf("timed out waiting for cancel functions; stacks:\n%s", buf[:n])
t.Fatalf("timed out after %v waiting for cancel functions; stacks:\n%s", d, buf[:n])
}
}
@ -500,12 +524,15 @@ func XTestInterlockedCancels(t testingT) {
cancelChild()
}()
cancelParent()
d := quiescent(t)
timer := time.NewTimer(d)
defer timer.Stop()
select {
case <-child.Done():
case <-time.After(1 * time.Second):
case <-timer.C:
buf := make([]byte, 10<<10)
n := runtime.Stack(buf, true)
t.Fatalf("timed out waiting for child.Done(); stacks:\n%s", buf[:n])
t.Fatalf("timed out after %v waiting for child.Done(); stacks:\n%s", d, buf[:n])
}
}
@ -523,7 +550,6 @@ func testLayers(t testingT, seed int64, testTimeout bool) {
t.Errorf(fmt.Sprintf("seed=%d: %s", seed, format), a...)
}
const (
timeout = 200 * time.Millisecond
minLayers = 30
)
type value int
@ -545,7 +571,11 @@ func testLayers(t testingT, seed int64, testTimeout bool) {
cancels = append(cancels, cancel)
case 2:
var cancel CancelFunc
ctx, cancel = WithTimeout(ctx, timeout)
d := veryLongDuration
if testTimeout {
d = shortDuration
}
ctx, cancel = WithTimeout(ctx, d)
cancels = append(cancels, cancel)
numTimers++
}
@ -568,10 +598,13 @@ func testLayers(t testingT, seed int64, testTimeout bool) {
t.Log(ctx)
checkValues("before cancel")
if testTimeout {
d := quiescent(t)
timer := time.NewTimer(d)
defer timer.Stop()
select {
case <-ctx.Done():
case <-time.After(timeout + time.Second):
errorf("ctx should have timed out")
case <-timer.C:
errorf("ctx should have timed out after %v", d)
}
checkValues("after timeout")
} else {
@ -615,8 +648,8 @@ func XTestWithCancelCanceledParent(t testingT) {
c, _ := WithCancel(parent)
select {
case <-c.Done():
case <-time.After(5 * time.Second):
t.Fatal("timeout waiting for Done")
default:
t.Errorf("child not done immediately upon construction")
}
if got, want := c.Err(), Canceled; got != want {
t.Errorf("child not cancelled; got = %v, want = %v", got, want)
@ -687,7 +720,7 @@ func XTestCustomContextGoroutines(t testingT) {
cancel0()
checkCreatedGoroutine()
_, cancel0 = WithTimeout(&myDoneCtx{Background()}, 1*time.Hour)
_, cancel0 = WithTimeout(&myDoneCtx{Background()}, veryLongDuration)
cancel0()
checkCreatedGoroutine()
@ -707,7 +740,7 @@ func XTestCustomContextGoroutines(t testingT) {
defer cancel3b()
checkCreatedGoroutine() // ctx1 is not providing Done, must not be used
ctx4, cancel4 := WithTimeout(ctx3, 1*time.Hour)
ctx4, cancel4 := WithTimeout(ctx3, veryLongDuration)
defer cancel4()
checkNoGoroutine()
@ -718,7 +751,7 @@ func XTestCustomContextGoroutines(t testingT) {
cancel5()
checkNoGoroutine()
_, cancel6 := WithTimeout(ctx5, 1*time.Hour)
_, cancel6 := WithTimeout(ctx5, veryLongDuration)
defer cancel6()
checkNoGoroutine()