Speed up testing (coredns#4239)

* Speed up testing * make notification run in the background, this recudes the test_readme time from 18s to 0.10s * reduce time for zone reload * TestServeDNSConcurrent remove entirely. This took a whopping 58s for ... ? A few minutes staring didn't reveal wth it is actually testing. Making values smaller revealed race conditions in the tests. Remove entirely. * Move many interval values to variables so we can reset them to short values for the tests. * test_large_axfr: make the zone smaller. The number used 64K has no rational, make it 64/10 to speed up. * TestProxyThreeWay: use client with shorter timeout A few random tidbits in other tests. Total time saved: 177s (almost 3m) - which makes it worthwhile again to run the test locally: this branch: ~~~ ok github.com/coredns/coredns/test 10.437s cd plugin; time go t ./... 5,51s user 7,51s system 11,15s elapsed 744%CPU ( ~~~ master: ~~~ ok github.com/coredns/coredns/test 35.252s cd plugin; time go t ./... 157,64s user 15,39s system 50,05s elapsed 345%CPU () ~~~ tests/ -25s plugins/ -40s This brings the total on 20s, and another 10s can be saved by fixing dnstapio. Moving this to 5s would be even better, but 10s is also nice. Signed-off-by: Miek Gieben <[email protected]> * Also 0.01 Signed-off-by: Miek Gieben <[email protected]>
diogenxs · Oct 30, 2020 · c840caf · c840caf
1 parent bc0115d
commit c840caf
Show file tree

Hide file tree

Showing 15 changed files with 85 additions and 285 deletions.
diff --git a/plugin/errors/errors_test.go b/plugin/errors/errors_test.go
@@ -6,11 +6,8 @@ import (
 	"errors"
 	"fmt"
 	golog "log"
-	"math/rand"
 	"regexp"
-	"strconv"
 	"strings"
-	"sync"
 	"sync/atomic"
 	"testing"
 	"time"
@@ -196,190 +193,6 @@ func TestStop(t *testing.T) {
 	}
 }
 
-const (
-	pattern0 = "failed"
-	pattern1 = "down$"
-)
-
-func TestServeDNSConcurrent(t *testing.T) {
-	buf := bytes.NewBuffer(nil)
-	golog.SetOutput(buf)
-
-	eg := newErrorGenerator()
-
-	h := &errorHandler{
-		patterns: []*pattern{
-			{
-				period:  3 * time.Nanosecond,
-				pattern: regexp.MustCompile(pattern0),
-			},
-			{
-				period:  2 * time.Nanosecond,
-				pattern: regexp.MustCompile(pattern1),
-			},
-		},
-		Next: eg,
-	}
-
-	ctx := context.TODO()
-	r := new(dns.Msg)
-	w := &test.ResponseWriter{}
-
-	var wg sync.WaitGroup
-	runnersCnt := 9
-	runner := func() {
-		defer wg.Done()
-		for eg.progress() < 100 {
-			h.ServeDNS(ctx, w, r)
-		}
-	}
-
-	wg.Add(runnersCnt)
-	for ; runnersCnt > 0; runnersCnt-- {
-		go runner()
-	}
-
-	stopCalled := false
-	for eg.progress() < 100 {
-		if !stopCalled && eg.progress() > 50 {
-			h.stop()
-			stopCalled = true
-		}
-		h.ServeDNS(ctx, w, r)
-	}
-	if !stopCalled {
-		h.stop()
-	}
-
-	wg.Wait()
-	time.Sleep(time.Millisecond)
-
-	rep := makeReport(t, buf)
-
-	if rep.c[Err0] == 0 {
-		t.Errorf("Err0 was never consolidated")
-	}
-	if rep.c[Err1] == 0 {
-		t.Errorf("Err1 was never consolidated")
-	}
-	if rep.c[Err0]+rep.r[Err0] != ErrCnt0 {
-		t.Errorf("Unexpected Err0 count, expected %d, consolidated %d and reported %d",
-			ErrCnt0, rep.c[Err0], rep.r[Err0])
-	}
-	if rep.c[Err1]+rep.r[Err1] != ErrCnt1 {
-		t.Errorf("Unexpected Err1 count, expected %d, consolidated %d and reported %d",
-			ErrCnt1, rep.c[Err1], rep.r[Err1])
-	}
-	if rep.r[Err2] != ErrCnt2 {
-		t.Errorf("Unexpected Err2 count, expected %d, reported %d",
-			ErrCnt2, rep.r[Err2])
-	}
-	if rep.r[Err3] != ErrCnt3 {
-		t.Errorf("Unexpected Err3 count, expected %d, reported %d",
-			ErrCnt3, rep.r[Err3])
-	}
-}
-
-// error generator
-const (
-	Err0 = iota
-	Err1
-	Err2
-	Err3
-
-	ErrStr0 = "failed to connect"
-	ErrStr1 = "upstream is down"
-	ErrStr2 = "access denied"
-	ErrStr3 = "yet another error"
-
-	ErrCnt0 = 120000
-	ErrCnt1 = 130000
-	ErrCnt2 = 150000
-	ErrCnt3 = 100000
-)
-
-type errorBunch struct {
-	cnt int32
-	err error
-}
-
-type errorGenerator struct {
-	errors   [4]errorBunch
-	totalCnt int32
-	totalLim int32
-}
-
-func newErrorGenerator() *errorGenerator {
-	rand.Seed(time.Now().UnixNano())
-
-	return &errorGenerator{
-		errors: [4]errorBunch{
-			{ErrCnt0, fmt.Errorf(ErrStr0)},
-			{ErrCnt1, fmt.Errorf(ErrStr1)},
-			{ErrCnt2, fmt.Errorf(ErrStr2)},
-			{ErrCnt3, fmt.Errorf(ErrStr3)},
-		},
-		totalLim: ErrCnt0 + ErrCnt1 + ErrCnt2 + ErrCnt3,
-	}
-}
-
-// returns progress as a value from [0..100] range
-func (sh *errorGenerator) progress() int32 {
-	return atomic.LoadInt32(&sh.totalCnt) * 100 / sh.totalLim
-}
-
-func (sh *errorGenerator) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
-	i := rand.Int()
-	for c := 0; c < 4; c++ {
-		errInd := (i + c) & 3
-		if atomic.AddInt32(&sh.errors[errInd].cnt, -1) >= 0 {
-			atomic.AddInt32(&sh.totalCnt, 1)
-			return 0, sh.errors[errInd].err
-		}
-		atomic.AddInt32(&sh.errors[errInd].cnt, 1)
-	}
-	return 0, nil
-}
-
-func (sh *errorGenerator) Name() string { return "errorGenerator" }
-
-// error report
-type errorReport struct {
-	c [4]uint32
-	r [4]uint32
-}
-
-func makeReport(t *testing.T, b *bytes.Buffer) errorReport {
-	logDump := b.String()
-	r := errorReport{}
-
-	re := regexp.MustCompile(`(\d+) errors like '(.*)' occurred`)
-	m := re.FindAllStringSubmatch(logDump, -1)
-	for _, sub := range m {
-		ind := 0
-		switch sub[2] {
-		case pattern0:
-			ind = Err0
-		case pattern1:
-			ind = Err1
-		default:
-			t.Fatalf("Unknown pattern found in log: %s", sub[0])
-		}
-		n, err := strconv.ParseUint(sub[1], 10, 32)
-		if err != nil {
-			t.Fatalf("Invalid number found in log: %s", sub[0])
-		}
-		r.c[ind] += uint32(n)
-	}
-	t.Logf("%d consolidated messages found", len(m))
-
-	r.r[Err0] = uint32(strings.Count(logDump, ErrStr0))
-	r.r[Err1] = uint32(strings.Count(logDump, ErrStr1))
-	r.r[Err2] = uint32(strings.Count(logDump, ErrStr2))
-	r.r[Err3] = uint32(strings.Count(logDump, ErrStr3))
-	return r
-}
-
 func genErrorHandler(rcode int, err error) plugin.Handler {
 	return plugin.HandlerFunc(func(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
 		return rcode, err

diff --git a/plugin/file/reload_test.go b/plugin/file/reload_test.go
@@ -30,9 +30,9 @@ func TestZoneReload(t *testing.T) {
 		t.Fatalf("Failed to parse zone: %s", err)
 	}
 
-	z.ReloadInterval = 500 * time.Millisecond
+	z.ReloadInterval = 10 * time.Millisecond
 	z.Reload(&transfer.Transfer{})
-	time.Sleep(time.Second)
+	time.Sleep(20 * time.Millisecond)
 
 	ctx := context.TODO()
 	r := new(dns.Msg)
@@ -60,7 +60,7 @@ func TestZoneReload(t *testing.T) {
 		t.Fatalf("Failed to write new zone data: %s", err)
 	}
 	// Could still be racy, but we need to wait a bit for the event to be seen
-	time.Sleep(1 * time.Second)
+	time.Sleep(30 * time.Millisecond)
 
 	rrs, err = z.ApexIfDefined()
 	if err != nil {

diff --git a/plugin/file/setup.go b/plugin/file/setup.go
@@ -28,9 +28,11 @@ func setup(c *caddy.Controller) error {
 			return nil
 		}
 		f.transfer = t.(*transfer.Transfer) // if found this must be OK.
-		for _, n := range zones.Names {
-			f.transfer.Notify(n)
-		}
+		go func() {
+			for _, n := range zones.Names {
+				f.transfer.Notify(n)
+			}
+		}()
 		return nil
 	})
 
@@ -39,9 +41,11 @@ func setup(c *caddy.Controller) error {
 		if t == nil {
 			return nil
 		}
-		for _, n := range zones.Names {
-			f.transfer.Notify(n)
-		}
+		go func() {
+			for _, n := range zones.Names {
+				f.transfer.Notify(n)
+			}
+		}()
 		return nil
 	})
 

diff --git a/plugin/forward/forward.go b/plugin/forward/forward.go
@@ -229,4 +229,4 @@ type options struct {
 	hcRecursionDesired bool
 }
 
-const defaultTimeout = 5 * time.Second
+var defaultTimeout = 5 * time.Second
diff --git a/plugin/forward/health.go b/plugin/forward/health.go
@@ -24,14 +24,19 @@ type dnsHc struct {
 	recursionDesired bool
 }
 
+var (
+	hcReadTimeout  = 1 * time.Second
+	hcWriteTimeout = 1 * time.Second
+)
+
 // NewHealthChecker returns a new HealthChecker based on transport.
 func NewHealthChecker(trans string, recursionDesired bool) HealthChecker {
 	switch trans {
 	case transport.DNS, transport.TLS:
 		c := new(dns.Client)
 		c.Net = "udp"
-		c.ReadTimeout = 1 * time.Second
-		c.WriteTimeout = 1 * time.Second
+		c.ReadTimeout = hcReadTimeout
+		c.WriteTimeout = hcWriteTimeout
 
 		return &dnsHc{c: c, recursionDesired: recursionDesired}
 	}