logpolicy, net/dnscache: cache log server DNS lookups across dials

logtail's dialer only used dnscache in its fallback path, and built a
new Resolver per dial there, so every new connection to the log server
did a fresh DNS lookup (twice when the first dial failed). On systems
without a caching resolver, that adds up to a lot of queries for
log.tailscale.com.

Share one dnscache.Resolver across all log dialers, and have the
bootstrap path go straight to dnsfallback rather than repeating the
regular lookup. Since the cache TTL is a fixed guess, make
dnscache.Dialer expire a cached entry and look the host up again when
dialing its cached IPs fails, so a moved host isn't stuck on stale IPs.

Updates #15326

Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>
Change-Id: I6a55d72a73ed878faebc15317421a54d9ae293ca

logpolicy/logpolicy.go

@@ -797,9 +797,18 @@ func (p *Policy) Shutdown(ctx context.Context) error {
 	return nil
 }
 
+// logDNSCache is the DNS cache shared by all logtail dialers, so new
+// connections to the log server don't each cost a DNS lookup, even on
+// systems without a caching resolver.
+var logDNSCache = &dnscache.Resolver{
+	Forward:     dnscache.Get().Forward, // use default cache's forwarder
+	UseLastGood: true,
+}
+
 // MakeDialFunc creates a net.Dialer.DialContext function specialized for use
 // by logtail.
 // It does the following:
+//   - Resolves hostnames using a process-wide DNS cache.
 //   - If DNS lookup fails, consults the bootstrap DNS list of Tailscale hostnames.
 //   - If TLS connection fails, try again using LetsEncrypt's built-in root certificate,
 //     for the benefit of older OS platforms which might not include it.
@@ -810,18 +819,24 @@ func MakeDialFunc(netMon *netmon.Monitor, logf logger.Logf) netx.DialFunc {
 	if netMon == nil {
 		netMon = netmon.NewStatic()
 	}
-	return func(ctx context.Context, netw, addr string) (net.Conn, error) {
-		return dialContext(ctx, netw, addr, netMon, logf)
-	}
-}
-
-func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor, logf logger.Logf) (net.Conn, error) {
 	nd := netns.FromDialer(logf, netMon, &net.Dialer{
 		Timeout:   30 * time.Second,
 		KeepAlive: netknob.PlatformTCPKeepAlive(),
 	})
+	return makeDialFunc(nd.DialContext, netMon, logf)
+}
+
+// makeDialFunc is like [MakeDialFunc] but dials IP addresses using dial.
+func makeDialFunc(dial netx.DialFunc, netMon *netmon.Monitor, logf logger.Logf) netx.DialFunc {
+	cachedDial := dnscache.Dialer(dial, logDNSCache)
+	return func(ctx context.Context, netw, addr string) (net.Conn, error) {
+		return dialContext(ctx, netw, addr, dial, cachedDial, netMon, logf)
+	}
+}
+
+func dialContext(ctx context.Context, netw, addr string, dial, cachedDial netx.DialFunc, netMon *netmon.Monitor, logf logger.Logf) (net.Conn, error) {
 	t0 := time.Now()
-	c, err := nd.DialContext(ctx, netw, addr)
+	c, err := cachedDial(ctx, netw, addr)
 	d := time.Since(t0).Round(time.Millisecond)
 	if err == nil {
 		dialLog.Printf("dialed %q in %v", addr, d)
@@ -846,14 +861,24 @@ func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor,
 		}
 	}
 
-	// If we failed to dial, try again with bootstrap DNS.
+	// Either regular DNS (via logDNSCache) failed or the IPs it gave us
+	// didn't work, so try again with IPs from bootstrap DNS.
 	logf("logtail: dial %q failed: %v (in %v), trying bootstrap...", addr, err, d)
-	dnsCache := &dnscache.Resolver{
-		Forward:          dnscache.Get().Forward, // use default cache's forwarder
-		UseLastGood:      true,
-		LookupIPFallback: dnsfallback.MakeLookupFunc(logf, netMon),
+	host, _, err := net.SplitHostPort(addr)
+	if err != nil {
+		return nil, err
 	}
-	dialer := dnscache.Dialer(nd.DialContext, dnsCache)
+	ips, err := dnsfallback.MakeLookupFunc(logf, netMon)(ctx, host)
+	if err != nil {
+		return nil, err
+	}
+	if len(ips) == 0 {
+		return nil, fmt.Errorf("no bootstrap DNS results for %q", host)
+	}
+	dialer := dnscache.Dialer(dial, &dnscache.Resolver{
+		SingleHost:             host,
+		SingleHostStaticResult: ips,
+	})
 	c, err = dialer(ctx, netw, addr)
 	if err == nil {
 		logf("logtail: bootstrap dial succeeded")

logpolicy/logpolicy_test.go

@@ -4,12 +4,18 @@
 package logpolicy
 
 import (
+	"context"
 	"net/http"
+	"net/netip"
 	"os"
 	"reflect"
+	"sync/atomic"
 	"testing"
 
 	"tailscale.com/logtail"
+	"tailscale.com/net/dnscache"
+	"tailscale.com/net/memnet"
+	"tailscale.com/tstest"
 )
 
 func resetLogTarget() {
@@ -128,3 +134,47 @@ func TestInvalidLogTarget(t *testing.T) {
 		})
 	}
 }
+
+// TestDialSharesDNSCache verifies that repeated dials, including from
+// separate dial funcs (as used by separate log transports), share one DNS
+// lookup.
+func TestDialSharesDNSCache(t *testing.T) {
+	var mn memnet.Network
+	ln, err := mn.Listen("tcp", "127.0.0.1:443")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer ln.Close()
+	go func() {
+		for {
+			c, err := ln.Accept()
+			if err != nil {
+				return
+			}
+			c.Close()
+		}
+	}()
+
+	var lookups atomic.Int32
+	tstest.Replace(t, &logDNSCache, &dnscache.Resolver{
+		UseLastGood: true,
+		LookupIPForTest: func(ctx context.Context, host string) ([]netip.Addr, error) {
+			lookups.Add(1)
+			return []netip.Addr{netip.MustParseAddr("127.0.0.1")}, nil
+		},
+	})
+
+	for range 2 {
+		dial := makeDialFunc(mn.Dial, nil, t.Logf)
+		for range 3 {
+			c, err := dial(t.Context(), "tcp", "log.example.com:443")
+			if err != nil {
+				t.Fatal(err)
+			}
+			c.Close()
+		}
+	}
+	if got := lookups.Load(); got != 1 {
+		t.Errorf("got %d DNS lookups; want 1", got)
+	}
+}

net/dnscache/dnscache.go

@@ -163,7 +163,7 @@ type ipCacheEntry struct {
 	ip      netip.Addr   // either v4 or v6
 	ip6     netip.Addr   // nil if no v4 or no v6
 	allIPs  []netip.Addr // 1+ v4 and/or v6
-	expires time.Time
+	expires time.Time    // fresh until then; zero means expired (see expireIPCache)
 }
 
 func (r *Resolver) fwd() *net.Resolver {
@@ -310,6 +310,18 @@ func (r *Resolver) lookupIPCache(host string) (ip, ip6 netip.Addr, allIPs []neti
 	return zaddr, zaddr, nil, false
 }
 
+// expireIPCache marks host's cache entry, if any, as expired by zeroing
+// its expires time, so the next lookup goes to the network. The entry
+// remains available to [Resolver.UseLastGood].
+func (r *Resolver) expireIPCache(host string) {
+	r.mu.Lock()
+	defer r.mu.Unlock()
+	if ent, ok := r.ipCache[host]; ok {
+		ent.expires = time.Time{}
+		r.ipCache[host] = ent
+	}
+}
+
 func (r *Resolver) lookupIPCacheExpired(host string) (ip, ip6 netip.Addr, allIPs []netip.Addr, ok bool) {
 	r.mu.Lock()
 	defer r.mu.Unlock()
@@ -499,15 +511,39 @@ func (d *dialer) DialContext(ctx context.Context, network, address string) (retC
 		}
 	}()
 
-	ip, _, allIPs, err := d.dnsCache.LookupIP(ctx, host)
-	if err != nil {
-		return nil, fmt.Errorf("failed to resolve %q: %w", host, err)
+	ip, _, allIPs, fromCache := d.dnsCache.lookupIPCache(host)
+	if fromCache {
+		d.dnsCache.dlogf("%q = %v (cached)", host, ip)
+	} else {
+		ip, _, allIPs, err = d.dnsCache.LookupIP(ctx, host)
+		if err != nil {
+			return nil, fmt.Errorf("failed to resolve %q: %w", host, err)
+		}
 	}
 
+	c, err := dc.dialIPs(ctx, ip, allIPs)
+	if err == nil || !fromCache || ctx.Err() != nil {
+		return c, err
+	}
+
+	// The cached IPs might be stale. Expire the cache entry (keeping it
+	// around for UseLastGood) and look up host again, dialing any new IPs.
+	d.dnsCache.expireIPCache(host)
+	if _, _, allIPs, err2 := d.dnsCache.LookupIP(ctx, host); err2 == nil {
+		if c, err2 := dc.raceDial(ctx, allIPs); err2 == nil {
+			return c, nil
+		}
+	}
+	return nil, err
+}
+
+// dialIPs dials ip if it's the only candidate in allIPs, or else races
+// dials to all of allIPs.
+func (dc *dialCall) dialIPs(ctx context.Context, ip netip.Addr, allIPs []netip.Addr) (net.Conn, error) {
 	// If we only have one candidate, just dial that, no matter what the
 	// address family is.
 	if len(allIPs) == 1 {
-		d.dnsCache.dlogf("dialing %s, %s for %s", network, ip, address)
+		dc.d.dnsCache.dlogf("dialing %s, %s for %s", dc.network, ip, dc.address)
 		return dc.dialOne(ctx, ip.Unmap())
 	}
 

net/dnscache/dnscache_test.go

@@ -573,3 +573,66 @@ func TestTLSDialerHostVerifiedHook(t *testing.T) {
 		}
 	})
 }
+
+func TestDialerRefreshesStaleCache(t *testing.T) {
+	ipA := netip.MustParseAddr("192.0.2.1")
+	ipB := netip.MustParseAddr("192.0.2.2")
+
+	var (
+		dnsAnswer = ipA
+		lookups   int
+		reachable = map[netip.Addr]bool{ipA: true}
+		dialed    []netip.Addr
+	)
+	r := &Resolver{
+		UseLastGood: true,
+		LookupIPForTest: func(ctx context.Context, host string) ([]netip.Addr, error) {
+			lookups++
+			return []netip.Addr{dnsAnswer}, nil
+		},
+	}
+	fwd := func(ctx context.Context, network, address string) (net.Conn, error) {
+		ip := netip.MustParseAddrPort(address).Addr()
+		dialed = append(dialed, ip)
+		if !reachable[ip] {
+			return nil, fmt.Errorf("can't reach %v", ip)
+		}
+		c1, c2 := net.Pipe()
+		c2.Close()
+		return c1, nil
+	}
+	dial := Dialer(fwd, r)
+
+	check := func(name string, wantErr bool, wantLookups int, wantDialed ...netip.Addr) {
+		t.Helper()
+		dialed = nil
+		c, err := dial(t.Context(), "tcp", "example.com:443")
+		if c != nil {
+			c.Close()
+		}
+		if (err != nil) != wantErr {
+			t.Errorf("%s: err = %v; want error = %v", name, err, wantErr)
+		}
+		if lookups != wantLookups {
+			t.Errorf("%s: lookups = %d; want %d", name, lookups, wantLookups)
+		}
+		if !slices.Equal(dialed, wantDialed) {
+			t.Errorf("%s: dialed %v; want %v", name, dialed, wantDialed)
+		}
+	}
+
+	check("first", false, 1, ipA)
+	check("cached", false, 1, ipA)
+
+	// The host moves. The cached IP fails, so the dialer should look the
+	// host up again and dial the new IP.
+	dnsAnswer = ipB
+	reachable = map[netip.Addr]bool{ipB: true}
+	check("moved", false, 2, ipA, ipB)
+	check("cached-after-move", false, 2, ipB)
+
+	// The host is unreachable but its DNS hasn't changed. The dialer
+	// should look it up once more but not redial the same IP.
+	reachable = nil
+	check("unreachable", true, 3, ipB)
+}