diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index 121141b1..acf22474 100644 --- a/nameserver/nameserver.go +++ b/nameserver/nameserver.go @@ -108,7 +108,7 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Return with server failure if offline. if netenv.GetOnlineStatus() == netenv.StatusOffline && !netenv.IsConnectivityDomain(q.FQDN) { - tracer.Debugf("resolver: not resolving %s, device is offline", q.FQDN) + tracer.Debugf("namserver: not resolving %s, device is offline", q.FQDN) return reply(nsutil.ServerFailure("resolving disabled, device is offline")) } @@ -121,6 +121,7 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Handle request for localhost. if strings.HasSuffix(q.FQDN, "localhost.") { + tracer.Tracef("namserver: returning localhost records") return reply(nsutil.Localhost("")) } @@ -196,15 +197,23 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // React to special errors. switch { case errors.Is(err, resolver.ErrNotFound): - return reply(nsutil.NxDomain(""), nil) + tracer.Tracef("namserver: NXDomain via error") + return reply(nsutil.NxDomain("")) case errors.Is(err, resolver.ErrBlocked): - return reply(nsutil.ZeroIP(""), nil) + tracer.Tracef("namserver: block via error") + return reply(nsutil.ZeroIP("")) case errors.Is(err, resolver.ErrLocalhost): - return reply(nsutil.Localhost(""), nil) + tracer.Tracef("namserver: returning localhost records") + return reply(nsutil.Localhost("")) default: - return reply(nsutil.ServerFailure("internal error: "+err.Error()), nil) + tracer.Warningf("nameserver: failed to resolve %s: %s", q.ID(), err) + return reply(nsutil.ServerFailure("internal error: " + err.Error())) } } + if rrCache == nil { + tracer.Warning("nameserver: received successful, but empty reply from resolver") + return reply(nsutil.ServerFailure("internal error: empty reply")) + } tracer.Trace("nameserver: deciding on resolved dns") rrCache = firewall.DecideOnResolvedDNS(ctx, conn, q, rrCache) diff --git a/nameserver/nsutil/nsutil.go b/nameserver/nsutil/nsutil.go index d427a376..7a8b730b 100644 --- a/nameserver/nsutil/nsutil.go +++ b/nameserver/nsutil/nsutil.go @@ -74,9 +74,7 @@ func ZeroIP(msgs ...string) ResponderFunc { reply.SetRcode(request, dns.RcodeSuccess) } - for _, msg := range msgs { - AddMessageToReply(ctx, reply, log.InfoLevel, msg) - } + AddMessagesToReply(ctx, reply, log.InfoLevel, msgs...) return reply } @@ -116,9 +114,7 @@ func Localhost(msgs ...string) ResponderFunc { reply.SetRcode(request, dns.RcodeSuccess) } - for _, msg := range msgs { - AddMessageToReply(ctx, reply, log.InfoLevel, msg) - } + AddMessagesToReply(ctx, reply, log.InfoLevel, msgs...) return reply } @@ -128,9 +124,7 @@ func Localhost(msgs ...string) ResponderFunc { func NxDomain(msgs ...string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg).SetRcode(request, dns.RcodeNameError) - for _, msg := range msgs { - AddMessageToReply(ctx, reply, log.InfoLevel, msg) - } + AddMessagesToReply(ctx, reply, log.InfoLevel, msgs...) return reply } } @@ -139,9 +133,7 @@ func NxDomain(msgs ...string) ResponderFunc { func Refused(msgs ...string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg).SetRcode(request, dns.RcodeRefused) - for _, msg := range msgs { - AddMessageToReply(ctx, reply, log.InfoLevel, msg) - } + AddMessagesToReply(ctx, reply, log.InfoLevel, msgs...) return reply } } @@ -150,9 +142,7 @@ func Refused(msgs ...string) ResponderFunc { func ServerFailure(msgs ...string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg).SetRcode(request, dns.RcodeServerFailure) - for _, msg := range msgs { - AddMessageToReply(ctx, reply, log.InfoLevel, msg) - } + AddMessagesToReply(ctx, reply, log.InfoLevel, msgs...) return reply } } @@ -174,18 +164,25 @@ func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { //nolin return rr, nil } -// AddMessageToReply creates an information resource records using -// MakeMessageRecord and immediately adds it the the extra section of the given +// AddMessagesToReply creates information resource records using +// MakeMessageRecord and immediately adds them to the extra section of the given // reply. If an error occurs, the resource record will not be added, and the // error will be logged. -func AddMessageToReply(ctx context.Context, reply *dns.Msg, level log.Severity, msg string) { - if msg != "" { +func AddMessagesToReply(ctx context.Context, reply *dns.Msg, level log.Severity, msgs ...string) { + for _, msg := range msgs { + // Ignore empty messages. + if msg == "" { + continue + } + + // Create resources record. rr, err := MakeMessageRecord(level, msg) if err != nil { log.Tracer(ctx).Warningf("nameserver: failed to add message to reply: %s", err) - return + continue } + // Add to extra section of the reply. reply.Extra = append(reply.Extra, rr) } } diff --git a/nameserver/response.go b/nameserver/response.go index 0780edf0..1159ce9e 100644 --- a/nameserver/response.go +++ b/nameserver/response.go @@ -29,8 +29,10 @@ func sendResponse( // Add extra RRs through a custom RRProvider. for _, rrProvider := range rrProviders { - rrs := rrProvider.GetExtraRRs(ctx, request) - reply.Extra = append(reply.Extra, rrs...) + if rrProvider != nil { + rrs := rrProvider.GetExtraRRs(ctx, request) + reply.Extra = append(reply.Extra, rrs...) + } } // Write reply. diff --git a/network/dns.go b/network/dns.go index c22867ef..a3161bff 100644 --- a/network/dns.go +++ b/network/dns.go @@ -105,7 +105,7 @@ func (conn *Connection) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns return nsutil.ZeroIP().ReplyWithDNS(ctx, request) default: reply := nsutil.ServerFailure().ReplyWithDNS(ctx, request) - nsutil.AddMessageToReply(ctx, reply, log.ErrorLevel, "INTERNAL ERROR: incorrect use of network.Connection's DNS Responder") + nsutil.AddMessagesToReply(ctx, reply, log.ErrorLevel, "INTERNAL ERROR: incorrect use of Connection DNS Responder") return reply } } diff --git a/resolver/resolve.go b/resolver/resolve.go index 004baa66..921f2b8e 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -132,7 +132,6 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { if !q.NoCaching { rrCache = checkCache(ctx, q) if rrCache != nil && !rrCache.Expired() { - rrCache.MixAnswers() return rrCache, nil } @@ -142,7 +141,6 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { // we waited for another request, recheck the cache! rrCache = checkCache(ctx, q) if rrCache != nil && !rrCache.Expired() { - rrCache.MixAnswers() return rrCache, nil } log.Tracer(ctx).Debugf("resolver: waited for another %s%s query, but cache missed!", q.FQDN, q.QType) @@ -221,7 +219,7 @@ func checkCache(ctx context.Context, q *Query) *RRCache { log.Tracer(ctx).Tracef( "resolver: cache for %s will expire in %s, refreshing async now", q.ID(), - time.Until(time.Unix(rrCache.TTL, 0)), + time.Until(time.Unix(rrCache.TTL, 0)).Round(time.Second), ) // resolve async @@ -231,6 +229,8 @@ func checkCache(ctx context.Context, q *Query) *RRCache { _, err := resolveAndCache(ctx, q, nil) if err != nil { tracer.Warningf("resolver: async query for %s failed: %s", q.ID(), err) + } else { + tracer.Debugf("resolver: async query for %s succeeded", q.ID()) } return nil }) @@ -240,7 +240,7 @@ func checkCache(ctx context.Context, q *Query) *RRCache { log.Tracer(ctx).Tracef( "resolver: using cached RR (expires in %s)", - time.Until(time.Unix(rrCache.TTL, 0)), + time.Until(time.Unix(rrCache.TTL, 0)).Round(time.Second), ) return rrCache } @@ -392,13 +392,24 @@ resolveLoop: } // Check if we want to use an older cache instead. - switch { - case err != nil: - // There was an error during resolving, return the old cache entry instead. - return oldCache, nil - case rrCache.IsNXDomain(): - // The new result is NXDomain, return the old cache entry instead. - return oldCache, nil + if oldCache != nil { + oldCache.isBackup = true + + switch { + case err != nil: + // There was an error during resolving, return the old cache entry instead. + log.Tracer(ctx).Debugf("resolver: serving backup cache of %s because query failed: %s", q.ID(), err) + return oldCache, nil + case rrCache.IsNXDomain(): + // The new result is NXDomain, return the old cache entry instead. + log.Tracer(ctx).Debugf("resolver: serving backup cache of %s because fresh response is NXDomain", q.ID()) + return oldCache, nil + } + } + + // Return error, if there is one. + if err != nil { + return nil, err } // Save the new entry if cache is enabled. @@ -406,7 +417,7 @@ resolveLoop: rrCache.Clean(minTTL) err = rrCache.Save() if err != nil { - log.Warningf("resolver: failed to cache RR for %s%s: %s", q.FQDN, q.QType.String(), err) + log.Tracer(ctx).Warningf("resolver: failed to cache RR for %s: %s", q.ID(), err) } } diff --git a/resolver/rrcache.go b/resolver/rrcache.go index df5e019f..ed1944bb 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -23,7 +23,7 @@ type RRCache struct { Domain string // constant Question dns.Type // constant - Answer []dns.RR // might be mixed + Answer []dns.RR // constant Ns []dns.RR // constant Extra []dns.RR // constant TTL int64 // constant @@ -34,6 +34,7 @@ type RRCache struct { servedFromCache bool // mutable requestingNew bool // mutable + isBackup bool // mutable Filtered bool // mutable FilteredEntries []string // mutable @@ -55,19 +56,11 @@ func (rrCache *RRCache) ExpiresSoon() bool { return rrCache.TTL <= time.Now().Unix()+refreshTTL } -// MixAnswers randomizes the answer records to allow dumb clients (who only look at the first record) to reliably connect. -func (rrCache *RRCache) MixAnswers() { +// Clean sets all TTLs to 17 and sets cache expiry with specified minimum. +func (rrCache *RRCache) Clean(minExpires uint32) { rrCache.Lock() defer rrCache.Unlock() - for i := range rrCache.Answer { - j := rand.Intn(i + 1) - rrCache.Answer[i], rrCache.Answer[j] = rrCache.Answer[j], rrCache.Answer[i] - } -} - -// Clean sets all TTLs to 17 and sets cache expiry with specified minimum. -func (rrCache *RRCache) Clean(minExpires uint32) { var lowestTTL uint32 = 0xFFFFFFFF var header *dns.RR_Header @@ -221,6 +214,9 @@ func (rrCache *RRCache) Flags() string { if rrCache.requestingNew { s += "R" } + if rrCache.isBackup { + s += "B" + } if rrCache.Filtered { s += "F" } @@ -253,6 +249,7 @@ func (rrCache *RRCache) ShallowCopy() *RRCache { updated: rrCache.updated, servedFromCache: rrCache.servedFromCache, requestingNew: rrCache.requestingNew, + isBackup: rrCache.isBackup, Filtered: rrCache.Filtered, FilteredEntries: rrCache.FilteredEntries, } @@ -263,13 +260,23 @@ func (rrCache *RRCache) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns // reply to query reply := new(dns.Msg) reply.SetRcode(request, dns.RcodeSuccess) - reply.Answer = rrCache.Answer reply.Ns = rrCache.Ns reply.Extra = rrCache.Extra - // Set NXDomain return code. if rrCache.IsNXDomain() { + // Set NXDomain return code if not the reply has no answers. reply.Rcode = dns.RcodeNameError + } else { + // Copy answers, as we randomize their order a little. + reply.Answer = make([]dns.RR, len(rrCache.Answer)) + copy(reply.Answer, rrCache.Answer) + + // Randomize the order of the answer records a little to allow dumb clients + // (who only look at the first record) to reliably connect. + for i := range reply.Answer { + j := rand.Intn(i + 1) + reply.Answer[i], reply.Answer[j] = reply.Answer[j], reply.Answer[i] + } } return reply @@ -286,13 +293,16 @@ func (rrCache *RRCache) GetExtraRRs(ctx context.Context, query *dns.Msg) (extra // Add expiry and cache information. if rrCache.Expired() { - extra = addExtra(ctx, extra, fmt.Sprintf("record expired since %s, requesting new", time.Since(time.Unix(rrCache.TTL, 0)))) + extra = addExtra(ctx, extra, fmt.Sprintf("record expired since %s", time.Since(time.Unix(rrCache.TTL, 0)).Round(time.Second))) } else { - extra = addExtra(ctx, extra, fmt.Sprintf("record valid for %s", time.Until(time.Unix(rrCache.TTL, 0)))) + extra = addExtra(ctx, extra, fmt.Sprintf("record valid for %s", time.Until(time.Unix(rrCache.TTL, 0)).Round(time.Second))) } if rrCache.requestingNew { extra = addExtra(ctx, extra, "async request to refresh the cache has been started") } + if rrCache.isBackup { + extra = addExtra(ctx, extra, "this record is served because a fresh request failed") + } // Add information about filtered entries. if rrCache.Filtered {