diff --git a/intel/clients.go b/intel/clients.go index 18b34b02..aa281cd0 100644 --- a/intel/clients.go +++ b/intel/clients.go @@ -2,12 +2,24 @@ package intel import ( "crypto/tls" + "net" "sync" "time" "github.com/miekg/dns" ) +var ( + localAddrFactory func(network string) net.Addr +) + +// SetLocalAddrFactory supplied the intel package with a function to set local addresses for connections. +func SetLocalAddrFactory(laf func(network string) net.Addr) { + if localAddrFactory == nil { + localAddrFactory = laf + } +} + type clientManager struct { dnsClient *dns.Client factory func() *dns.Client @@ -21,10 +33,13 @@ type clientManager struct { func newDNSClientManager(resolver *Resolver) *clientManager { return &clientManager{ - ttl: -1 * time.Minute, + // ttl: 1 * time.Minute, factory: func() *dns.Client { return &dns.Client{ Timeout: 5 * time.Second, + Dialer: &net.Dialer{ + LocalAddr: localAddrFactory("udp"), + }, } }, } @@ -32,11 +47,14 @@ func newDNSClientManager(resolver *Resolver) *clientManager { func newTCPClientManager(resolver *Resolver) *clientManager { return &clientManager{ - ttl: -15 * time.Minute, + // ttl: 5 * time.Minute, factory: func() *dns.Client { return &dns.Client{ Net: "tcp", Timeout: 5 * time.Second, + Dialer: &net.Dialer{ + LocalAddr: localAddrFactory("tcp"), + }, } }, } @@ -44,7 +62,7 @@ func newTCPClientManager(resolver *Resolver) *clientManager { func newTLSClientManager(resolver *Resolver) *clientManager { return &clientManager{ - ttl: -15 * time.Minute, + // ttl: 5 * time.Minute, factory: func() *dns.Client { return &dns.Client{ Net: "tcp-tls", @@ -55,6 +73,9 @@ func newTLSClientManager(resolver *Resolver) *clientManager { // Rand: io.Reader, }, Timeout: 5 * time.Second, + Dialer: &net.Dialer{ + LocalAddr: localAddrFactory("tcp"), + }, } }, } @@ -62,7 +83,7 @@ func newTLSClientManager(resolver *Resolver) *clientManager { func newHTTPSClientManager(resolver *Resolver) *clientManager { return &clientManager{ - ttl: -15 * time.Minute, + // ttl: 5 * time.Minute, factory: func() *dns.Client { new := &dns.Client{ Net: "https", @@ -72,6 +93,9 @@ func newHTTPSClientManager(resolver *Resolver) *clientManager { // Rand: io.Reader, }, Timeout: 5 * time.Second, + Dialer: &net.Dialer{ + LocalAddr: localAddrFactory("tcp"), + }, } if resolver.VerifyDomain != "" { new.TLSConfig.ServerName = resolver.VerifyDomain @@ -85,7 +109,7 @@ func (cm *clientManager) getDNSClient() *dns.Client { cm.lock.Lock() defer cm.lock.Unlock() - if cm.dnsClient == nil || time.Now().After(cm.refreshAfter) { + if cm.dnsClient == nil || cm.ttl == 0 || time.Now().After(cm.refreshAfter) { cm.dnsClient = cm.factory() cm.refreshAfter = time.Now().Add(cm.ttl) } diff --git a/intel/config.go b/intel/config.go index c7b7440b..e9328ca7 100644 --- a/intel/config.go +++ b/intel/config.go @@ -8,18 +8,19 @@ import ( var ( configuredNameServers config.StringArrayOption defaultNameServers = []string{ + "dns|1.1.1.1:53", // Cloudflare + "dns|1.0.0.1:53", // Cloudflare + "dns|9.9.9.9:53", // Quad9 "tls|1.1.1.1:853|cloudflare-dns.com", // Cloudflare "tls|1.0.0.1:853|cloudflare-dns.com", // Cloudflare "tls|9.9.9.9:853|dns.quad9.net", // Quad9 // "https|cloudflare-dns.com/dns-query", // HTTPS still experimental - "dns|1.1.1.1:53", // Cloudflare - "dns|1.0.0.1:53", // Cloudflare - "dns|9.9.9.9:53", // Quad9 } nameserverRetryRate config.IntOption doNotUseMulticastDNS status.SecurityLevelOption doNotUseAssignedNameservers status.SecurityLevelOption + doNotUseInsecureProtocols status.SecurityLevelOption doNotResolveSpecialDomains status.SecurityLevelOption ) @@ -73,7 +74,7 @@ func prep() error { ExpertiseLevel: config.ExpertiseLevelExpert, OptType: config.OptTypeInt, ExternalOptType: "security level", - DefaultValue: 6, + DefaultValue: 4, ValidationRegex: "^(7|6|4)$", }) if err != nil { @@ -81,6 +82,21 @@ func prep() error { } doNotUseAssignedNameservers = status.ConfigIsActiveConcurrent("intel/doNotUseAssignedNameservers") + err = config.Register(&config.Option{ + Name: "Do not resolve insecurely", + Key: "intel/doNotUseInsecureProtocols", + Description: "Do not resolve domains with insecure protocols, ie. plain DNS", + ExpertiseLevel: config.ExpertiseLevelExpert, + OptType: config.OptTypeInt, + ExternalOptType: "security level", + DefaultValue: 4, + ValidationRegex: "^(7|6|4)$", + }) + if err != nil { + return err + } + doNotUseInsecureProtocols = status.ConfigIsActiveConcurrent("intel/doNotUseInsecureProtocols") + err = config.Register(&config.Option{ Name: "Do not resolve special domains", Key: "intel/doNotResolveSpecialDomains", diff --git a/intel/main.go b/intel/main.go index 24e2b639..df8505ae 100644 --- a/intel/main.go +++ b/intel/main.go @@ -1,6 +1,8 @@ package intel import ( + "context" + "github.com/miekg/dns" "github.com/Safing/portbase/log" @@ -24,12 +26,16 @@ func start() error { } // GetIntelAndRRs returns intel and DNS resource records for the given domain. -func GetIntelAndRRs(domain string, qtype dns.Type, securityLevel uint8) (intel *Intel, rrs *RRCache) { +func GetIntelAndRRs(ctx context.Context, domain string, qtype dns.Type, securityLevel uint8) (intel *Intel, rrs *RRCache) { + log.Tracer(ctx).Trace("intel: getting intel") intel, err := GetIntel(domain) if err != nil { + log.Tracer(ctx).Warningf("intel: failed to get intel: %s", err) log.Errorf("intel: failed to get intel: %s", err) intel = nil } - rrs = Resolve(domain, qtype, securityLevel) + + log.Tracer(ctx).Tracef("intel: getting records") + rrs = Resolve(ctx, domain, qtype, securityLevel) return } diff --git a/intel/mdns.go b/intel/mdns.go index 0292ef6f..35a597c5 100644 --- a/intel/mdns.go +++ b/intel/mdns.go @@ -3,6 +3,7 @@ package intel import ( + "context" "errors" "fmt" "net" @@ -262,7 +263,9 @@ func listenForDNSPackets(conn *net.UDPConn, messages chan *dns.Msg) { } } -func queryMulticastDNS(fqdn string, qtype dns.Type) (*RRCache, error) { +func queryMulticastDNS(ctx context.Context, fqdn string, qtype dns.Type) (*RRCache, error) { + log.Tracer(ctx).Trace("intel: resolving with mDNS") + q := new(dns.Msg) q.SetQuestion(fqdn, uint16(qtype)) // request unicast response diff --git a/intel/resolve.go b/intel/resolve.go index 6242a421..9e5d02d6 100644 --- a/intel/resolve.go +++ b/intel/resolve.go @@ -3,6 +3,7 @@ package intel import ( + "context" "fmt" "math/rand" "net" @@ -69,7 +70,7 @@ import ( // special -> local scopes, local // Resolve resolves the given query for a domain and type and returns a RRCache object or nil, if the query failed. -func Resolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { +func Resolve(ctx context.Context, fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { fqdn = dns.Fqdn(fqdn) // use this to time how long it takes resolve this domain @@ -82,15 +83,17 @@ func Resolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { switch err { case database.ErrNotFound: default: + log.Tracer(ctx).Warningf("intel: getting RRCache %s%s from database failed: %s", fqdn, qtype.String(), err) log.Warningf("intel: getting RRCache %s%s from database failed: %s", fqdn, qtype.String(), err) } - return resolveAndCache(fqdn, qtype, securityLevel) + return resolveAndCache(ctx, fqdn, qtype, securityLevel) } if rrCache.TTL <= time.Now().Unix() { - log.Tracef("intel: serving cache, requesting new. TTL=%d, now=%d", rrCache.TTL, time.Now().Unix()) + log.Tracer(ctx).Tracef("intel: serving from cache, requesting new. TTL=%d, now=%d", rrCache.TTL, time.Now().Unix()) + // log.Tracef("intel: serving cache, requesting new. TTL=%d, now=%d", rrCache.TTL, time.Now().Unix()) rrCache.requestingNew = true - go resolveAndCache(fqdn, qtype, securityLevel) + go resolveAndCache(nil, fqdn, qtype, securityLevel) } // randomize records to allow dumb clients (who only look at the first record) to reliably connect @@ -102,8 +105,8 @@ func Resolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { return rrCache } -func resolveAndCache(fqdn string, qtype dns.Type, securityLevel uint8) (rrCache *RRCache) { - // log.Tracef("intel: resolving %s%s", fqdn, qtype.String()) +func resolveAndCache(ctx context.Context, fqdn string, qtype dns.Type, securityLevel uint8) (rrCache *RRCache) { + log.Tracer(ctx).Tracef("intel: resolving %s%s", fqdn, qtype.String()) // dedup requests dupKey := fmt.Sprintf("%s%s", fqdn, qtype.String()) @@ -116,7 +119,8 @@ func resolveAndCache(fqdn string, qtype dns.Type, securityLevel uint8) (rrCache dupReqLock.Unlock() } else { dupReqLock.Unlock() - log.Tracef("intel: waiting for duplicate query for %s to complete", dupKey) + log.Tracer(ctx).Tracef("intel: waiting for duplicate query for %s to complete", dupKey) + // log.Tracef("intel: waiting for duplicate query for %s to complete", dupKey) mutex.Lock() // wait until duplicate request is finished, then fetch current RRCache and return mutex.Unlock() @@ -136,7 +140,7 @@ func resolveAndCache(fqdn string, qtype dns.Type, securityLevel uint8) (rrCache }() // resolve - rrCache = intelligentResolve(fqdn, qtype, securityLevel) + rrCache = intelligentResolve(ctx, fqdn, qtype, securityLevel) if rrCache == nil { return nil } @@ -148,7 +152,7 @@ func resolveAndCache(fqdn string, qtype dns.Type, securityLevel uint8) (rrCache return rrCache } -func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { +func intelligentResolve(ctx context.Context, fqdn string, qtype dns.Type, securityLevel uint8) *RRCache { // TODO: handle being offline // TODO: handle multiple network connections @@ -178,7 +182,7 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac if domainInScopes(preDottedFqdn, localReverseScopes) { // try local resolvers for _, resolver := range localResolvers { - rrCache, ok := tryResolver(resolver, lastFailBoundary, fqdn, qtype, securityLevel) + rrCache, ok := tryResolver(ctx, resolver, lastFailBoundary, fqdn, qtype, securityLevel) if ok && rrCache != nil && !rrCache.IsNXDomain() { return rrCache } @@ -188,8 +192,9 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac return nil } // try mdns - rrCache, err := queryMulticastDNS(fqdn, qtype) + rrCache, err := queryMulticastDNS(ctx, fqdn, qtype) if err != nil { + log.Tracer(ctx).Warningf("intel: failed to query mdns: %s", err) log.Errorf("intel: failed to query mdns: %s", err) } return rrCache @@ -199,7 +204,7 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac for _, scope := range localScopes { if strings.HasSuffix(preDottedFqdn, scope.Domain) { for _, resolver := range scope.Resolvers { - rrCache, ok := tryResolver(resolver, lastFailBoundary, fqdn, qtype, securityLevel) + rrCache, ok := tryResolver(ctx, resolver, lastFailBoundary, fqdn, qtype, securityLevel) if ok && rrCache != nil && !rrCache.IsNXDomain() { return rrCache } @@ -214,8 +219,9 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac return nil } // try mdns - rrCache, err := queryMulticastDNS(fqdn, qtype) + rrCache, err := queryMulticastDNS(ctx, fqdn, qtype) if err != nil { + log.Tracer(ctx).Warningf("intel: failed to query mdns: %s", err) log.Errorf("intel: failed to query mdns: %s", err) } return rrCache @@ -226,7 +232,7 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac } // try local resolvers for _, resolver := range localResolvers { - rrCache, ok := tryResolver(resolver, lastFailBoundary, fqdn, qtype, securityLevel) + rrCache, ok := tryResolver(ctx, resolver, lastFailBoundary, fqdn, qtype, securityLevel) if ok { return rrCache } @@ -234,13 +240,14 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac default: // try global resolvers for _, resolver := range globalResolvers { - rrCache, ok := tryResolver(resolver, lastFailBoundary, fqdn, qtype, securityLevel) + rrCache, ok := tryResolver(ctx, resolver, lastFailBoundary, fqdn, qtype, securityLevel) if ok { return rrCache } } } + log.Tracer(ctx).Warningf("intel: failed to resolve %s%s: all resolvers failed (or were skipped to fulfill the security level)", fqdn, qtype.String()) log.Criticalf("intel: failed to resolve %s%s: all resolvers failed (or were skipped to fulfill the security level)", fqdn, qtype.String()) return nil @@ -248,24 +255,29 @@ func intelligentResolve(fqdn string, qtype dns.Type, securityLevel uint8) *RRCac } -func tryResolver(resolver *Resolver, lastFailBoundary int64, fqdn string, qtype dns.Type, securityLevel uint8) (*RRCache, bool) { - // skip if not allowed in current security level - if resolver.AllowedSecurityLevel < status.ActiveSecurityLevel() || resolver.AllowedSecurityLevel < securityLevel { - log.Tracef("intel: skipping resolver %s, because it isn't allowed to operate on the current security level: %d|%d", resolver, status.ActiveSecurityLevel(), securityLevel) +func tryResolver(ctx context.Context, resolver *Resolver, lastFailBoundary int64, fqdn string, qtype dns.Type, securityLevel uint8) (*RRCache, bool) { + log.Tracer(ctx).Tracef("intel: resolving with %s", resolver) + + // skip if not security level denies insecure protocols + if doNotUseInsecureProtocols(securityLevel) && resolver.ServerType == "dns" { + log.Tracer(ctx).Tracef("intel: skipping resolver %s, because it isn't allowed to operate on the current security level: %d|%d", resolver, status.ActiveSecurityLevel(), securityLevel) return nil, false } + // skip if not security level denies assigned dns servers if doNotUseAssignedNameservers(securityLevel) && resolver.Source == "dhcp" { - log.Tracef("intel: skipping resolver %s, because assigned nameservers are not allowed on the current security level: %d|%d", resolver, status.ActiveSecurityLevel(), securityLevel) + log.Tracer(ctx).Tracef("intel: skipping resolver %s, because assigned nameservers are not allowed on the current security level: %d|%d", resolver, status.ActiveSecurityLevel(), securityLevel) return nil, false } // check if failed recently if atomic.LoadInt64(resolver.LastFail) > lastFailBoundary { + log.Tracer(ctx).Tracef("intel: skipping resolver %s, because it failed recently", resolver) return nil, false } // TODO: put SkipFqdnBeforeInit back into !resolver.Initialized.IsSet() as soon as Go1.9 arrives and we can use a custom resolver // skip resolver if initializing and fqdn is set to skip if fqdn == resolver.SkipFqdnBeforeInit { + log.Tracer(ctx).Tracef("intel: skipping resolver %s, because %s is set to be skipped before init", resolver, fqdn) return nil, false } // check if resolver is already initialized @@ -285,15 +297,16 @@ func tryResolver(resolver *Resolver, lastFailBoundary int64, fqdn string, qtype } } // resolve - log.Tracef("intel: trying to resolve %s%s with %s", fqdn, qtype.String(), resolver.Server) - rrCache, err := query(resolver, fqdn, qtype) + rrCache, err := query(ctx, resolver, fqdn, qtype) if err != nil { // check if failing is disabled if atomic.LoadInt64(resolver.LastFail) == -1 { - log.Tracef("intel: non-failing resolver %s failed (%s), moving to next", resolver, err) + log.Tracer(ctx).Tracef("intel: non-failing resolver %s failed, moving to next: %s", resolver, err) + // log.Tracef("intel: non-failing resolver %s failed (%s), moving to next", resolver, err) return nil, false } - log.Warningf("intel: resolver %s failed (%s), moving to next", resolver, err) + log.Tracer(ctx).Warningf("intel: resolver %s failed, moving to next: %s", resolver, err) + log.Warningf("intel: resolver %s failed, moving to next: %s", resolver, err) resolver.LockReason.Lock() resolver.FailReason = err.Error() resolver.LockReason.Unlock() @@ -306,7 +319,7 @@ func tryResolver(resolver *Resolver, lastFailBoundary int64, fqdn string, qtype return rrCache, true } -func query(resolver *Resolver, fqdn string, qtype dns.Type) (*RRCache, error) { +func query(ctx context.Context, resolver *Resolver, fqdn string, qtype dns.Type) (*RRCache, error) { q := new(dns.Msg) q.SetQuestion(fqdn, uint16(qtype)) @@ -322,7 +335,7 @@ func query(resolver *Resolver, fqdn string, qtype dns.Type) (*RRCache, error) { // error handling if err != nil { - log.Tracef("intel: query to %s encountered error: %s", resolver.Server, err) + log.Tracer(ctx).Tracef("intel: query to %s encountered error: %s", resolver.Server, err) // TODO: handle special cases // 1. connect: network is unreachable @@ -330,7 +343,7 @@ func query(resolver *Resolver, fqdn string, qtype dns.Type) (*RRCache, error) { // temporary error if nerr, ok := err.(net.Error); ok && nerr.Timeout() { - log.Tracef("intel: retrying to resolve %s%s with %s, error was: %s", fqdn, qtype.String(), resolver.Server, err) + log.Tracer(ctx).Tracef("intel: retrying to resolve %s%s with %s, error is temporary", fqdn, qtype, resolver.Server) continue } @@ -343,8 +356,6 @@ func query(resolver *Resolver, fqdn string, qtype dns.Type) (*RRCache, error) { } if err != nil { - err = fmt.Errorf("resolving %s%s failed: %s", fqdn, qtype.String(), err) - log.Warning(err.Error()) return nil, err } diff --git a/intel/resolver.go b/intel/resolver.go index 668197cf..8c555859 100644 --- a/intel/resolver.go +++ b/intel/resolver.go @@ -16,7 +16,6 @@ import ( "github.com/Safing/portmaster/network/environment" "github.com/Safing/portmaster/network/netutils" - "github.com/Safing/portmaster/status" ) // Resolver holds information about an active resolver. @@ -32,9 +31,8 @@ type Resolver struct { Source string clientManager *clientManager - Search *[]string - AllowedSecurityLevel uint8 - SkipFqdnBeforeInit string + Search *[]string + SkipFqdnBeforeInit string // atomic Initialized *abool.AtomicBool @@ -149,7 +147,7 @@ configuredServersLoop: var lastFail int64 new := &Resolver{ Server: server, - ServerType: parts[0], + ServerType: strings.ToLower(parts[0]), ServerAddress: parts[1], ServerIP: ip, ServerIPScope: netutils.ClassifyIP(ip), @@ -159,13 +157,12 @@ configuredServersLoop: Initialized: abool.NewBool(false), } - switch strings.ToLower(parts[0]) { + switch new.ServerType { case "dns": new.clientManager = newDNSClientManager(new) case "tcp": new.clientManager = newTCPClientManager(new) case "tls": - new.AllowedSecurityLevel = status.SecurityLevelFortress if len(parts) < 3 { log.Warningf("intel: nameserver missing verification domain as third parameter: %s", server) continue configuredServersLoop @@ -173,7 +170,6 @@ configuredServersLoop: new.VerifyDomain = parts[2] new.clientManager = newTLSClientManager(new) case "https": - new.AllowedSecurityLevel = status.SecurityLevelFortress new.SkipFqdnBeforeInit = dns.Fqdn(strings.Split(parts[1], ":")[0]) if len(parts) > 2 { new.VerifyDomain = parts[2] @@ -203,16 +199,15 @@ assignedServersLoop: var lastFail int64 new := &Resolver{ - Server: server, - ServerType: "dns", - ServerAddress: urlFormatAddress(nameserver.IP, 53), - ServerIP: nameserver.IP, - ServerIPScope: netutils.ClassifyIP(nameserver.IP), - ServerPort: 53, - LastFail: &lastFail, - Source: "dhcp", - Initialized: abool.NewBool(false), - AllowedSecurityLevel: status.SecurityLevelSecure, + Server: server, + ServerType: "dns", + ServerAddress: urlFormatAddress(nameserver.IP, 53), + ServerIP: nameserver.IP, + ServerIPScope: netutils.ClassifyIP(nameserver.IP), + ServerPort: 53, + LastFail: &lastFail, + Source: "dhcp", + Initialized: abool.NewBool(false), } new.clientManager = newDNSClientManager(new) diff --git a/intel/reverse.go b/intel/reverse.go index 21f811bc..e57bd5a7 100644 --- a/intel/reverse.go +++ b/intel/reverse.go @@ -18,7 +18,7 @@ func ResolveIPAndValidate(ip string, securityLevel uint8) (domain string, err er } // get PTR record - rrCache := Resolve(rQ, dns.Type(dns.TypePTR), securityLevel) + rrCache := Resolve(nil, rQ, dns.Type(dns.TypePTR), securityLevel) if rrCache == nil { return "", errors.New("querying for PTR record failed (may be NXDomain)") } @@ -42,9 +42,9 @@ func ResolveIPAndValidate(ip string, securityLevel uint8) (domain string, err er // get forward record if strings.Contains(ip, ":") { - rrCache = Resolve(ptrName, dns.Type(dns.TypeAAAA), securityLevel) + rrCache = Resolve(nil, ptrName, dns.Type(dns.TypeAAAA), securityLevel) } else { - rrCache = Resolve(ptrName, dns.Type(dns.TypeA), securityLevel) + rrCache = Resolve(nil, ptrName, dns.Type(dns.TypeA), securityLevel) } if rrCache == nil { return "", errors.New("querying for A/AAAA record failed (may be NXDomain)") diff --git a/nameserver/nameserver.go b/nameserver/nameserver.go index 378e19dc..1c0eae4d 100644 --- a/nameserver/nameserver.go +++ b/nameserver/nameserver.go @@ -3,6 +3,7 @@ package nameserver import ( + "context" "net" "time" @@ -73,6 +74,21 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { fqdn := dns.Fqdn(question.Name) qtype := dns.Type(question.Qtype) + // check class + if question.Qclass != dns.ClassINET { + // we only serve IN records, return nxdomain + nxDomain(w, query) + return + } + + // handle request for localhost + if fqdn == "localhost." { + m := new(dns.Msg) + m.SetReply(query) + m.Answer = localhostIPs + w.WriteMsg(m) + } + // get addresses remoteAddr, ok := w.RemoteAddr().(*net.UDPAddr) if !ok { @@ -91,28 +107,25 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { return } - log.Tracef("nameserver: handling request for %s%s from %s:%d", fqdn, 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 - - // check class - if question.Qclass != dns.ClassINET { - // we only serve IN records, return nxdomain + // check if valid domain name + if !netutils.IsValidFqdn(fqdn) { + log.Debugf("nameserver: domain name %s is invalid, returning nxdomain", fqdn) nxDomain(w, query) return } - // handle request for localhost - if fqdn == "localhost." { - m := new(dns.Msg) - m.SetReply(query) - m.Answer = localhostIPs - w.WriteMsg(m) - } + // start tracer + ctx := log.AddTracer(context.Background()) + log.Tracer(ctx).Tracef("nameserver: handling new request for %s%s from %s:%d", fqdn, qtype, remoteAddr.IP, remoteAddr.Port) - // check if valid domain name - if !netutils.IsValidFqdn(fqdn) { - log.Tracef("nameserver: domain name %s is invalid, returning nxdomain", fqdn) + // TODO: if there are 3 request for the same domain/type in a row, delete all caches of that domain + + // get connection + // start = time.Now() + comm, err := network.GetCommunicationByDNSRequest(ctx, remoteAddr.IP, uint16(remoteAddr.Port), fqdn) + // log.Tracef("nameserver: took %s to get comms (and maybe process)", time.Since(start)) + if err != nil { + log.ErrorTracef(ctx, "nameserver: could not identify process of %s:%d, returning nxdomain: %s", remoteAddr.IP, remoteAddr.Port, err) nxDomain(w, query) return } @@ -122,44 +135,29 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { lms := algs.LmsScoreOfDomain(fqdn) // log.Tracef("nameserver: domain %s has lms score of %f", fqdn, lms) if lms < 10 { - log.Tracef("nameserver: possible data tunnel: %s has lms score of %f, returning nxdomain", fqdn, lms) + log.WarningTracef(ctx, "nameserver: possible data tunnel by %s: %s has lms score of %f, returning nxdomain", comm.Process(), fqdn, lms) nxDomain(w, query) return } - // [1/2] use this to time how long it takes to get process info - // timed := time.Now() - - // get connection - // start = time.Now() - comm, err := network.GetCommunicationByDNSRequest(remoteAddr.IP, uint16(remoteAddr.Port), fqdn) - // log.Tracef("nameserver: took %s to get comms (and maybe process)", time.Since(start)) - if err != nil { - log.Warningf("nameserver: someone is requesting %s, but could not identify process: %s, returning nxdomain", fqdn, err) - nxDomain(w, query) - return - } - - // [2/2] use this to time how long it takes to get process info - // log.Tracef("nameserver: took %s to get connection/process of %s request", time.Now().Sub(timed).String(), fqdn) - // check profile before we even get intel and rr // start = time.Now() firewall.DecideOnCommunicationBeforeIntel(comm, fqdn) // log.Tracef("nameserver: took %s to make decision", time.Since(start)) if comm.GetVerdict() == network.VerdictBlock || comm.GetVerdict() == network.VerdictDrop { + log.InfoTracef(ctx, "nameserver: %s denied before intel, returning nxdomain", comm) nxDomain(w, query) return } // get intel and RRs // start = time.Now() - domainIntel, rrCache := intel.GetIntelAndRRs(fqdn, qtype, comm.Process().ProfileSet().SecurityLevel()) + domainIntel, rrCache := intel.GetIntelAndRRs(ctx, fqdn, qtype, comm.Process().ProfileSet().SecurityLevel()) // log.Tracef("nameserver: took %s to get intel and RRs", time.Since(start)) if rrCache == nil { // TODO: analyze nxdomain requests, malware could be trying DGA-domains - log.Infof("nameserver: %s tried to query %s, but is nxdomain", comm.Process().String(), fqdn) + log.WarningTracef(ctx, "nameserver: %s requested %s%s, is nxdomain", comm.Process(), fqdn, qtype) nxDomain(w, query) return } @@ -174,6 +172,7 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { firewall.DecideOnCommunicationAfterIntel(comm, fqdn, rrCache) switch comm.GetVerdict() { case network.VerdictUndecided, network.VerdictBlock, network.VerdictDrop: + log.InfoTracef(ctx, "nameserver: %s denied after intel, returning nxdomain", comm) nxDomain(w, query) return } @@ -181,6 +180,7 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { // filter DNS response rrCache = firewall.FilterDNSResponse(comm, fqdn, rrCache) if rrCache == nil { + log.InfoTracef(ctx, "nameserver: %s implicitly denied by filtering the dns response, returning nxdomain", comm) nxDomain(w, query) return } @@ -224,4 +224,5 @@ func handleRequest(w dns.ResponseWriter, query *dns.Msg) { m.Ns = rrCache.Ns m.Extra = rrCache.Extra w.WriteMsg(m) + log.DebugTracef(ctx, "nameserver: returning response %s%s to %s", fqdn, qtype, comm.Process()) }