plugin/cache: fix negative cache masking cases (#3744)

* fix negative cache masking cases
Signed-off-by: Chris O'Haver <cohaver@infoblox.com>

* remove unecessary param
Signed-off-by: Chris O'Haver <cohaver@infoblox.com>

plugin/cache/cache.go

@@ -210,6 +210,10 @@ func (w *ResponseWriter) set(m *dns.Msg, key uint64, mt response.Type, duration
 	case response.NoError, response.Delegation:
 		i := newItem(m, w.now(), duration)
 		w.pcache.Add(key, i)
+		// when pre-fetching, remove the negative cache entry if it exists
+		if w.prefetch {
+			w.ncache.Remove(key)
+		}
 
 	case response.NameError, response.NoData, response.ServerError:
 		i := newItem(m, w.now(), duration)

plugin/cache/cache_test.go

@@ -296,6 +296,92 @@ func TestServeFromStaleCache(t *testing.T) {
 	}
 }
 
+func TestNegativeStaleMaskingPositiveCache(t *testing.T) {
+	c := New()
+	c.staleUpTo = time.Minute * 10
+	c.Next = nxDomainBackend(60)
+
+	req := new(dns.Msg)
+	qname := "cached.org."
+	req.SetQuestion(qname, dns.TypeA)
+	ctx := context.TODO()
+
+	// Add an entry to Negative Cache": cached.org. = NXDOMAIN
+	expectedResult := dns.RcodeNameError
+	if ret, _ := c.ServeDNS(ctx, &test.ResponseWriter{}, req); ret != expectedResult {
+		t.Errorf("Test 0 Negative Cache Population: expecting %v; got %v", expectedResult, ret)
+	}
+
+	// Confirm item was added to negative cache and not to positive cache
+	if c.ncache.Len() == 0 {
+		t.Errorf("Test 0 Negative Cache Population: item not added to negative cache")
+	}
+	if c.pcache.Len() != 0 {
+		t.Errorf("Test 0 Negative Cache Population: item added to positive cache")
+	}
+
+	// Set the Backend to return non-cachable errors only
+	c.Next = plugin.HandlerFunc(func(context.Context, dns.ResponseWriter, *dns.Msg) (int, error) {
+		return 255, nil // Below, a 255 means we tried querying upstream.
+	})
+
+	// Confirm we get the NXDOMAIN from the negative cache, not the error form the backend
+	rec := dnstest.NewRecorder(&test.ResponseWriter{})
+	req = new(dns.Msg)
+	req.SetQuestion(qname, dns.TypeA)
+	expectedResult = dns.RcodeNameError
+	if c.ServeDNS(ctx, rec, req); rec.Rcode != expectedResult {
+		t.Errorf("Test 1 NXDOMAIN from Negative Cache: expecting %v; got %v", expectedResult, rec.Rcode)
+	}
+
+	// Jump into the future beyond when the negative cache item would go stale
+	// but before the item goes rotten (exceeds serve stale time)
+	c.now = func() time.Time { return time.Now().Add(time.Duration(5) * time.Minute) }
+
+	// Set Backend to return a positive NOERROR + A record response
+	c.Next = BackendHandler()
+
+	// Make a query for the stale cache item
+	rec = dnstest.NewRecorder(&test.ResponseWriter{})
+	req = new(dns.Msg)
+	req.SetQuestion(qname, dns.TypeA)
+	expectedResult = dns.RcodeNameError
+	if c.ServeDNS(ctx, rec, req); rec.Rcode != expectedResult {
+		t.Errorf("Test 2 NOERROR from Backend: expecting %v; got %v", expectedResult, rec.Rcode)
+	}
+
+	// Confirm that prefetch removes the negative cache item.
+	waitFor := 3
+	for i := 1; i <= waitFor; i++ {
+		if c.ncache.Len() != 0 {
+			if i == waitFor {
+				t.Errorf("Test 2 NOERROR from Backend: item still exists in negative cache")
+			}
+			time.Sleep(time.Second)
+			continue
+		}
+	}
+
+	// Confirm that positive cache has the item
+	if c.pcache.Len() != 1 {
+		t.Errorf("Test 2 NOERROR from Backend: item missing from positive cache")
+	}
+
+	// Backend - Give error only
+	c.Next = plugin.HandlerFunc(func(context.Context, dns.ResponseWriter, *dns.Msg) (int, error) {
+		return 255, nil // Below, a 255 means we tried querying upstream.
+	})
+
+	// Query again, expect that positive cache entry is not masked by a negative cache entry
+	rec = dnstest.NewRecorder(&test.ResponseWriter{})
+	req = new(dns.Msg)
+	req.SetQuestion(qname, dns.TypeA)
+	expectedResult = dns.RcodeSuccess
+	if ret, _ := c.ServeDNS(ctx, rec, req); ret != expectedResult {
+		t.Errorf("Test 3 NOERROR from Cache: expecting %v; got %v", expectedResult, ret)
+	}
+}
+
 func BenchmarkCacheResponse(b *testing.B) {
 	c := New()
 	c.prefetch = 1
@@ -334,6 +420,20 @@ func BackendHandler() plugin.Handler {
 	})
 }
 
+func nxDomainBackend(ttl int) plugin.Handler {
+	return plugin.HandlerFunc(func(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
+		m := new(dns.Msg)
+		m.SetReply(r)
+		m.Response, m.RecursionAvailable = true, true
+
+		m.Ns = []dns.RR{test.SOA(fmt.Sprintf("example.org. %d IN	SOA	sns.dns.icann.org. noc.dns.icann.org. 2016082540 7200 3600 1209600 3600", ttl))}
+
+		m.MsgHdr.Rcode = dns.RcodeNameError
+		w.WriteMsg(m)
+		return dns.RcodeNameError, nil
+	})
+}
+
 func ttlBackend(ttl int) plugin.Handler {
 	return plugin.HandlerFunc(func(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
 		m := new(dns.Msg)

plugin/cache/handler.go

@@ -31,7 +31,7 @@ func (c *Cache) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg)
 	if i != nil {
 		ttl = i.ttl(now)
 	}
-	if i == nil || -ttl >= int(c.staleUpTo.Seconds()) {
+	if i == nil {
 		crr := &ResponseWriter{ResponseWriter: w, Cache: c, state: state, server: server}
 		return plugin.NextOrFailure(c.Name(), c.Next, ctx, crr, r)
 	}
@@ -104,15 +104,15 @@ func (c *Cache) getIgnoreTTL(now time.Time, state request.Request, server string
 		ttl := i.(*item).ttl(now)
 		if ttl > 0 || (c.staleUpTo > 0 && -ttl < int(c.staleUpTo.Seconds())) {
 			cacheHits.WithLabelValues(server, Denial).Inc()
+			return i.(*item)
 		}
-		return i.(*item)
 	}
 	if i, ok := c.pcache.Get(k); ok {
 		ttl := i.(*item).ttl(now)
 		if ttl > 0 || (c.staleUpTo > 0 && -ttl < int(c.staleUpTo.Seconds())) {
 			cacheHits.WithLabelValues(server, Success).Inc()
+			return i.(*item)
 		}
-		return i.(*item)
 	}
 	cacheMisses.WithLabelValues(server).Inc()
 	return nil