plugin/cache: Fix prefetching issues (#1363)

* Improve plugin/cache metrics

* Add coredns_cache_prefetch_total metric to track number of prefetches.
* Remove unnecessary Cache.get() call which would incorrectly increment
  cache counters.
* Initialize all counters and gauges at zero.

* Allow prefetching of a single request per ttl

The original implementation didn't allow prefetching queries which are
only requested once during the duration of a TTL. The minimum amount of
queries which had to be seen was therefore capped at 2.

This change also implements a real prefetch test. The existing test was
a noop and always passed regardless of any prefetch implementation.

* Fix prefetching for items with a short TTL

The default prefetch threshold (percentage) is 10% of the lifetime of a
cache item. With the previous implementation, this disabled prefetching
for all items with a TTL < 10s (the resulting percentage would be 0, at
which point a cached item is already discarded).

This change uses a time based threshold calculation and ensures that
a prefetch is triggered at a TTL of 1 at the latest.

* Fix wrong duration reporting of cached responses

The logging and metrics plugins (among others) included the duration of
a cache prefetch in the request latency of client request. This change
fixes this wrong reporting and executes the prefetch request in a
goroutine in the background.

1 files changed, 6 insertions, 12 deletions

diff --git a/plugin/cache/cache_test.go b/plugin/cache/cache_test.go
index 7b7c2c6f2..b475f3473 100644
--- a/plugin/cache/cache_test.go
+++ b/plugin/cache/cache_test.go
@@ -9,7 +9,6 @@ import (
 	"golang.org/x/net/context"
 
 	"github.com/coredns/coredns/plugin"
-	"github.com/coredns/coredns/plugin/pkg/cache"
 	"github.com/coredns/coredns/plugin/pkg/response"
 	"github.com/coredns/coredns/plugin/test"
 
@@ -149,9 +148,9 @@ func cacheMsg(m *dns.Msg, tc cacheTestCase) *dns.Msg {
 }
 
 func newTestCache(ttl time.Duration) (*Cache, *ResponseWriter) {
-	c := &Cache{Zones: []string{"."}, pcap: defaultCap, ncap: defaultCap, pttl: ttl, nttl: ttl}
-	c.pcache = cache.New(c.pcap)
-	c.ncache = cache.New(c.ncap)
+	c := New()
+	c.pttl = ttl
+	c.nttl = ttl
 
 	crr := &ResponseWriter{ResponseWriter: nil, Cache: c}
 	return c, crr
@@ -187,7 +186,7 @@ func TestCache(t *testing.T) {
 		}
 
 		if ok {
-			resp := i.toMsg(m)
+			resp := i.toMsg(m, time.Now().UTC())
 
 			if !test.Header(t, tc.Case, resp) {
 				t.Logf("%v\n", resp)
@@ -209,9 +208,7 @@ func TestCache(t *testing.T) {
 }
 
 func TestCacheZeroTTL(t *testing.T) {
-	c := &Cache{Zones: []string{"."}, pcap: defaultCap, ncap: defaultCap, pttl: maxTTL, nttl: maxTTL}
-	c.pcache = cache.New(c.pcap)
-	c.ncache = cache.New(c.ncap)
+	c := New()
 	c.Next = zeroTTLBackend()
 
 	req := new(dns.Msg)
@@ -228,11 +225,8 @@ func TestCacheZeroTTL(t *testing.T) {
 }
 
 func BenchmarkCacheResponse(b *testing.B) {
-	c := &Cache{Zones: []string{"."}, pcap: defaultCap, ncap: defaultCap, pttl: maxTTL, nttl: maxTTL}
-	c.pcache = cache.New(c.pcap)
-	c.ncache = cache.New(c.ncap)
+	c := New()
 	c.prefetch = 1
-	c.duration = 1 * time.Second
 	c.Next = BackendHandler()
 
 	ctx := context.TODO()