From f46e7595240648ec8197ca9bf6194051d8bb73ba Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 16:57:54 +0200 Subject: [PATCH 01/22] Use new Purge method of the database --- core/base/databases.go | 3 -- core/control.go | 1 - intel/filterlists/database.go | 22 ++++++++++---- intel/filterlists/updater.go | 55 ++++++----------------------------- network/database.go | 1 - resolver/namerecord.go | 47 ++++-------------------------- 6 files changed, 32 insertions(+), 97 deletions(-) diff --git a/core/base/databases.go b/core/base/databases.go index cf8bd8f8..e9ae8f74 100644 --- a/core/base/databases.go +++ b/core/base/databases.go @@ -20,7 +20,6 @@ func registerDatabases() error { Name: "core", Description: "Holds core data, such as settings and profiles", StorageType: DefaultDatabaseStorageType, - PrimaryAPI: "", }) if err != nil { return err @@ -30,7 +29,6 @@ func registerDatabases() error { Name: "cache", Description: "Cached data, such as Intelligence and DNS Records", StorageType: DefaultDatabaseStorageType, - PrimaryAPI: "", }) if err != nil { return err @@ -40,7 +38,6 @@ func registerDatabases() error { // Name: "history", // Description: "Historic event data", // StorageType: DefaultDatabaseStorageType, - // PrimaryAPI: "", // }) // if err != nil { // return err diff --git a/core/control.go b/core/control.go index b94163d9..32898a85 100644 --- a/core/control.go +++ b/core/control.go @@ -69,7 +69,6 @@ func registerControlDatabase() error { Name: "control", Description: "Control Interface for the Portmaster", StorageType: "injected", - PrimaryAPI: "", }) if err != nil { return err diff --git a/intel/filterlists/database.go b/intel/filterlists/database.go index 46c54673..bff14c5e 100644 --- a/intel/filterlists/database.go +++ b/intel/filterlists/database.go @@ -76,7 +76,7 @@ func isLoaded() bool { } } -// processListFile opens the latest version of f ile and decodes it's DSDL +// processListFile opens the latest version of file and decodes it's DSDL // content. It calls processEntry for each decoded filterlists entry. func processListFile(ctx context.Context, filter *scopedBloom, file *updater.File) error { f, err := os.Open(file.Path()) @@ -135,10 +135,20 @@ func processListFile(ctx context.Context, filter *scopedBloom, file *updater.Fil func persistRecords(startJob func(func() error), records <-chan record.Record) { var cnt int start := time.Now() + logProgress := func() { + if cnt == 0 { + // protection against panic + return + } + + timePerEntity := time.Since(start) / time.Duration(cnt) + speed := float64(time.Second) / float64(timePerEntity) + log.Debugf("processed %d entities in %s with %s / entity (%.2f entities/second)", cnt, time.Since(start), timePerEntity, speed) + } batch := database.NewInterface(&database.Options{Local: true, Internal: true}) - var processBatch func() error + var processBatch func() error processBatch = func() error { batchPut := batch.PutMany("cache") for r := range records { @@ -148,9 +158,7 @@ func persistRecords(startJob func(func() error), records <-chan record.Record) { cnt++ if cnt%10000 == 0 { - timePerEntity := time.Since(start) / time.Duration(cnt) - speed := float64(time.Second) / float64(timePerEntity) - log.Debugf("processed %d entities %s with %s / entity (%.2f entits/second)", cnt, time.Since(start), timePerEntity, speed) + logProgress() } if cnt%1000 == 0 { @@ -164,6 +172,10 @@ func persistRecords(startJob func(func() error), records <-chan record.Record) { } } + // log final batch + if cnt%10000 != 0 { // avoid duplicate logging + logProgress() + } return batchPut(nil) } diff --git a/intel/filterlists/updater.go b/intel/filterlists/updater.go index 8e0cf8fc..fee830dc 100644 --- a/intel/filterlists/updater.go +++ b/intel/filterlists/updater.go @@ -129,56 +129,19 @@ func performUpdate(ctx context.Context) error { return nil } -func removeAllObsoleteFilterEntries(_ context.Context) error { +func removeAllObsoleteFilterEntries(ctx context.Context) error { log.Debugf("intel/filterlists: cleanup task started, removing obsolete filter list entries ...") - for { - done, err := removeObsoleteFilterEntries(10000) - if err != nil { - return err - } - - if done { - return nil - } - } -} - -func removeObsoleteFilterEntries(batchSize int) (bool, error) { - iter, err := cache.Query( - query.New(filterListKeyPrefix).Where( - // TODO(ppacher): remember the timestamp we started the last update - // and use that rather than "one hour ago" - query.Where("UpdatedAt", query.LessThan, time.Now().Add(-time.Hour).Unix()), - ), - ) + n, err := cache.Purge(ctx, query.New(filterListKeyPrefix).Where( + // TODO(ppacher): remember the timestamp we started the last update + // and use that rather than "one hour ago" + query.Where("UpdatedAt", query.LessThan, time.Now().Add(-time.Hour).Unix()), + )) if err != nil { - return false, err + return err } - keys := make([]string, 0, batchSize) - - var cnt int - for r := range iter.Next { - cnt++ - keys = append(keys, r.Key()) - - if cnt == batchSize { - break - } - } - iter.Cancel() - - for _, key := range keys { - if err := cache.Delete(key); err != nil { - log.Errorf("intel/filterlists: failed to remove stale cache entry %q: %s", key, err) - } - } - - log.Debugf("intel/filterlists: successfully removed %d obsolete entries", cnt) - - // if we removed less entries that the batch size we - // are done and no more entries exist - return cnt < batchSize, nil + log.Debugf("intel/filterlists: successfully removed %d obsolete entries", n) + return nil } // getUpgradableFiles returns a slice of filterlists files diff --git a/network/database.go b/network/database.go index a44a379c..9418414f 100644 --- a/network/database.go +++ b/network/database.go @@ -129,7 +129,6 @@ func registerAsDatabase() error { Name: "network", Description: "Network and Firewall Data", StorageType: "injected", - PrimaryAPI: "", }) if err != nil { return err diff --git a/resolver/namerecord.go b/resolver/namerecord.go index 8c9b888d..2c240327 100644 --- a/resolver/namerecord.go +++ b/resolver/namerecord.go @@ -85,48 +85,13 @@ func (rec *NameRecord) Save() error { return recordDatabase.PutNew(rec) } -func clearNameCache(_ context.Context, _ interface{}) error { - log.Debugf("resolver: name cache clearing started...") - for { - done, err := removeNameEntries(10000) - if err != nil { - return err - } - - if done { - return nil - } - } -} - -func removeNameEntries(batchSize int) (bool, error) { - iter, err := recordDatabase.Query(query.New(nameRecordsKeyPrefix)) +func clearNameCache(ctx context.Context, _ interface{}) error { + log.Debugf("resolver: dns cache clearing started...") + n, err := recordDatabase.Purge(ctx, query.New(nameRecordsKeyPrefix)) if err != nil { - return false, err + return err } - keys := make([]string, 0, batchSize) - - var cnt int - for r := range iter.Next { - cnt++ - keys = append(keys, r.Key()) - - if cnt == batchSize { - break - } - } - iter.Cancel() - - for _, key := range keys { - if err := recordDatabase.Delete(key); err != nil { - log.Warningf("resolver: failed to remove name cache entry %q: %s", key, err) - } - } - - log.Debugf("resolver: successfully removed %d name cache entries", cnt) - - // if we removed less entries that the batch size we - // are done and no more entries exist - return cnt < batchSize, nil + log.Debugf("resolver: cleared %d entries in dns cache", n) + return nil } From 3f3d82bdf1496d9dea523291d57306953f8ef17c Mon Sep 17 00:00:00 2001 From: Daniel Date: Tue, 22 Sep 2020 15:27:55 +0200 Subject: [PATCH 02/22] Improve debug information in DNS responses --- firewall/bypassing.go | 4 +- intel/block_reason.go | 15 ++- nameserver/nameserver.go | 260 ++++++++++++++---------------------- nameserver/nsutil/nsutil.go | 128 ++++++++++++++---- nameserver/response.go | 59 +++++--- network/dns.go | 49 +++++++ network/status.go | 24 ++++ resolver/rrcache.go | 59 ++++++++ 8 files changed, 382 insertions(+), 216 deletions(-) diff --git a/firewall/bypassing.go b/firewall/bypassing.go index 5beb96b0..602fbea2 100644 --- a/firewall/bypassing.go +++ b/firewall/bypassing.go @@ -13,7 +13,9 @@ import ( func PreventBypassing(conn *network.Connection) (endpoints.EPResult, string, nsutil.Responder) { // Block firefox canary domain to disable DoH if strings.ToLower(conn.Entity.Domain) == "use-application-dns.net." { - return endpoints.Denied, "blocked canary domain to prevent enabling DNS-over-HTTPs", nsutil.NxDomain() + return endpoints.Denied, + "blocked canary domain to prevent enabling of DNS-over-HTTPs", + nsutil.NxDomain("blocked canary domain to prevent enabling of DNS-over-HTTPs") } return endpoints.NoMatch, "", nil diff --git a/intel/block_reason.go b/intel/block_reason.go index ad140f4f..266e7140 100644 --- a/intel/block_reason.go +++ b/intel/block_reason.go @@ -1,6 +1,7 @@ package intel import ( + "context" "encoding/json" "fmt" "strings" @@ -66,31 +67,31 @@ func (br ListBlockReason) MarshalJSON() ([]byte, error) { // GetExtraRR implements the nsutil.RRProvider interface // and adds additional TXT records justifying the reason // the request was blocked. -func (br ListBlockReason) GetExtraRR(_ *dns.Msg, _ string, _ interface{}) []dns.RR { +func (br ListBlockReason) GetExtraRRs(ctx context.Context, _ *dns.Msg) []dns.RR { rrs := make([]dns.RR, 0, len(br)) for _, lm := range br { - blockedBy, err := dns.NewRR(fmt.Sprintf( - `%s 0 IN TXT "blocked by filter lists %s"`, + blockedBy, err := nsutil.MakeMessageRecord(log.InfoLevel, fmt.Sprintf( + "%s is blocked by filter lists %s", lm.Entity, strings.Join(lm.ActiveLists, ", "), )) if err == nil { rrs = append(rrs, blockedBy) } else { - log.Errorf("intel: failed to create TXT RR for block reason: %s", err) + log.Tracer(ctx).Errorf("intel: failed to create TXT RR for block reason: %s", err) } if len(lm.InactiveLists) > 0 { - wouldBeBlockedBy, err := dns.NewRR(fmt.Sprintf( - `%s 0 IN TXT "would be blocked by filter lists %s"`, + wouldBeBlockedBy, err := nsutil.MakeMessageRecord(log.InfoLevel, fmt.Sprintf( + "%s would be blocked by filter lists %s", lm.Entity, strings.Join(lm.InactiveLists, ", "), )) if err == nil { rrs = append(rrs, wouldBeBlockedBy) } else { - log.Errorf("intel: failed to create TXT RR for block reason: %s", err) + log.Tracer(ctx).Errorf("intel: failed to create TXT RR for block reason: %s", err) } } } diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index dc0cde3d..2b8f77e7 100644 --- a/nameserver/nameserver.go +++ b/nameserver/nameserver.go @@ -3,7 +3,6 @@ package nameserver import ( "context" "errors" - "fmt" "net" "strings" @@ -28,11 +27,10 @@ var ( dnsServer *dns.Server listenAddress = "0.0.0.0:53" - localhostRRs []dns.RR ) func init() { - module = modules.Register("nameserver", prep, start, stop, "core", "resolver") + module = modules.Register("nameserver", nil, start, stop, "core", "resolver") subsystems.Register( "dns", "Secure DNS", @@ -43,22 +41,6 @@ func init() { ) } -func prep() error { - localhostIPv4, err := dns.NewRR("localhost. 17 IN A 127.0.0.1") - if err != nil { - return err - } - - localhostIPv6, err := dns.NewRR("localhost. 17 IN AAAA ::1") - if err != nil { - return err - } - - localhostRRs = []dns.RR{localhostIPv4, localhostIPv6} - - return nil -} - func start() error { dnsServer = &dns.Server{Addr: listenAddress, Net: "udp"} dns.HandleFunc(".", handleRequestAsWorker) @@ -89,12 +71,6 @@ func stop() error { return nil } -func returnServerFailure(w dns.ResponseWriter, query *dns.Msg) { - m := new(dns.Msg) - m.SetRcode(query, dns.RcodeServerFailure) - _ = writeDNSResponse(w, m) -} - func handleRequestAsWorker(w dns.ResponseWriter, query *dns.Msg) { err := module.RunWorker("dns request", func(ctx context.Context) error { return handleRequest(ctx, w, query) @@ -104,86 +80,80 @@ func handleRequestAsWorker(w dns.ResponseWriter, query *dns.Msg) { } } -func handleRequest(ctx context.Context, w dns.ResponseWriter, query *dns.Msg) error { //nolint:gocognit // TODO - // only process first question, that's how everyone does it. - question := query.Question[0] +func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) error { //nolint:gocognit // TODO + // Only process first question, that's how everyone does it. + question := request.Question[0] q := &resolver.Query{ FQDN: question.Name, QType: dns.Type(question.Qtype), } - // return with server failure if offline - if netenv.GetOnlineStatus() == netenv.StatusOffline && - !netenv.IsConnectivityDomain(q.FQDN) { - log.Tracer(ctx).Debugf("resolver: not resolving %s, device is offline", q.FQDN) - returnServerFailure(w, query) - return nil - } - - // check class - if question.Qclass != dns.ClassINET { - // we only serve IN records, return nxdomain - log.Warningf("nameserver: only IN record requests are supported but received Qclass %d, returning NXDOMAIN", question.Qclass) - sendResponse(w, query, 0, "qclass not served", nsutil.Refused()) - return nil - } - - // handle request for localhost - if strings.HasSuffix(q.FQDN, "localhost.") { - m := new(dns.Msg) - m.SetReply(query) - m.Answer = localhostRRs - if err := writeDNSResponse(w, m); err != nil { - log.Warningf("nameserver: failed to handle request to %s: %s", q.FQDN, err) - } - return nil - } - - // get remote address + // Get remote address of request. remoteAddr, ok := w.RemoteAddr().(*net.UDPAddr) if !ok { log.Warningf("nameserver: failed to get remote address of request for %s%s, ignoring", q.FQDN, q.QType) return nil } - // check if the request is local - local, err := netenv.IsMyIP(remoteAddr.IP) - if err != nil { - log.Warningf("nameserver: failed to check if request for %s%s is local: %s", q.FQDN, q.QType, err) - return nil - } - if !local { - log.Warningf("nameserver: external request for %s%s, ignoring", q.FQDN, q.QType) - return nil - } - - // check if valid domain name - if !netutils.IsValidFqdn(q.FQDN) { - log.Debugf("nameserver: domain name %s is invalid, returning nxdomain", q.FQDN) - sendResponse(w, query, 0, "invalid FQDN", nsutil.Refused()) - return nil - } - - // start tracer + // Start context tracer for context-aware logging. ctx, tracer := log.AddTracer(ctx) defer tracer.Submit() - tracer.Tracef("nameserver: handling new request for %s%s from %s:%d, getting connection", q.FQDN, q.QType, remoteAddr.IP, remoteAddr.Port) + tracer.Tracef("nameserver: handling new request for %s%s from %s:%d", q.FQDN, q.QType, remoteAddr.IP, remoteAddr.Port) - // TODO: if there are 3 request for the same domain/type in a row, delete all caches of that domain + // Setup quick reply function. + reply := func(responder nsutil.Responder, rrProviders ...nsutil.RRProvider) error { + return sendResponse(ctx, w, request, responder, rrProviders...) + } - // get connection + // 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) + return reply(nsutil.ServerFailure("resolving disabled, device is offline")) + } + + // Check the Query Class. + if question.Qclass != dns.ClassINET { + // we only serve IN records, return nxdomain + tracer.Warningf("nameserver: only IN record requests are supported but received Qclass %d, returning NXDOMAIN", question.Qclass) + return reply(nsutil.Refused("unsupported qclass")) + } + + // Handle request for localhost. + if strings.HasSuffix(q.FQDN, "localhost.") { + return reply(nsutil.Localhost("")) + } + + // Authenticate request - only requests from the local host, but with any of its IPs, are allowed. + local, err := netenv.IsMyIP(remoteAddr.IP) + if err != nil { + tracer.Warningf("nameserver: failed to check if request for %s%s is local: %s", q.FQDN, q.QType, err) + return nil // Do no reply, drop request immediately. + } + if !local { + tracer.Warningf("nameserver: external request for %s%s, ignoring", q.FQDN, q.QType) + return nil // Do no reply, drop request immediately. + } + + // Validate domain name. + if !netutils.IsValidFqdn(q.FQDN) { + tracer.Debugf("nameserver: domain name %s is invalid, refusing", q.FQDN) + return reply(nsutil.Refused("invalid domain")) + } + + // Get connection for this request. This identifies the process behind the request. conn := network.NewConnectionFromDNSRequest(ctx, q.FQDN, nil, packet.IPv4, remoteAddr.IP, uint16(remoteAddr.Port)) - // once we decided on the connection we might need to save it to the database - // so we defer that check right now. + // Once we decided on the connection we might need to save it to the database, + // so we defer that check for now. defer func() { switch conn.Verdict { - // we immediately save blocked, dropped or failed verdicts so - // the pop up in the UI. + // We immediately save blocked, dropped or failed verdicts so + // they pop up in the UI. case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: conn.Save() - // for undecided or accepted connections we don't save them yet because + // For undecided or accepted connections we don't save them yet, because // that will happen later anyway. case network.VerdictUndecided, network.VerdictAccept, network.VerdictRerouteToNameserver, network.VerdictRerouteToTunnel: @@ -194,104 +164,72 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, query *dns.Msg) er } }() - // TODO: this has been obsoleted due to special profiles - if conn.Process().Profile() == nil { - tracer.Infof("nameserver: failed to find process for request %s, returning NXDOMAIN", conn) - // NOTE(ppacher): saving unknown process connection might end up in a lot of - // processes. Consider disabling that via config. - conn.Failed("Unknown process") - sendResponse(w, query, conn.Verdict, conn.Reason, conn.ReasonContext) - return nil - } - - // save security level to query - q.SecurityLevel = conn.Process().Profile().SecurityLevel() - - // check profile before we even get intel and rr + // Check request with the privacy filter before resolving. firewall.DecideOnConnection(ctx, conn, nil) + // Check if there is Verdict to act upon. switch conn.Verdict { - case network.VerdictBlock: - tracer.Infof("nameserver: %s blocked, returning nxdomain", conn) - sendResponse(w, query, conn.Verdict, conn.Reason, conn.ReasonContext) - return nil - case network.VerdictDrop, network.VerdictFailed: - tracer.Infof("nameserver: %s dropped, not replying", conn) - return nil + case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: + tracer.Infof("nameserver: request for %s from %s %s", q.ID(), conn.Process(), conn.Verdict.Verb()) + return reply(conn, conn) } - // the firewall now decided on the connection and set it to accept - // If we have a reason context and that context implements nsutil.Responder - // we may need to responde with something else. + // Check if there is a responder from the firewall. + // In special cases, the firewall might want to respond the query itself. // A reason for this might be that the request is sink-holed to a forced - // ip address in which case we "Accept" it but handle the resolving - // differently. + // IP address in which case we "accept" it, but let the firewall handle + // the resolving as it wishes. if responder, ok := conn.ReasonContext.(nsutil.Responder); ok { - tracer.Infof("nameserver: %s handing over to reason-responder: %s", q.FQDN, conn.Reason) - reply := responder.ReplyWithDNS(query, conn.Reason, conn.ReasonContext) - if err := w.WriteMsg(reply); err != nil { - tracer.Warningf("nameserver: failed to return response %s%s to %s: %s", q.FQDN, q.QType, conn.Process(), err) - } else { - tracer.Debugf("nameserver: returning response %s%s to %s", q.FQDN, q.QType, conn.Process()) - } - - // save dns request as open + // Save the request as open, as we don't know if there will be a connection or not. network.SaveOpenDNSRequest(conn) - return nil + tracer.Infof("nameserver: handing over request for %s to filter responder: %s", q.ID(), conn.Reason) + return reply(responder) } - // resolve + // Save security level to query, so that the resolver can react to configuration. + q.SecurityLevel = conn.Process().Profile().SecurityLevel() + + // Resolve request. rrCache, err := resolver.Resolve(ctx, q) if err != nil { - // TODO: analyze nxdomain requests, malware could be trying DGA-domains - tracer.Debugf("nameserver: %s requested %s%s: %s", conn.Process(), q.FQDN, q.QType, err) - - if errors.Is(err, resolver.ErrBlocked) { - conn.Block(err.Error()) - } else { - conn.Failed("failed to resolve: " + err.Error()) + // React to special errors. + switch { + case errors.Is(err, resolver.ErrNotFound): + return reply(nsutil.NxDomain(""), nil) + case errors.Is(err, resolver.ErrBlocked): + return reply(nsutil.ZeroIP(""), nil) + case errors.Is(err, resolver.ErrLocalhost): + return reply(nsutil.Localhost(""), nil) + default: + return reply(nsutil.ServerFailure("internal error: "+err.Error()), nil) } - - sendResponse(w, query, conn.Verdict, conn.Reason, conn.ReasonContext) - return nil } tracer.Trace("nameserver: deciding on resolved dns") rrCache = firewall.DecideOnResolvedDNS(ctx, conn, q, rrCache) if rrCache == nil { - sendResponse(w, query, conn.Verdict, conn.Reason, conn.ReasonContext) - return nil - } + // Check again if there is a responder from the firewall. + if responder, ok := conn.ReasonContext.(nsutil.Responder); ok { + // Save the request as open, as we don't know if there will be a connection or not. + network.SaveOpenDNSRequest(conn) - // reply to query - m := new(dns.Msg) - m.SetReply(query) - m.Answer = rrCache.Answer - m.Ns = rrCache.Ns - m.Extra = rrCache.Extra - - if err := writeDNSResponse(w, m); err != nil { - tracer.Warningf("nameserver: failed to return response %s%s to %s: %s", q.FQDN, q.QType, conn.Process(), err) - } else { - tracer.Debugf("nameserver: returning response %s%s to %s", q.FQDN, q.QType, conn.Process()) - } - - // save dns request as open - network.SaveOpenDNSRequest(conn) - - return nil -} - -func writeDNSResponse(w dns.ResponseWriter, m *dns.Msg) (err error) { - defer func() { - // recover from panic - if panicErr := recover(); panicErr != nil { - err = fmt.Errorf("panic: %s", panicErr) - log.Warningf("nameserver: panic caused by this msg: %#v", m) + tracer.Infof("nameserver: handing over request for %s to filter responder: %s", q.ID(), conn.Reason) + return reply(responder) } - }() - err = w.WriteMsg(m) - return + // Request was blocked by the firewall. + switch conn.Verdict { + case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: + tracer.Infof("nameserver: request for %s from %s %s", q.ID(), conn.Process(), conn.Verdict.Verb()) + return reply(conn, conn) + } + } + + // Save dns request as open. + defer network.SaveOpenDNSRequest(conn) + + // Reply with successful response. + tracer.Infof("nameserver: returning %s response %s to %s", conn.Verdict.Verb(), q.ID(), conn.Process()) + return reply(rrCache, conn, rrCache) } diff --git a/nameserver/nsutil/nsutil.go b/nameserver/nsutil/nsutil.go index a43bf26c..cd42daba 100644 --- a/nameserver/nsutil/nsutil.go +++ b/nameserver/nsutil/nsutil.go @@ -1,6 +1,10 @@ package nsutil import ( + "context" + "fmt" + "strings" + "github.com/miekg/dns" "github.com/safing/portbase/log" ) @@ -13,35 +17,35 @@ import ( type Responder interface { // ReplyWithDNS is called when a DNS response to a DNS message is // crafted because the request is either denied or blocked. - ReplyWithDNS(query *dns.Msg, reason string, reasonCtx interface{}) *dns.Msg + ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns.Msg } // RRProvider defines the interface that any block/deny reason interface // may implement to support adding additional DNS resource records to // the DNS responses extra (additional) section. type RRProvider interface { - // GetExtraRR is called when a DNS response to a DNS message is + // GetExtraRRs is called when a DNS response to a DNS message is // crafted because the request is either denied or blocked. - GetExtraRR(query *dns.Msg, reason string, reasonCtx interface{}) []dns.RR + GetExtraRRs(ctx context.Context, request *dns.Msg) []dns.RR } // ResponderFunc is a convenience type to use a function // directly as a Responder. -type ResponderFunc func(query *dns.Msg, reason string, reasonCtx interface{}) *dns.Msg +type ResponderFunc func(ctx context.Context, request *dns.Msg) *dns.Msg // ReplyWithDNS implements the Responder interface and calls rf. -func (rf ResponderFunc) ReplyWithDNS(query *dns.Msg, reason string, reasonCtx interface{}) *dns.Msg { - return rf(query, reason, reasonCtx) +func (rf ResponderFunc) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns.Msg { + return rf(ctx, request) } // ZeroIP is a ResponderFunc than replies with either 0.0.0.0 or :: for // each A or AAAA question respectively. -func ZeroIP() ResponderFunc { - return func(query *dns.Msg, _ string, _ interface{}) *dns.Msg { - m := new(dns.Msg) +func ZeroIP(msg string) ResponderFunc { + return func(ctx context.Context, request *dns.Msg) *dns.Msg { + reply := new(dns.Msg) hasErr := false - for _, question := range query.Question { + for _, question := range request.Question { var rr dns.RR var err error @@ -53,40 +57,110 @@ func ZeroIP() ResponderFunc { } if err != nil { - log.Errorf("nameserver: failed to create zero-ip response for %s: %s", question.Name, err) + log.Tracer(ctx).Errorf("nameserver: failed to create zero-ip response for %s: %s", question.Name, err) hasErr = true } else { - m.Answer = append(m.Answer, rr) + reply.Answer = append(reply.Answer, rr) } } - if hasErr && len(m.Answer) == 0 { - m.SetRcode(query, dns.RcodeServerFailure) - } else { - m.SetRcode(query, dns.RcodeSuccess) + switch { + case hasErr && len(reply.Answer) == 0: + reply.SetRcode(request, dns.RcodeServerFailure) + case len(reply.Answer) == 0: + reply.SetRcode(request, dns.RcodeNameError) + default: + reply.SetRcode(request, dns.RcodeSuccess) } - return m + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + + return reply + } +} + +func Localhost(msg string) ResponderFunc { + return func(ctx context.Context, request *dns.Msg) *dns.Msg { + reply := new(dns.Msg) + hasErr := false + + for _, question := range request.Question { + var rr dns.RR + var err error + + switch question.Qtype { + case dns.TypeA: + rr, err = dns.NewRR("localhost. 0 IN A 127.0.0.1") + case dns.TypeAAAA: + rr, err = dns.NewRR("localhost. 0 IN AAAA ::1") + } + + if err != nil { + log.Tracer(ctx).Errorf("nameserver: failed to create localhost response for %s: %s", question.Name, err) + hasErr = true + } else { + reply.Answer = append(reply.Answer, rr) + } + } + + switch { + case hasErr && len(reply.Answer) == 0: + reply.SetRcode(request, dns.RcodeServerFailure) + case len(reply.Answer) == 0: + reply.SetRcode(request, dns.RcodeNameError) + default: + reply.SetRcode(request, dns.RcodeSuccess) + } + + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + + return reply } } // NxDomain returns a ResponderFunc that replies with NXDOMAIN. -func NxDomain() ResponderFunc { - return func(query *dns.Msg, _ string, _ interface{}) *dns.Msg { - return new(dns.Msg).SetRcode(query, dns.RcodeNameError) +func NxDomain(msg string) ResponderFunc { + return func(ctx context.Context, request *dns.Msg) *dns.Msg { + reply := new(dns.Msg).SetRcode(request, dns.RcodeNameError) + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + return reply } } // Refused returns a ResponderFunc that replies with REFUSED. -func Refused() ResponderFunc { - return func(query *dns.Msg, _ string, _ interface{}) *dns.Msg { - return new(dns.Msg).SetRcode(query, dns.RcodeRefused) +func Refused(msg string) ResponderFunc { + return func(ctx context.Context, request *dns.Msg) *dns.Msg { + reply := new(dns.Msg).SetRcode(request, dns.RcodeRefused) + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + return reply } } -// ServeFail returns a ResponderFunc that replies with SERVFAIL. -func ServeFail() ResponderFunc { - return func(query *dns.Msg, _ string, _ interface{}) *dns.Msg { - return new(dns.Msg).SetRcode(query, dns.RcodeServerFailure) +// ServerFailure returns a ResponderFunc that replies with SERVFAIL. +func ServerFailure(msg string) ResponderFunc { + return func(ctx context.Context, request *dns.Msg) *dns.Msg { + reply := new(dns.Msg).SetRcode(request, dns.RcodeServerFailure) + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + return reply + } +} + +func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { + return dns.NewRR(fmt.Sprintf( + `%s.portmaster. 0 IN TXT "%s"`, + strings.ToLower(level.String()), + msg, + )) +} + +func AddMessageToReply(ctx context.Context, reply *dns.Msg, level log.Severity, msg string) { + if msg != "" { + rr, err := MakeMessageRecord(level, msg) + if err != nil { + log.Tracer(ctx).Warningf("nameserver: failed to add message to reply: %s", err) + return + } + + reply.Extra = append(reply.Extra, rr) } } diff --git a/nameserver/response.go b/nameserver/response.go index 17c63964..0780edf0 100644 --- a/nameserver/response.go +++ b/nameserver/response.go @@ -1,36 +1,55 @@ package nameserver import ( + "context" + "fmt" + "github.com/miekg/dns" "github.com/safing/portbase/log" "github.com/safing/portmaster/nameserver/nsutil" - "github.com/safing/portmaster/network" ) -// sendResponse sends a response to query using w. If reasonCtx is not -// nil and implements either the Responder or RRProvider interface then -// those functions are used to craft a DNS response. If reasonCtx is nil -// or does not implement the Responder interface and verdict is not set -// to failed a ZeroIP response will be sent. If verdict is set to failed -// then a ServFail will be sent instead. -func sendResponse(w dns.ResponseWriter, query *dns.Msg, verdict network.Verdict, reason string, reasonCtx interface{}) { - responder, ok := reasonCtx.(nsutil.Responder) - if !ok { - if verdict == network.VerdictFailed { - responder = nsutil.ServeFail() - } else { - responder = nsutil.ZeroIP() - } +// sendResponse sends a response to query using w. The response message is +// created by responder. If addExtraRRs is not nil and implements the +// RRProvider interface then it will be also used to add more RRs in the +// extra section. +func sendResponse( + ctx context.Context, + w dns.ResponseWriter, + request *dns.Msg, + responder nsutil.Responder, + rrProviders ...nsutil.RRProvider, +) error { + // Have the Responder craft a DNS reply. + reply := responder.ReplyWithDNS(ctx, request) + if reply == nil { + // Dropping query. + return nil } - reply := responder.ReplyWithDNS(query, reason, reasonCtx) - - if extra, ok := reasonCtx.(nsutil.RRProvider); ok { - rrs := extra.GetExtraRR(query, reason, reasonCtx) + // Add extra RRs through a custom RRProvider. + for _, rrProvider := range rrProviders { + rrs := rrProvider.GetExtraRRs(ctx, request) reply.Extra = append(reply.Extra, rrs...) } + // Write reply. if err := writeDNSResponse(w, reply); err != nil { - log.Errorf("nameserver: failed to send response: %s", err) + return fmt.Errorf("nameserver: failed to send response: %w", err) } + + return nil +} + +func writeDNSResponse(w dns.ResponseWriter, m *dns.Msg) (err error) { + defer func() { + // recover from panic + if panicErr := recover(); panicErr != nil { + err = fmt.Errorf("panic: %s", panicErr) + log.Warningf("nameserver: panic caused by this msg: %#v", m) + } + }() + + err = w.WriteMsg(m) + return } diff --git a/network/dns.go b/network/dns.go index d5f71faa..de46d8de 100644 --- a/network/dns.go +++ b/network/dns.go @@ -2,10 +2,14 @@ package network import ( "context" + "fmt" "strconv" "sync" "time" + "github.com/miekg/dns" + "github.com/safing/portbase/log" + "github.com/safing/portmaster/nameserver/nsutil" "github.com/safing/portmaster/process" ) @@ -88,3 +92,48 @@ func writeOpenDNSRequestsToDB() { conn.Unlock() } } + +// ReplyWithDNS creates a new reply to the given request with the data from the RRCache, and additional informational records. +func (conn *Connection) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns.Msg { + // Select request responder. + switch conn.Verdict { + case VerdictBlock: + return nsutil.ZeroIP("").ReplyWithDNS(ctx, request) + case VerdictDrop: + return nil // Do not respond to request. + case VerdictFailed: + 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") + return reply + } +} + +// GetExtraRRs returns a slice of RRs with additional informational records. +func (conn *Connection) GetExtraRRs(ctx context.Context, request *dns.Msg) []dns.RR { + // Select level to add the verdict record with. + var level log.Severity + switch conn.Verdict { + case VerdictFailed: + level = log.ErrorLevel + default: + level = log.InfoLevel + } + + // Create resource record with verdict and reason. + rr, err := nsutil.MakeMessageRecord(level, fmt.Sprintf("%s: %s", conn.Verdict.Verb(), conn.Reason)) + if err != nil { + log.Tracer(ctx).Warningf("filter: failed to add informational record to reply: %s", err) + return nil + } + extra := []dns.RR{rr} + + // Add additional records from ReasonContext. + if rrProvider, ok := conn.ReasonContext.(nsutil.RRProvider); ok { + rrs := rrProvider.GetExtraRRs(ctx, request) + extra = append(extra, rrs...) + } + + return extra +} diff --git a/network/status.go b/network/status.go index c0930acc..149434ee 100644 --- a/network/status.go +++ b/network/status.go @@ -39,6 +39,30 @@ func (v Verdict) String() string { } } +// Verb returns the verdict as a past tense verb. +func (v Verdict) Verb() string { + switch v { + case VerdictUndecided: + return "undecided" + case VerdictUndeterminable: + return "undeterminable" + case VerdictAccept: + return "accepted" + case VerdictBlock: + return "blocked" + case VerdictDrop: + return "dropped" + case VerdictRerouteToNameserver: + return "rerouted to nameserver" + case VerdictRerouteToTunnel: + return "rerouted to tunnel" + case VerdictFailed: + return "failed" + default: + return "invalid" + } +} + // Packer Directions const ( Inbound = true diff --git a/resolver/rrcache.go b/resolver/rrcache.go index da1bd0a0..d9ada8d3 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -28,6 +28,7 @@ type RRCache struct { Server string // constant ServerScope int8 // constant + ServerInfo string // constant servedFromCache bool // mutable requestingNew bool // mutable @@ -246,3 +247,61 @@ func (rrCache *RRCache) ShallowCopy() *RRCache { FilteredEntries: rrCache.FilteredEntries, } } + +// ReplyWithDNS creates a new reply to the given query with the data from the RRCache, and additional informational records. +func (rrCache *RRCache) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns.Msg { + // 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() { + reply.Rcode = dns.RcodeNameError + } + + return reply +} + +// GetExtraRRs returns a slice of RRs with additional informational records. +func (rrCache *RRCache) GetExtraRRs(ctx context.Context, query *dns.Msg) (extra []dns.RR) { + // Add cache status and source of data. + if rrCache.servedFromCache { + extra = addExtra(ctx, extra, log.InfoLevel, "served from cache, resolved by "+rrCache.ServerInfo) + } else { + extra = addExtra(ctx, extra, log.InfoLevel, "freshly resolved by "+rrCache.ServerInfo) + } + + // Add expiry and cache information. + if rrCache.Expired() { + extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("record expired since %s, requesting new", time.Since(time.Unix(rrCache.TTL, 0)))) + } else { + extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("record valid for %s", time.Until(time.Unix(rrCache.TTL, 0)))) + } + if rrCache.requestingNew { + extra = addExtra(ctx, extra, log.InfoLevel, "async request to refresh the cache has been started") + } + + // Add information about filtered entries. + if rrCache.Filtered { + if len(rrCache.FilteredEntries) > 1 { + extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("%d records have been filtered", len(rrCache.FilteredEntries))) + } else { + extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("%d record has been filtered", len(rrCache.FilteredEntries))) + } + } + + return extra +} + +func addExtra(ctx context.Context, extra []dns.RR, level log.Severity, msg string) []dns.RR { + rr, err := nsutil.MakeMessageRecord(level, msg) + if err != nil { + log.Tracer(ctx).Warningf("resolver: failed to add informational record to reply: %s", err) + return extra + } + extra = append(extra, rr) + return extra +} From 1b11d1589b0a342421ef44c2825f96d21a446aac Mon Sep 17 00:00:00 2001 From: Daniel Date: Tue, 22 Sep 2020 15:30:21 +0200 Subject: [PATCH 03/22] Add ServerInfo to resolvers and caches --- resolver/namerecord.go | 1 + resolver/resolver-env.go | 2 ++ resolver/resolver-mdns.go | 12 +++++++++++- resolver/resolver-plain.go | 1 + resolver/resolver-tcp.go | 1 + resolver/resolver.go | 1 + resolver/resolvers.go | 7 +++++++ resolver/rrcache.go | 5 +++++ 8 files changed, 29 insertions(+), 1 deletion(-) diff --git a/resolver/namerecord.go b/resolver/namerecord.go index 2c240327..f277c435 100644 --- a/resolver/namerecord.go +++ b/resolver/namerecord.go @@ -35,6 +35,7 @@ type NameRecord struct { Server string ServerScope int8 + ServerInfo string } func makeNameRecordKey(domain string, question string) string { diff --git a/resolver/resolver-env.go b/resolver/resolver-env.go index 4a8caa31..7cdbc008 100644 --- a/resolver/resolver-env.go +++ b/resolver/resolver-env.go @@ -23,6 +23,7 @@ var ( Server: ServerSourceEnv, ServerType: ServerTypeEnv, ServerIPScope: netutils.SiteLocal, + ServerInfo: "Portmaster environment", Source: ServerSourceEnv, Conn: &envResolverConn{}, } @@ -114,6 +115,7 @@ func (er *envResolverConn) makeRRCache(q *Query, answers []dns.RR) *RRCache { Extra: []dns.RR{internalSpecialUseComment}, // Always add comment about this TLD. Server: envResolver.Server, ServerScope: envResolver.ServerIPScope, + ServerInfo: envResolver.ServerInfo, } } diff --git a/resolver/resolver-mdns.go b/resolver/resolver-mdns.go index 9a3732e7..bd965258 100644 --- a/resolver/resolver-mdns.go +++ b/resolver/resolver-mdns.go @@ -34,6 +34,7 @@ var ( Server: ServerSourceMDNS, ServerType: ServerTypeDNS, ServerIPScope: netutils.SiteLocal, + ServerInfo: "mDNS resolver", Source: ServerSourceMDNS, Conn: &mDNSResolverConn{}, } @@ -203,6 +204,7 @@ func handleMDNSMessages(ctx context.Context, messages chan *dns.Msg) error { Question: dns.Type(question.Qtype), Server: mDNSResolver.Server, ServerScope: mDNSResolver.ServerIPScope, + ServerInfo: mDNSResolver.ServerInfo, } } } @@ -304,6 +306,7 @@ func handleMDNSMessages(ctx context.Context, messages chan *dns.Msg) error { Answer: []dns.RR{v}, Server: mDNSResolver.Server, ServerScope: mDNSResolver.ServerIPScope, + ServerInfo: mDNSResolver.ServerInfo, } rrCache.Clean(minMDnsTTL) err := rrCache.Save() @@ -416,7 +419,14 @@ func queryMulticastDNS(ctx context.Context, q *Query) (*RRCache, error) { } } - return nil, ErrNotFound + // Respond with NXDomain. + return &RRCache{ + Domain: q.FQDN, + Question: q.QType, + Server: mDNSResolver.Server, + ServerScope: mDNSResolver.ServerIPScope, + ServerInfo: mDNSResolver.ServerInfo, + }, nil } func cleanSavedQuestions() { diff --git a/resolver/resolver-plain.go b/resolver/resolver-plain.go index 4417ebc1..a64dc314 100644 --- a/resolver/resolver-plain.go +++ b/resolver/resolver-plain.go @@ -86,6 +86,7 @@ func (pr *PlainResolver) Query(ctx context.Context, q *Query) (*RRCache, error) Extra: reply.Extra, Server: pr.resolver.Server, ServerScope: pr.resolver.ServerIPScope, + ServerInfo: pr.resolver.ServerInfo, } // TODO: check if reply.Answer is valid diff --git a/resolver/resolver-tcp.go b/resolver/resolver-tcp.go index f2e1e5b7..b3eb35e9 100644 --- a/resolver/resolver-tcp.go +++ b/resolver/resolver-tcp.go @@ -51,6 +51,7 @@ func (ifq *InFlightQuery) MakeCacheRecord(reply *dns.Msg) *RRCache { Extra: reply.Extra, Server: ifq.Resolver.Server, ServerScope: ifq.Resolver.ServerIPScope, + ServerInfo: ifq.Resolver.ServerInfo, } } diff --git a/resolver/resolver.go b/resolver/resolver.go index 1cf37409..d7f21555 100644 --- a/resolver/resolver.go +++ b/resolver/resolver.go @@ -60,6 +60,7 @@ type Resolver struct { ServerIP net.IP ServerIPScope int8 ServerPort uint16 + ServerInfo string // Special Options VerifyDomain string diff --git a/resolver/resolvers.go b/resolver/resolvers.go index da5c30ba..906b38ea 100644 --- a/resolver/resolvers.go +++ b/resolver/resolvers.go @@ -128,6 +128,13 @@ func createResolver(resolverURL, source string) (*Resolver, bool, error) { UpstreamBlockDetection: blockType, } + u.RawQuery = "" // Remove options from parsed URL + if new.Name != "" { + new.ServerInfo = fmt.Sprintf("%s (%s, from %s)", new.Name, u, source) + } else { + new.ServerInfo = fmt.Sprintf("%s (from %s)", u, source) + } + new.Conn = resolverConnFactory(new) return new, false, nil } diff --git a/resolver/rrcache.go b/resolver/rrcache.go index d9ada8d3..24866455 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -1,6 +1,7 @@ package resolver import ( + "context" "fmt" "math/rand" "net" @@ -8,6 +9,7 @@ import ( "time" "github.com/safing/portbase/log" + "github.com/safing/portmaster/nameserver/nsutil" "github.com/safing/portmaster/netenv" "github.com/miekg/dns" @@ -130,6 +132,7 @@ func (rrCache *RRCache) ToNameRecord() *NameRecord { TTL: rrCache.TTL, Server: rrCache.Server, ServerScope: rrCache.ServerScope, + ServerInfo: rrCache.ServerInfo, } // stringify RR entries @@ -176,6 +179,7 @@ func GetRRCache(domain string, question dns.Type) (*RRCache, error) { rrCache.Server = nameRecord.Server rrCache.ServerScope = nameRecord.ServerScope + rrCache.ServerInfo = nameRecord.ServerInfo rrCache.servedFromCache = true return rrCache, nil } @@ -239,6 +243,7 @@ func (rrCache *RRCache) ShallowCopy() *RRCache { Server: rrCache.Server, ServerScope: rrCache.ServerScope, + ServerInfo: rrCache.ServerInfo, updated: rrCache.updated, servedFromCache: rrCache.servedFromCache, From 3c6cd69f509afb6e1dfc48289b04a851d579d0d3 Mon Sep 17 00:00:00 2001 From: Daniel Date: Tue, 22 Sep 2020 15:31:15 +0200 Subject: [PATCH 04/22] Add support for default ports nameserver config --- resolver/resolvers.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/resolver/resolvers.go b/resolver/resolvers.go index 906b38ea..4bb6d205 100644 --- a/resolver/resolvers.go +++ b/resolver/resolvers.go @@ -90,6 +90,16 @@ func createResolver(resolverURL, source string) (*Resolver, bool, error) { return nil, false, fmt.Errorf("invalid resolver IP") } + // Add default port for scheme if it is missing. + if u.Port() == "" { + switch u.Scheme { + case ServerTypeDNS, ServerTypeTCP: + u.Host += ":53" + case ServerTypeDoT: + u.Host += ":853" + } + } + scope := netutils.ClassifyIP(ip) if scope == netutils.HostLocal { return nil, true, nil // skip From bd8d047428ae0899f5ab6c6985118e3703b08b05 Mon Sep 17 00:00:00 2001 From: Daniel Date: Tue, 22 Sep 2020 16:07:51 +0200 Subject: [PATCH 05/22] Retry NSDomain queries, if wanted --- resolver/resolve.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/resolver/resolve.go b/resolver/resolve.go index 6234a345..d701713b 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -358,6 +358,10 @@ resolveLoop: // Defensive: This should normally not happen. continue } + // Check if we got NXDomain and whether we should try another resolver. + if rrCache.IsNXDomain() && tryAll { + continue + } break resolveLoop } } From 34247b1d82faf7bc08004422360e327f609fc7ac Mon Sep 17 00:00:00 2001 From: Daniel Date: Tue, 22 Sep 2020 16:08:17 +0200 Subject: [PATCH 06/22] Add hearbeat check to TCP resolver --- resolver/resolver-tcp.go | 91 ++++++++++++++++++++++++++++++++++------ 1 file changed, 79 insertions(+), 12 deletions(-) diff --git a/resolver/resolver-tcp.go b/resolver/resolver-tcp.go index b3eb35e9..c777b71c 100644 --- a/resolver/resolver-tcp.go +++ b/resolver/resolver-tcp.go @@ -3,6 +3,8 @@ package resolver import ( "context" "crypto/tls" + "errors" + "io" "net" "sync/atomic" "time" @@ -26,6 +28,8 @@ type TCPResolver struct { dnsClient *dns.Client clientStarted *abool.AtomicBool + clientHeartbeat chan struct{} + clientCancel func() connInstanceID *uint32 queries chan *dns.Msg inFlightQueries map[uint16]*InFlightQuery @@ -68,10 +72,12 @@ func NewTCPResolver(resolver *Resolver) *TCPResolver { Timeout: defaultConnectTimeout, WriteTimeout: tcpWriteTimeout, }, - connInstanceID: &instanceID, - queries: make(chan *dns.Msg, 100), - inFlightQueries: make(map[uint16]*InFlightQuery), clientStarted: abool.New(), + clientHeartbeat: make(chan struct{}), + clientCancel: func() {}, + connInstanceID: &instanceID, + queries: make(chan *dns.Msg, 1000), + inFlightQueries: make(map[uint16]*InFlightQuery), } } @@ -146,6 +152,7 @@ func (tr *TCPResolver) Query(ctx context.Context, q *Query) (*RRCache, error) { // submit to client inFlight := tr.submitQuery(ctx, q) if inFlight == nil { + tr.checkClientStatus() return nil, ErrTimeout } @@ -153,6 +160,7 @@ func (tr *TCPResolver) Query(ctx context.Context, q *Query) (*RRCache, error) { select { case reply = <-inFlight.Response: case <-time.After(defaultRequestTimeout): + tr.checkClientStatus() return nil, ErrTimeout } @@ -168,6 +176,21 @@ func (tr *TCPResolver) Query(ctx context.Context, q *Query) (*RRCache, error) { return inFlight.MakeCacheRecord(reply), nil } +func (tr *TCPResolver) checkClientStatus() { + // Get client cancel function before waiting in order to not immediately + // cancel a new client. + tr.Lock() + cancelClient := tr.clientCancel + tr.Unlock() + + // Check if the client is alive with the heartbeat, if not shut it down. + select { + case tr.clientHeartbeat <- struct{}{}: + case <-time.After(defaultRequestTimeout): + cancelClient() + } +} + type tcpResolverConnMgr struct { tr *TCPResolver responses chan *dns.Msg @@ -185,8 +208,14 @@ func (tr *TCPResolver) startClient() { } func (mgr *tcpResolverConnMgr) run(workerCtx context.Context) error { - mgr.tr.clientStarted.Set() defer mgr.shutdown() + mgr.tr.clientStarted.Set() + + // Create additional cancel function for this worker. + workerCtx, cancelWorker := context.WithCancel(workerCtx) + mgr.tr.Lock() + mgr.tr.clientCancel = cancelWorker + mgr.tr.Unlock() // connection lifecycle loop for { @@ -314,10 +343,21 @@ func (mgr *tcpResolverConnMgr) establishConnection(workerCtx context.Context) ( log.Debugf("resolver: failed to connect to %s (%s)", mgr.tr.resolver.GetName(), mgr.tr.resolver.ServerAddress) return nil, nil, nil, nil } - connCtx, cancelConnCtx = context.WithCancel(workerCtx) + connCtx, cancelConnCtx = context.WithCancel(context.Background()) connClosing = abool.New() - log.Debugf("resolver: connected to %s (%s)", mgr.tr.resolver.GetName(), conn.RemoteAddr()) + // Get amount of in waiting queries. + mgr.tr.Lock() + waitingQueries := len(mgr.tr.inFlightQueries) + mgr.tr.Unlock() + + // Log that a connection to the resolver was established. + log.Debugf( + "resolver: connected to %s (%s) with %d queries waiting", + mgr.tr.resolver.GetName(), + conn.RemoteAddr(), + waitingQueries, + ) // start reader module.StartServiceWorker("dns client reader", 10*time.Millisecond, func(workerCtx context.Context) error { @@ -349,6 +389,9 @@ func (mgr *tcpResolverConnMgr) queryHandler( //nolint:golint // context.Context for { select { + case <-mgr.tr.clientHeartbeat: + // respond to alive checks + case <-workerCtx.Done(): // module shutdown return false @@ -373,9 +416,7 @@ func (mgr *tcpResolverConnMgr) queryHandler( //nolint:golint // context.Context _ = conn.SetWriteDeadline(time.Now().Add(mgr.tr.dnsClient.WriteTimeout)) err := conn.WriteMsg(msg) if err != nil { - if connClosing.SetToIf(false, true) { - log.Warningf("resolver: write error to %s (%s): %s", mgr.tr.resolver.GetName(), conn.RemoteAddr(), err) - } + mgr.logConnectionError(err, conn, connClosing) return true } @@ -456,11 +497,37 @@ func (mgr *tcpResolverConnMgr) msgReader( for { msg, err := conn.ReadMsg() if err != nil { - if connClosing.SetToIf(false, true) { - log.Warningf("resolver: read error from %s (%s): %s", mgr.tr.resolver.GetName(), conn.RemoteAddr(), err) - } + mgr.logConnectionError(err, conn, connClosing) return nil } mgr.responses <- msg } } + +func (mgr *tcpResolverConnMgr) logConnectionError(err error, conn *dns.Conn, connClosing *abool.AtomicBool) { + // Check if we are the first to see an error. + if connClosing.SetToIf(false, true) { + // Get amount of in flight queries. + mgr.tr.Lock() + inFlightQueries := len(mgr.tr.inFlightQueries) + mgr.tr.Unlock() + + // Log error. + if errors.Is(err, io.EOF) { + log.Debugf( + "resolver: connection to %s (%s) was closed with %d in-flight queries", + mgr.tr.resolver.GetName(), + conn.RemoteAddr(), + inFlightQueries, + ) + } else { + log.Warningf( + "resolver: write error to %s (%s) with %d in-flight queries: %s", + mgr.tr.resolver.GetName(), + conn.RemoteAddr(), + inFlightQueries, + err, + ) + } + } +} From 5df7182b5d755f0fb25dff2a4e3f57b2040f2b40 Mon Sep 17 00:00:00 2001 From: Daniel Date: Wed, 23 Sep 2020 14:11:44 +0200 Subject: [PATCH 07/22] Implement feedback --- firewall/bypassing.go | 2 +- resolver/resolver-tcp.go | 3 ++- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/firewall/bypassing.go b/firewall/bypassing.go index 602fbea2..7416cc93 100644 --- a/firewall/bypassing.go +++ b/firewall/bypassing.go @@ -15,7 +15,7 @@ func PreventBypassing(conn *network.Connection) (endpoints.EPResult, string, nsu if strings.ToLower(conn.Entity.Domain) == "use-application-dns.net." { return endpoints.Denied, "blocked canary domain to prevent enabling of DNS-over-HTTPs", - nsutil.NxDomain("blocked canary domain to prevent enabling of DNS-over-HTTPs") + nsutil.NxDomain("") } return endpoints.NoMatch, "", nil diff --git a/resolver/resolver-tcp.go b/resolver/resolver-tcp.go index c777b71c..54a7a8f5 100644 --- a/resolver/resolver-tcp.go +++ b/resolver/resolver-tcp.go @@ -76,7 +76,7 @@ func NewTCPResolver(resolver *Resolver) *TCPResolver { clientHeartbeat: make(chan struct{}), clientCancel: func() {}, connInstanceID: &instanceID, - queries: make(chan *dns.Msg, 1000), + queries: make(chan *dns.Msg, 100), inFlightQueries: make(map[uint16]*InFlightQuery), } } @@ -187,6 +187,7 @@ func (tr *TCPResolver) checkClientStatus() { select { case tr.clientHeartbeat <- struct{}{}: case <-time.After(defaultRequestTimeout): + log.Warningf("resolver: heartbeat failed for %s dns client, stopping", tr.resolver.GetName()) cancelClient() } } From 12b0ff973d908c8802a5dd370ef454bdbd62bbc9 Mon Sep 17 00:00:00 2001 From: Daniel Date: Wed, 23 Sep 2020 14:12:14 +0200 Subject: [PATCH 08/22] Fix special responders --- nameserver/nameserver.go | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index 2b8f77e7..121141b1 100644 --- a/nameserver/nameserver.go +++ b/nameserver/nameserver.go @@ -167,13 +167,6 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Check request with the privacy filter before resolving. firewall.DecideOnConnection(ctx, conn, nil) - // Check if there is Verdict to act upon. - switch conn.Verdict { - case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: - tracer.Infof("nameserver: request for %s from %s %s", q.ID(), conn.Process(), conn.Verdict.Verb()) - return reply(conn, conn) - } - // Check if there is a responder from the firewall. // In special cases, the firewall might want to respond the query itself. // A reason for this might be that the request is sink-holed to a forced @@ -183,10 +176,17 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Save the request as open, as we don't know if there will be a connection or not. network.SaveOpenDNSRequest(conn) - tracer.Infof("nameserver: handing over request for %s to filter responder: %s", q.ID(), conn.Reason) + tracer.Infof("nameserver: handing over request for %s to special filter responder: %s", q.ID(), conn.Reason) return reply(responder) } + // Check if there is Verdict to act upon. + switch conn.Verdict { + case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: + tracer.Infof("nameserver: request for %s from %s %s", q.ID(), conn.Process(), conn.Verdict.Verb()) + return reply(conn, conn) + } + // Save security level to query, so that the resolver can react to configuration. q.SecurityLevel = conn.Process().Profile().SecurityLevel() From af056780fc9a4a801b734390c11750e2bc4314c0 Mon Sep 17 00:00:00 2001 From: Daniel Date: Wed, 23 Sep 2020 14:12:23 +0200 Subject: [PATCH 09/22] Fix linter errors --- firewall/interception/nfqexp/nfqexp.go | 2 +- intel/block_reason.go | 2 +- nameserver/nsutil/nsutil.go | 9 ++++++++- resolver/resolver-tcp.go | 4 ++-- resolver/rrcache.go | 18 +++++++++--------- 5 files changed, 21 insertions(+), 14 deletions(-) diff --git a/firewall/interception/nfqexp/nfqexp.go b/firewall/interception/nfqexp/nfqexp.go index aa8cc451..4c0d7e45 100644 --- a/firewall/interception/nfqexp/nfqexp.go +++ b/firewall/interception/nfqexp/nfqexp.go @@ -28,7 +28,7 @@ type Queue struct { } // New opens a new nfQueue. -func New(qid uint16, v6 bool) (*Queue, error) { +func New(qid uint16, v6 bool) (*Queue, error) { //nolint:gocognit afFamily := unix.AF_INET if v6 { afFamily = unix.AF_INET6 diff --git a/intel/block_reason.go b/intel/block_reason.go index 266e7140..6ec51cb0 100644 --- a/intel/block_reason.go +++ b/intel/block_reason.go @@ -64,7 +64,7 @@ func (br ListBlockReason) MarshalJSON() ([]byte, error) { }) } -// GetExtraRR implements the nsutil.RRProvider interface +// GetExtraRRs implements the nsutil.RRProvider interface // and adds additional TXT records justifying the reason // the request was blocked. func (br ListBlockReason) GetExtraRRs(ctx context.Context, _ *dns.Msg) []dns.RR { diff --git a/nameserver/nsutil/nsutil.go b/nameserver/nsutil/nsutil.go index cd42daba..7307f763 100644 --- a/nameserver/nsutil/nsutil.go +++ b/nameserver/nsutil/nsutil.go @@ -79,6 +79,7 @@ func ZeroIP(msg string) ResponderFunc { } } +// Localhost is a ResponderFunc than replies with localhost IP addresses. func Localhost(msg string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg) @@ -145,7 +146,9 @@ func ServerFailure(msg string) ResponderFunc { } } -func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { +// MakeMessageRecord creates an informational resource record that can be added +// to the extra section of a reply. +func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { //nolint:interfacer return dns.NewRR(fmt.Sprintf( `%s.portmaster. 0 IN TXT "%s"`, strings.ToLower(level.String()), @@ -153,6 +156,10 @@ func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { )) } +// AddMessageToReply creates an information resource records using +// MakeMessageRecord and immediately adds it the 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 != "" { rr, err := MakeMessageRecord(level, msg) diff --git a/resolver/resolver-tcp.go b/resolver/resolver-tcp.go index 54a7a8f5..ff915b97 100644 --- a/resolver/resolver-tcp.go +++ b/resolver/resolver-tcp.go @@ -239,7 +239,7 @@ func (mgr *tcpResolverConnMgr) run(workerCtx context.Context) error { } // create connection - conn, connClosing, connCtx, cancelConnCtx := mgr.establishConnection(workerCtx) + conn, connClosing, connCtx, cancelConnCtx := mgr.establishConnection() if conn == nil { mgr.failCnt++ continue @@ -324,7 +324,7 @@ func (mgr *tcpResolverConnMgr) waitForWork(workerCtx context.Context) (proceed b return true } -func (mgr *tcpResolverConnMgr) establishConnection(workerCtx context.Context) ( +func (mgr *tcpResolverConnMgr) establishConnection() ( conn *dns.Conn, connClosing *abool.AtomicBool, connCtx context.Context, diff --git a/resolver/rrcache.go b/resolver/rrcache.go index 24866455..0c24f4c8 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -274,35 +274,35 @@ func (rrCache *RRCache) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns func (rrCache *RRCache) GetExtraRRs(ctx context.Context, query *dns.Msg) (extra []dns.RR) { // Add cache status and source of data. if rrCache.servedFromCache { - extra = addExtra(ctx, extra, log.InfoLevel, "served from cache, resolved by "+rrCache.ServerInfo) + extra = addExtra(ctx, extra, "served from cache, resolved by "+rrCache.ServerInfo) } else { - extra = addExtra(ctx, extra, log.InfoLevel, "freshly resolved by "+rrCache.ServerInfo) + extra = addExtra(ctx, extra, "freshly resolved by "+rrCache.ServerInfo) } // Add expiry and cache information. if rrCache.Expired() { - extra = addExtra(ctx, extra, log.InfoLevel, 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, requesting new", time.Since(time.Unix(rrCache.TTL, 0)))) } else { - extra = addExtra(ctx, extra, log.InfoLevel, 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)))) } if rrCache.requestingNew { - extra = addExtra(ctx, extra, log.InfoLevel, "async request to refresh the cache has been started") + extra = addExtra(ctx, extra, "async request to refresh the cache has been started") } // Add information about filtered entries. if rrCache.Filtered { if len(rrCache.FilteredEntries) > 1 { - extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("%d records have been filtered", len(rrCache.FilteredEntries))) + extra = addExtra(ctx, extra, fmt.Sprintf("%d records have been filtered", len(rrCache.FilteredEntries))) } else { - extra = addExtra(ctx, extra, log.InfoLevel, fmt.Sprintf("%d record has been filtered", len(rrCache.FilteredEntries))) + extra = addExtra(ctx, extra, fmt.Sprintf("%d record has been filtered", len(rrCache.FilteredEntries))) } } return extra } -func addExtra(ctx context.Context, extra []dns.RR, level log.Severity, msg string) []dns.RR { - rr, err := nsutil.MakeMessageRecord(level, msg) +func addExtra(ctx context.Context, extra []dns.RR, msg string) []dns.RR { + rr, err := nsutil.MakeMessageRecord(log.InfoLevel, msg) if err != nil { log.Tracer(ctx).Warningf("resolver: failed to add informational record to reply: %s", err) return extra From c856b7372a77cf4b6a8d5a74f7235233545cbb03 Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 10:42:48 +0200 Subject: [PATCH 10/22] Improve handling of expired or failed queries --- resolver/config.go | 2 +- resolver/resolve.go | 70 +++++++++++++++++++++++++++++---------------- resolver/rrcache.go | 5 ++++ 3 files changed, 51 insertions(+), 26 deletions(-) diff --git a/resolver/config.go b/resolver/config.go index e2205728..f90fa625 100644 --- a/resolver/config.go +++ b/resolver/config.go @@ -96,7 +96,7 @@ IP: always use the IP address and _not_ the domain name! Port: - always add the port! + optionally define a custom port Parameters: name: give your DNS Server a name that is used for messages and logs diff --git a/resolver/resolve.go b/resolver/resolve.go index d701713b..004baa66 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -46,7 +46,8 @@ var ( ) const ( - minTTL = 60 // 1 Minute + minTTL = 60 // 1 Minute + refreshTTL = minTTL / 2 minMDnsTTL = 60 // 1 Minute maxTTL = 24 * 60 * 60 // 24 hours ) @@ -130,7 +131,7 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { // check the cache if !q.NoCaching { rrCache = checkCache(ctx, q) - if rrCache != nil { + if rrCache != nil && !rrCache.Expired() { rrCache.MixAnswers() return rrCache, nil } @@ -140,7 +141,7 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { if markRequestFinished == nil { // we waited for another request, recheck the cache! rrCache = checkCache(ctx, q) - if rrCache != nil { + if rrCache != nil && !rrCache.Expired() { rrCache.MixAnswers() return rrCache, nil } @@ -149,17 +150,22 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { } else { // we are the first! defer markRequestFinished() - } } - return resolveAndCache(ctx, q) + return resolveAndCache(ctx, q, rrCache) } func checkCache(ctx context.Context, q *Query) *RRCache { + // Never ask cache for connectivity domains. + if netenv.IsConnectivityDomain(q.FQDN) { + return nil + } + + // Get data from cache. rrCache, err := GetRRCache(q.FQDN, q.QType) - // failed to get from cache + // Return if entry is not in cache. if err != nil { if err != database.ErrNotFound { log.Tracer(ctx).Warningf("resolver: getting RRCache %s%s from database failed: %s", q.FQDN, q.QType.String(), err) @@ -167,21 +173,21 @@ func checkCache(ctx context.Context, q *Query) *RRCache { return nil } - // get resolver that rrCache was resolved with + // Get the resolver that the rrCache was resolved with. resolver := getActiveResolverByIDWithLocking(rrCache.Server) if resolver == nil { log.Tracer(ctx).Debugf("resolver: ignoring RRCache %s%s because source server %s has been removed", q.FQDN, q.QType.String(), rrCache.Server) return nil } - // check compliance of resolver + // Check compliance of the resolver, return if non-compliant. err = resolver.checkCompliance(ctx, q) if err != nil { log.Tracer(ctx).Debugf("resolver: cached entry for %s%s does not comply to query parameters: %s", q.FQDN, q.QType.String(), err) return nil } - // check if we want to reset the cache + // Check if we want to reset the cache for this entry. if shouldResetCache(q) { err := DeleteNameRecord(q.FQDN, q.QType.String()) switch { @@ -195,27 +201,36 @@ func checkCache(ctx context.Context, q *Query) *RRCache { return nil } - // check if expired + // Check if the cache has already expired. + // We still return the cache, if it isn't NXDomain, as it will be used if the + // new query fails. if rrCache.Expired() { - if netenv.IsConnectivityDomain(rrCache.Domain) { - // do not use cache, resolve immediately + if rrCache.IsNXDomain() { return nil } + return rrCache + } + // Check if the cache will expire soon and start an async request. + if rrCache.ExpiresSoon() { + // Set flag that we are refreshing this entry. rrCache.Lock() rrCache.requestingNew = true rrCache.Unlock() log.Tracer(ctx).Tracef( - "resolver: using expired RR from cache (since %s), refreshing async now", - time.Since(time.Unix(rrCache.TTL, 0)), + "resolver: cache for %s will expire in %s, refreshing async now", + q.ID(), + time.Until(time.Unix(rrCache.TTL, 0)), ) // resolve async module.StartWorker("resolve async", func(ctx context.Context) error { - _, err := resolveAndCache(ctx, q) + ctx, tracer := log.AddTracer(ctx) + tracer.Debugf("resolver: resolving %s async", q.ID()) + _, err := resolveAndCache(ctx, q, nil) if err != nil { - log.Warningf("resolver: async query for %s%s failed: %s", q.FQDN, q.QType, err) + tracer.Warningf("resolver: async query for %s failed: %s", q.ID(), err) } return nil }) @@ -290,7 +305,7 @@ retry: } } -func resolveAndCache(ctx context.Context, q *Query) (rrCache *RRCache, err error) { //nolint:gocognit +func resolveAndCache(ctx context.Context, q *Query, oldCache *RRCache) (rrCache *RRCache, err error) { //nolint:gocognit // get resolvers resolvers, tryAll := GetResolversInScope(ctx, q) if len(resolvers) == 0 { @@ -366,23 +381,28 @@ resolveLoop: } } - // check for error + // Post-process errors if err != nil { // tried all resolvers, possibly twice if i > 1 { - return nil, fmt.Errorf("all %d query-compliant resolvers failed, last error: %s", len(resolvers), err) + err = fmt.Errorf("all %d query-compliant resolvers failed, last error: %s", len(resolvers), err) } - return nil, err + } else if rrCache == nil /* defensive */ { + err = ErrNotFound } - // check for result - if rrCache == nil /* defensive */ { - return nil, ErrNotFound + // 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 } - // cache if enabled + // Save the new entry if cache is enabled. if !q.NoCaching { - // persist to database rrCache.Clean(minTTL) err = rrCache.Save() if err != nil { diff --git a/resolver/rrcache.go b/resolver/rrcache.go index 0c24f4c8..df5e019f 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -50,6 +50,11 @@ func (rrCache *RRCache) Expired() bool { return rrCache.TTL <= time.Now().Unix() } +// Expired returns whether the record will expire soon and should already be refreshed. +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() { rrCache.Lock() From 67cdc52fcdfbe34f444a8400f6320222fd3115a1 Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 17:11:29 +0200 Subject: [PATCH 11/22] Implement Feedback --- firewall/bypassing.go | 2 +- nameserver/nsutil/nsutil.go | 40 +++++++++++++++++++++++++++---------- network/dns.go | 6 +++--- 3 files changed, 33 insertions(+), 15 deletions(-) diff --git a/firewall/bypassing.go b/firewall/bypassing.go index 7416cc93..cd811d8c 100644 --- a/firewall/bypassing.go +++ b/firewall/bypassing.go @@ -15,7 +15,7 @@ func PreventBypassing(conn *network.Connection) (endpoints.EPResult, string, nsu if strings.ToLower(conn.Entity.Domain) == "use-application-dns.net." { return endpoints.Denied, "blocked canary domain to prevent enabling of DNS-over-HTTPs", - nsutil.NxDomain("") + nsutil.NxDomain() } return endpoints.NoMatch, "", nil diff --git a/nameserver/nsutil/nsutil.go b/nameserver/nsutil/nsutil.go index 7307f763..d427a376 100644 --- a/nameserver/nsutil/nsutil.go +++ b/nameserver/nsutil/nsutil.go @@ -2,6 +2,7 @@ package nsutil import ( "context" + "errors" "fmt" "strings" @@ -40,7 +41,7 @@ func (rf ResponderFunc) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns // ZeroIP is a ResponderFunc than replies with either 0.0.0.0 or :: for // each A or AAAA question respectively. -func ZeroIP(msg string) ResponderFunc { +func ZeroIP(msgs ...string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg) hasErr := false @@ -73,14 +74,16 @@ func ZeroIP(msg string) ResponderFunc { reply.SetRcode(request, dns.RcodeSuccess) } - AddMessageToReply(ctx, reply, log.InfoLevel, msg) + for _, msg := range msgs { + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + } return reply } } // Localhost is a ResponderFunc than replies with localhost IP addresses. -func Localhost(msg string) ResponderFunc { +func Localhost(msgs ...string) ResponderFunc { return func(ctx context.Context, request *dns.Msg) *dns.Msg { reply := new(dns.Msg) hasErr := false @@ -113,35 +116,43 @@ func Localhost(msg string) ResponderFunc { reply.SetRcode(request, dns.RcodeSuccess) } - AddMessageToReply(ctx, reply, log.InfoLevel, msg) + for _, msg := range msgs { + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + } return reply } } // NxDomain returns a ResponderFunc that replies with NXDOMAIN. -func NxDomain(msg 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) - AddMessageToReply(ctx, reply, log.InfoLevel, msg) + for _, msg := range msgs { + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + } return reply } } // Refused returns a ResponderFunc that replies with REFUSED. -func Refused(msg 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) - AddMessageToReply(ctx, reply, log.InfoLevel, msg) + for _, msg := range msgs { + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + } return reply } } // ServerFailure returns a ResponderFunc that replies with SERVFAIL. -func ServerFailure(msg 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) - AddMessageToReply(ctx, reply, log.InfoLevel, msg) + for _, msg := range msgs { + AddMessageToReply(ctx, reply, log.InfoLevel, msg) + } return reply } } @@ -149,11 +160,18 @@ func ServerFailure(msg string) ResponderFunc { // MakeMessageRecord creates an informational resource record that can be added // to the extra section of a reply. func MakeMessageRecord(level log.Severity, msg string) (dns.RR, error) { //nolint:interfacer - return dns.NewRR(fmt.Sprintf( + rr, err := dns.NewRR(fmt.Sprintf( `%s.portmaster. 0 IN TXT "%s"`, strings.ToLower(level.String()), msg, )) + if err != nil { + return nil, err + } + if rr == nil { + return nil, errors.New("record is nil") + } + return rr, nil } // AddMessageToReply creates an information resource records using diff --git a/network/dns.go b/network/dns.go index de46d8de..c22867ef 100644 --- a/network/dns.go +++ b/network/dns.go @@ -98,13 +98,13 @@ func (conn *Connection) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns // Select request responder. switch conn.Verdict { case VerdictBlock: - return nsutil.ZeroIP("").ReplyWithDNS(ctx, request) + return nsutil.ZeroIP().ReplyWithDNS(ctx, request) case VerdictDrop: return nil // Do not respond to request. case VerdictFailed: - return nsutil.ZeroIP("").ReplyWithDNS(ctx, request) + return nsutil.ZeroIP().ReplyWithDNS(ctx, request) default: - reply := nsutil.ServerFailure("").ReplyWithDNS(ctx, request) + reply := nsutil.ServerFailure().ReplyWithDNS(ctx, request) nsutil.AddMessageToReply(ctx, reply, log.ErrorLevel, "INTERNAL ERROR: incorrect use of network.Connection's DNS Responder") return reply } From 89dfbf72e64c26eeb46d5aea24a6a4d0fca62dfc Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 22:03:02 +0200 Subject: [PATCH 12/22] Final feedback implementation and fixes --- nameserver/nameserver.go | 19 +++++++++++++----- nameserver/nsutil/nsutil.go | 37 ++++++++++++++++------------------ nameserver/response.go | 6 ++++-- network/dns.go | 2 +- resolver/resolve.go | 35 +++++++++++++++++++++----------- resolver/rrcache.go | 40 +++++++++++++++++++++++-------------- 6 files changed, 84 insertions(+), 55 deletions(-) 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 { From 0f2e3cdb2fbe80661525cfee23f865fd20511427 Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 22:09:01 +0200 Subject: [PATCH 13/22] Fix comment for linter --- resolver/rrcache.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/resolver/rrcache.go b/resolver/rrcache.go index ed1944bb..b6a103a8 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -51,7 +51,7 @@ func (rrCache *RRCache) Expired() bool { return rrCache.TTL <= time.Now().Unix() } -// Expired returns whether the record will expire soon and should already be refreshed. +// ExpiresSoon returns whether the record will expire soon and should already be refreshed. func (rrCache *RRCache) ExpiresSoon() bool { return rrCache.TTL <= time.Now().Unix()+refreshTTL } From 00de73d65e2779a9fb2c1cf030ebe237ccc6902e Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 22:44:27 +0200 Subject: [PATCH 14/22] Further logging improvements --- nameserver/nameserver.go | 22 +++++++++++----------- resolver/resolve.go | 4 ++++ resolver/reverse.go | 2 +- resolver/scopes.go | 2 +- 4 files changed, 17 insertions(+), 13 deletions(-) diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index acf22474..9deec933 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("namserver: not resolving %s, device is offline", q.FQDN) + tracer.Debugf("nameserver: not resolving %s, device is offline", q.FQDN) return reply(nsutil.ServerFailure("resolving disabled, device is offline")) } @@ -121,8 +121,8 @@ 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("")) + tracer.Tracef("nameserver: returning localhost records") + return reply(nsutil.Localhost()) } // Authenticate request - only requests from the local host, but with any of its IPs, are allowed. @@ -197,14 +197,14 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // React to special errors. switch { case errors.Is(err, resolver.ErrNotFound): - tracer.Tracef("namserver: NXDomain via error") - return reply(nsutil.NxDomain("")) + tracer.Tracef("nameserver: NXDomain via error: %s", err) + return reply(nsutil.NxDomain("nxdomain: " + err.Error())) case errors.Is(err, resolver.ErrBlocked): - tracer.Tracef("namserver: block via error") - return reply(nsutil.ZeroIP("")) + tracer.Tracef("nameserver: block via error: %s", err) + return reply(nsutil.ZeroIP("blocked: " + err.Error())) case errors.Is(err, resolver.ErrLocalhost): - tracer.Tracef("namserver: returning localhost records") - return reply(nsutil.Localhost("")) + tracer.Tracef("nameserver: returning localhost records") + return reply(nsutil.Localhost()) default: tracer.Warningf("nameserver: failed to resolve %s: %s", q.ID(), err) return reply(nsutil.ServerFailure("internal error: " + err.Error())) @@ -230,7 +230,7 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Request was blocked by the firewall. switch conn.Verdict { case network.VerdictBlock, network.VerdictDrop, network.VerdictFailed: - tracer.Infof("nameserver: request for %s from %s %s", q.ID(), conn.Process(), conn.Verdict.Verb()) + tracer.Infof("nameserver: %s request for %s from %s", conn.Verdict.Verb(), q.ID(), conn.Process()) return reply(conn, conn) } } @@ -239,6 +239,6 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) defer network.SaveOpenDNSRequest(conn) // Reply with successful response. - tracer.Infof("nameserver: returning %s response %s to %s", conn.Verdict.Verb(), q.ID(), conn.Process()) + tracer.Infof("nameserver: returning %s response for %s to %s", conn.Verdict.Verb(), q.ID(), conn.Process()) return reply(rrCache, conn, rrCache) } diff --git a/resolver/resolve.go b/resolver/resolve.go index 921f2b8e..566ba63d 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -121,6 +121,9 @@ func Resolve(ctx context.Context, q *Query) (rrCache *RRCache, err error) { } // log + // try adding a context tracer + ctx, tracer := log.AddTracer(ctx) + defer tracer.Submit() log.Tracer(ctx).Tracef("resolver: resolving %s%s", q.FQDN, q.QType) // check query compliance @@ -225,6 +228,7 @@ func checkCache(ctx context.Context, q *Query) *RRCache { // resolve async module.StartWorker("resolve async", func(ctx context.Context) error { ctx, tracer := log.AddTracer(ctx) + defer tracer.Submit() tracer.Debugf("resolver: resolving %s async", q.ID()) _, err := resolveAndCache(ctx, q, nil) if err != nil { diff --git a/resolver/reverse.go b/resolver/reverse.go index c236818b..88e67d3a 100644 --- a/resolver/reverse.go +++ b/resolver/reverse.go @@ -14,7 +14,7 @@ func ResolveIPAndValidate(ctx context.Context, ip string, securityLevel uint8) ( // get reversed DNS address reverseIP, err := dns.ReverseAddr(ip) if err != nil { - log.Tracef("resolver: failed to get reverse address of %s: %s", ip, err) + log.Tracer(ctx).Tracef("resolver: failed to get reverse address of %s: %s", ip, err) return "", ErrInvalid } diff --git a/resolver/scopes.go b/resolver/scopes.go index c0414381..0943cf2b 100644 --- a/resolver/scopes.go +++ b/resolver/scopes.go @@ -158,7 +158,7 @@ addNextResolver: for _, resolver := range addResolvers { // check for compliance if err := resolver.checkCompliance(ctx, q); err != nil { - log.Tracef("skipping non-compliant resolver %s: %s", resolver.GetName(), err) + log.Tracer(ctx).Tracef("skipping non-compliant resolver %s: %s", resolver.GetName(), err) continue } From 1bf7946e58a75babd0ed0ce693a5558ae579aba7 Mon Sep 17 00:00:00 2001 From: Daniel Date: Thu, 24 Sep 2020 22:47:56 +0200 Subject: [PATCH 15/22] Delete filterlist entry if update has no sources --- intel/filterlists/database.go | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/intel/filterlists/database.go b/intel/filterlists/database.go index bff14c5e..6c1bb695 100644 --- a/intel/filterlists/database.go +++ b/intel/filterlists/database.go @@ -197,6 +197,7 @@ func normalizeEntry(entry *listEntry) { func processEntry(ctx context.Context, filter *scopedBloom, entry *listEntry, records chan<- record.Record) error { normalizeEntry(entry) + // Only add the entry to the bloom filter if it has any sources. if len(entry.Sources) > 0 { filter.add(entry.Type, entry.Entity) } @@ -208,6 +209,12 @@ func processEntry(ctx context.Context, filter *scopedBloom, entry *listEntry, re UpdatedAt: time.Now().Unix(), } + // If the entry is a "delete" update, actually delete it to save space. + if len(entry.Sources) == 0 { + r.CreateMeta() + r.Meta().Delete() + } + key := makeListCacheKey(strings.ToLower(r.Type), r.Value) r.SetKey(key) From 4e14439112b89e05e454d66331833b59540e715c Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 10:13:10 +0200 Subject: [PATCH 16/22] Handle DNS Rcodes --- nameserver/nameserver.go | 11 ++++++++--- resolver/namerecord.go | 1 + resolver/resolve.go | 14 +++++++------- resolver/resolver-env.go | 1 + resolver/resolver-mdns.go | 3 +++ resolver/resolver-plain.go | 1 + resolver/resolver-tcp.go | 5 +++++ resolver/rrcache.go | 39 ++++++++++++++++++++++++++------------ 8 files changed, 53 insertions(+), 22 deletions(-) diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index 9deec933..21b81151 100644 --- a/nameserver/nameserver.go +++ b/nameserver/nameserver.go @@ -98,7 +98,12 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // Start context tracer for context-aware logging. ctx, tracer := log.AddTracer(ctx) defer tracer.Submit() - tracer.Tracef("nameserver: handling new request for %s%s from %s:%d", q.FQDN, q.QType, remoteAddr.IP, remoteAddr.Port) + tracer.Tracef("nameserver: handling new request for %s from %s:%d", q.ID(), remoteAddr.IP, remoteAddr.Port) + + // Check if there are more than one question. + if len(request.Question) > 1 { + tracer.Warningf("nameserver: received more than one question from (%s:%d), first question is %s", remoteAddr.IP, remoteAddr.Port, q.ID()) + } // Setup quick reply function. reply := func(responder nsutil.Responder, rrProviders ...nsutil.RRProvider) error { @@ -197,10 +202,10 @@ func handleRequest(ctx context.Context, w dns.ResponseWriter, request *dns.Msg) // React to special errors. switch { case errors.Is(err, resolver.ErrNotFound): - tracer.Tracef("nameserver: NXDomain via error: %s", err) + tracer.Tracef("nameserver: %s", err) return reply(nsutil.NxDomain("nxdomain: " + err.Error())) case errors.Is(err, resolver.ErrBlocked): - tracer.Tracef("nameserver: block via error: %s", err) + tracer.Tracef("nameserver: %s", err) return reply(nsutil.ZeroIP("blocked: " + err.Error())) case errors.Is(err, resolver.ErrLocalhost): tracer.Tracef("nameserver: returning localhost records") diff --git a/resolver/namerecord.go b/resolver/namerecord.go index f277c435..45deae30 100644 --- a/resolver/namerecord.go +++ b/resolver/namerecord.go @@ -28,6 +28,7 @@ type NameRecord struct { Domain string Question string + RCode int Answer []string Ns []string Extra []string diff --git a/resolver/resolve.go b/resolver/resolve.go index 566ba63d..526c6931 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -206,10 +206,10 @@ func checkCache(ctx context.Context, q *Query) *RRCache { // We still return the cache, if it isn't NXDomain, as it will be used if the // new query fails. if rrCache.Expired() { - if rrCache.IsNXDomain() { - return nil + if rrCache.RCode == dns.RcodeSuccess { + return rrCache } - return rrCache + return nil } // Check if the cache will expire soon and start an async request. @@ -377,8 +377,8 @@ resolveLoop: // Defensive: This should normally not happen. continue } - // Check if we got NXDomain and whether we should try another resolver. - if rrCache.IsNXDomain() && tryAll { + // Check if request suceeded and whether we should try another resolver. + if rrCache.RCode != dns.RcodeSuccess && tryAll { continue } break resolveLoop @@ -404,7 +404,7 @@ resolveLoop: // 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(): + case !rrCache.Cacheable(): // 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 @@ -417,7 +417,7 @@ resolveLoop: } // Save the new entry if cache is enabled. - if !q.NoCaching { + if !q.NoCaching && rrCache.Cacheable() { rrCache.Clean(minTTL) err = rrCache.Save() if err != nil { diff --git a/resolver/resolver-env.go b/resolver/resolver-env.go index 7cdbc008..2d4ad230 100644 --- a/resolver/resolver-env.go +++ b/resolver/resolver-env.go @@ -111,6 +111,7 @@ func (er *envResolverConn) makeRRCache(q *Query, answers []dns.RR) *RRCache { return &RRCache{ Domain: q.FQDN, Question: q.QType, + RCode: dns.RcodeSuccess, Answer: answers, Extra: []dns.RR{internalSpecialUseComment}, // Always add comment about this TLD. Server: envResolver.Server, diff --git a/resolver/resolver-mdns.go b/resolver/resolver-mdns.go index bd965258..21a91a87 100644 --- a/resolver/resolver-mdns.go +++ b/resolver/resolver-mdns.go @@ -202,6 +202,7 @@ func handleMDNSMessages(ctx context.Context, messages chan *dns.Msg) error { rrCache = &RRCache{ Domain: question.Name, Question: dns.Type(question.Qtype), + RCode: dns.RcodeSuccess, Server: mDNSResolver.Server, ServerScope: mDNSResolver.ServerIPScope, ServerInfo: mDNSResolver.ServerInfo, @@ -303,6 +304,7 @@ func handleMDNSMessages(ctx context.Context, messages chan *dns.Msg) error { rrCache = &RRCache{ Domain: v.Header().Name, Question: dns.Type(v.Header().Class), + RCode: dns.RcodeSuccess, Answer: []dns.RR{v}, Server: mDNSResolver.Server, ServerScope: mDNSResolver.ServerIPScope, @@ -423,6 +425,7 @@ func queryMulticastDNS(ctx context.Context, q *Query) (*RRCache, error) { return &RRCache{ Domain: q.FQDN, Question: q.QType, + RCode: dns.RcodeNameError, Server: mDNSResolver.Server, ServerScope: mDNSResolver.ServerIPScope, ServerInfo: mDNSResolver.ServerInfo, diff --git a/resolver/resolver-plain.go b/resolver/resolver-plain.go index a64dc314..3892ab91 100644 --- a/resolver/resolver-plain.go +++ b/resolver/resolver-plain.go @@ -81,6 +81,7 @@ func (pr *PlainResolver) Query(ctx context.Context, q *Query) (*RRCache, error) newRecord := &RRCache{ Domain: q.FQDN, Question: q.QType, + RCode: reply.Rcode, Answer: reply.Answer, Ns: reply.Ns, Extra: reply.Extra, diff --git a/resolver/resolver-tcp.go b/resolver/resolver-tcp.go index ff915b97..76c54cb8 100644 --- a/resolver/resolver-tcp.go +++ b/resolver/resolver-tcp.go @@ -50,6 +50,7 @@ func (ifq *InFlightQuery) MakeCacheRecord(reply *dns.Msg) *RRCache { return &RRCache{ Domain: ifq.Query.FQDN, Question: ifq.Query.QType, + RCode: reply.Rcode, Answer: reply.Answer, Ns: reply.Ns, Extra: reply.Extra, @@ -477,6 +478,10 @@ func (mgr *tcpResolverConnMgr) handleQueryResponse(conn *dns.Conn, msg *dns.Msg) // persist to database rrCache := inFlight.MakeCacheRecord(msg) + if !rrCache.Cacheable() { + return + } + rrCache.Clean(minTTL) err := rrCache.Save() if err != nil { diff --git a/resolver/rrcache.go b/resolver/rrcache.go index b6a103a8..9411e9db 100644 --- a/resolver/rrcache.go +++ b/resolver/rrcache.go @@ -22,6 +22,7 @@ type RRCache struct { Domain string // constant Question dns.Type // constant + RCode int // constant Answer []dns.RR // constant Ns []dns.RR // constant @@ -84,8 +85,8 @@ func (rrCache *RRCache) Clean(minExpires uint32) { // shorten caching switch { - case rrCache.IsNXDomain(): - // NXDomain + case rrCache.RCode != dns.RcodeSuccess: + // Any sort of error. lowestTTL = 10 case netenv.IsConnectivityDomain(rrCache.Domain): // Responses from these domains might change very quickly depending on the environment. @@ -127,6 +128,7 @@ func (rrCache *RRCache) ToNameRecord() *NameRecord { new := &NameRecord{ Domain: rrCache.Domain, Question: rrCache.Question.String(), + RCode: rrCache.RCode, TTL: rrCache.TTL, Server: rrCache.Server, ServerScope: rrCache.ServerScope, @@ -147,8 +149,27 @@ func (rrCache *RRCache) ToNameRecord() *NameRecord { return new } +// rcodeIsCacheable returns whether a record with the given RCode should be cached. +func rcodeIsCacheable(rCode int) bool { + switch rCode { + case dns.RcodeSuccess, dns.RcodeNameError, dns.RcodeRefused: + return true + default: + return false + } +} + +// Cacheable returns whether the record should be cached. +func (rrCache *RRCache) Cacheable() bool { + return rcodeIsCacheable(rrCache.RCode) +} + // Save saves the RRCache to the database as a NameRecord. func (rrCache *RRCache) Save() error { + if !rrCache.Cacheable() { + return nil + } + return rrCache.ToNameRecord().Save() } @@ -164,6 +185,7 @@ func GetRRCache(domain string, question dns.Type) (*RRCache, error) { return nil, err } + rrCache.RCode = nameRecord.RCode rrCache.TTL = nameRecord.TTL for _, entry := range nameRecord.Answer { rrCache.Answer = parseRR(rrCache.Answer, entry) @@ -227,16 +249,12 @@ func (rrCache *RRCache) Flags() string { return "" } -// IsNXDomain returnes whether the result is nxdomain. -func (rrCache *RRCache) IsNXDomain() bool { - return len(rrCache.Answer) == 0 -} - // ShallowCopy returns a shallow copy of the cache. slices are not copied, but referenced. func (rrCache *RRCache) ShallowCopy() *RRCache { return &RRCache{ Domain: rrCache.Domain, Question: rrCache.Question, + RCode: rrCache.RCode, Answer: rrCache.Answer, Ns: rrCache.Ns, Extra: rrCache.Extra, @@ -259,14 +277,11 @@ func (rrCache *RRCache) ShallowCopy() *RRCache { func (rrCache *RRCache) ReplyWithDNS(ctx context.Context, request *dns.Msg) *dns.Msg { // reply to query reply := new(dns.Msg) - reply.SetRcode(request, dns.RcodeSuccess) + reply.SetRcode(request, rrCache.RCode) reply.Ns = rrCache.Ns reply.Extra = rrCache.Extra - if rrCache.IsNXDomain() { - // Set NXDomain return code if not the reply has no answers. - reply.Rcode = dns.RcodeNameError - } else { + if len(rrCache.Answer) > 0 { // Copy answers, as we randomize their order a little. reply.Answer = make([]dns.RR, len(rrCache.Answer)) copy(reply.Answer, rrCache.Answer) From 3474b042281558be3a3db96cd08003669ed0a906 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 10:18:56 +0200 Subject: [PATCH 17/22] Use whitelist flag to delete --- intel/filterlists/database.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/intel/filterlists/database.go b/intel/filterlists/database.go index 6c1bb695..23ce779e 100644 --- a/intel/filterlists/database.go +++ b/intel/filterlists/database.go @@ -210,7 +210,7 @@ func processEntry(ctx context.Context, filter *scopedBloom, entry *listEntry, re } // If the entry is a "delete" update, actually delete it to save space. - if len(entry.Sources) == 0 { + if entry.Whitelist { r.CreateMeta() r.Meta().Delete() } From 991cebb3d3f478ca89856bc57bef57d2c7c0cc63 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 10:23:59 +0200 Subject: [PATCH 18/22] Retry send DNS response without extra section --- nameserver/response.go | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/nameserver/response.go b/nameserver/response.go index 1159ce9e..1894c9b5 100644 --- a/nameserver/response.go +++ b/nameserver/response.go @@ -53,5 +53,14 @@ func writeDNSResponse(w dns.ResponseWriter, m *dns.Msg) (err error) { }() err = w.WriteMsg(m) + if err == nil { + // If we receive an error we might have exceeded the message size with all + // our extra information records. Retry again without the extra section. + m.Extra = nil + noExtraErr := w.WriteMsg(m) + if noExtraErr == nil { + log.Warningf("nameserver: failed to write dns message with extra section: %s", err) + } + } return } From ee3c046656eb18cebfa7fc8ebff02864175eb931 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 10:32:50 +0200 Subject: [PATCH 19/22] Bump version --- cmds/portmaster-core/main.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cmds/portmaster-core/main.go b/cmds/portmaster-core/main.go index fa375248..4a03599b 100644 --- a/cmds/portmaster-core/main.go +++ b/cmds/portmaster-core/main.go @@ -18,7 +18,7 @@ import ( func main() { // set information - info.Set("Portmaster", "0.5.4", "AGPLv3", true) + info.Set("Portmaster", "0.5.5", "AGPLv3", true) // enable SPN client mode conf.EnableClient(true) From a498611a2a8f0ef9640c4b7f8643f64512c86d58 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 11:07:36 +0200 Subject: [PATCH 20/22] Fix second write when responding with extra section --- nameserver/response.go | 2 +- resolver/resolve.go | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/nameserver/response.go b/nameserver/response.go index 1894c9b5..4171b36f 100644 --- a/nameserver/response.go +++ b/nameserver/response.go @@ -53,7 +53,7 @@ func writeDNSResponse(w dns.ResponseWriter, m *dns.Msg) (err error) { }() err = w.WriteMsg(m) - if err == nil { + if err != nil { // If we receive an error we might have exceeded the message size with all // our extra information records. Retry again without the extra section. m.Extra = nil diff --git a/resolver/resolve.go b/resolver/resolve.go index 526c6931..67b95ec6 100644 --- a/resolver/resolve.go +++ b/resolver/resolve.go @@ -309,7 +309,7 @@ retry: } } -func resolveAndCache(ctx context.Context, q *Query, oldCache *RRCache) (rrCache *RRCache, err error) { //nolint:gocognit +func resolveAndCache(ctx context.Context, q *Query, oldCache *RRCache) (rrCache *RRCache, err error) { //nolint:gocognit,gocyclo // get resolvers resolvers, tryAll := GetResolversInScope(ctx, q) if len(resolvers) == 0 { @@ -377,7 +377,7 @@ resolveLoop: // Defensive: This should normally not happen. continue } - // Check if request suceeded and whether we should try another resolver. + // Check if request succeeded and whether we should try another resolver. if rrCache.RCode != dns.RcodeSuccess && tryAll { continue } From 7ea1c98d03de88e24f355e0bc0e10368afc1f9d8 Mon Sep 17 00:00:00 2001 From: Daniel Date: Fri, 25 Sep 2020 11:36:15 +0200 Subject: [PATCH 21/22] Bump core version --- cmds/portmaster-core/main.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cmds/portmaster-core/main.go b/cmds/portmaster-core/main.go index 4a03599b..cbbf46e8 100644 --- a/cmds/portmaster-core/main.go +++ b/cmds/portmaster-core/main.go @@ -18,7 +18,7 @@ import ( func main() { // set information - info.Set("Portmaster", "0.5.5", "AGPLv3", true) + info.Set("Portmaster", "0.5.6", "AGPLv3", true) // enable SPN client mode conf.EnableClient(true) From 7c5cbefc274e238479b21b25d0960e0d0c1117d5 Mon Sep 17 00:00:00 2001 From: Daniel Date: Mon, 28 Sep 2020 12:37:17 +0200 Subject: [PATCH 22/22] Update Adguard DNS configuration to use new IPs See their announcement: https://adguard.com/en/blog/adguard-dns-new-addresses.html --- resolver/config.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/resolver/config.go b/resolver/config.go index f90fa625..0c50ed9b 100644 --- a/resolver/config.go +++ b/resolver/config.go @@ -32,8 +32,8 @@ var ( // `dot://1.0.0.2:853?verify=cloudflare-dns.com&name=Cloudflare&blockedif=zeroip`, // AdGuard (encrypted DNS, default flavor) - // `dot://176.103.130.130:853?verify=dns.adguard.com&name=AdGuard&blockedif=zeroip`, - // `dot://176.103.130.131:853?verify=dns.adguard.com&name=AdGuard&blockedif=zeroip`, + // `dot://94.140.14.14:853?verify=dns.adguard.com&name=AdGuard&blockedif=zeroip`, + // `dot://94.140.15.15:853?verify=dns.adguard.com&name=AdGuard&blockedif=zeroip`, // Foundation for Applied Privacy (encrypted DNS) // `dot://94.130.106.88:853?verify=dot1.applied-privacy.net&name=AppliedPrivacy`, @@ -48,8 +48,8 @@ var ( // `dns://1.0.0.2:53?name=Cloudflare&blockedif=zeroip`, // AdGuard (plain DNS, default flavor) - // `dns://176.103.130.130&name=AdGuard&blockedif=zeroip`, - // `dns://176.103.130.131&name=AdGuard&blockedif=zeroip`, + // `dns://94.140.14.14&name=AdGuard&blockedif=zeroip`, + // `dns://94.140.15.15&name=AdGuard&blockedif=zeroip`, } CfgOptionNameServersKey = "dns/nameservers"