appc,ipn/ipnlocal: log DNS parsing errors in app connectors (#14607)

If we fail to parse the upstream DNS response in an app connector, we
might miss new IPs for the target domain. Log parsing errors to be able
to diagnose that.

Updates #14606

Signed-off-by: Andrew Lytvynov <awly@tailscale.com>

appc/appconnector.go

@@ -374,13 +374,13 @@ func (e *AppConnector) DomainRoutes() map[string][]netip.Addr {
 // response is being returned over the PeerAPI. The response is parsed and
 // matched against the configured domains, if matched the routeAdvertiser is
 // advised to advertise the discovered route.
-func (e *AppConnector) ObserveDNSResponse(res []byte) {
+func (e *AppConnector) ObserveDNSResponse(res []byte) error {
 	var p dnsmessage.Parser
 	if _, err := p.Start(res); err != nil {
-		return
+		return err
 	}
 	if err := p.SkipAllQuestions(); err != nil {
-		return
+		return err
 	}
 
 	// cnameChain tracks a chain of CNAMEs for a given query in order to reverse
@@ -399,12 +399,12 @@ func (e *AppConnector) ObserveDNSResponse(res []byte) {
 			break
 		}
 		if err != nil {
-			return
+			return err
 		}
 
 		if h.Class != dnsmessage.ClassINET {
 			if err := p.SkipAnswer(); err != nil {
-				return
+				return err
 			}
 			continue
 		}
@@ -413,7 +413,7 @@ func (e *AppConnector) ObserveDNSResponse(res []byte) {
 		case dnsmessage.TypeCNAME, dnsmessage.TypeA, dnsmessage.TypeAAAA:
 		default:
 			if err := p.SkipAnswer(); err != nil {
-				return
+				return err
 			}
 			continue
 
@@ -427,7 +427,7 @@ func (e *AppConnector) ObserveDNSResponse(res []byte) {
 		if h.Type == dnsmessage.TypeCNAME {
 			res, err := p.CNAMEResource()
 			if err != nil {
-				return
+				return err
 			}
 			cname := strings.TrimSuffix(strings.ToLower(res.CNAME.String()), ".")
 			if len(cname) == 0 {
@@ -441,20 +441,20 @@ func (e *AppConnector) ObserveDNSResponse(res []byte) {
 		case dnsmessage.TypeA:
 			r, err := p.AResource()
 			if err != nil {
-				return
+				return err
 			}
 			addr := netip.AddrFrom4(r.A)
 			mak.Set(&addressRecords, domain, append(addressRecords[domain], addr))
 		case dnsmessage.TypeAAAA:
 			r, err := p.AAAAResource()
 			if err != nil {
-				return
+				return err
 			}
 			addr := netip.AddrFrom16(r.AAAA)
 			mak.Set(&addressRecords, domain, append(addressRecords[domain], addr))
 		default:
 			if err := p.SkipAnswer(); err != nil {
-				return
+				return err
 			}
 			continue
 		}
@@ -485,6 +485,7 @@ func (e *AppConnector) ObserveDNSResponse(res []byte) {
 			e.scheduleAdvertisement(domain, toAdvertise...)
 		}
 	}
+	return nil
 }
 
 // starting from the given domain that resolved to an address, find it, or any

appc/appconnector_test.go

@@ -69,7 +69,9 @@ func TestUpdateRoutes(t *testing.T) {
 		a.updateDomains([]string{"*.example.com"})
 
 		// This route should be collapsed into the range
-		a.ObserveDNSResponse(dnsResponse("a.example.com.", "192.0.2.1"))
+		if err := a.ObserveDNSResponse(dnsResponse("a.example.com.", "192.0.2.1")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 
 		if !slices.Equal(rc.Routes(), []netip.Prefix{netip.MustParsePrefix("192.0.2.1/32")}) {
@@ -77,7 +79,9 @@ func TestUpdateRoutes(t *testing.T) {
 		}
 
 		// This route should not be collapsed or removed
-		a.ObserveDNSResponse(dnsResponse("b.example.com.", "192.0.0.1"))
+		if err := a.ObserveDNSResponse(dnsResponse("b.example.com.", "192.0.0.1")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 
 		routes := []netip.Prefix{netip.MustParsePrefix("192.0.2.0/24"), netip.MustParsePrefix("192.0.0.1/32")}
@@ -130,7 +134,9 @@ func TestDomainRoutes(t *testing.T) {
 			a = NewAppConnector(t.Logf, rc, nil, nil)
 		}
 		a.updateDomains([]string{"example.com"})
-		a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(context.Background())
 
 		want := map[string][]netip.Addr{
@@ -155,7 +161,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		}
 
 		// a has no domains configured, so it should not advertise any routes
-		a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		if got, want := rc.Routes(), ([]netip.Prefix)(nil); !slices.Equal(got, want) {
 			t.Errorf("got %v; want %v", got, want)
 		}
@@ -163,7 +171,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		wantRoutes := []netip.Prefix{netip.MustParsePrefix("192.0.0.8/32")}
 
 		a.updateDomains([]string{"example.com"})
-		a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		if got, want := rc.Routes(), wantRoutes; !slices.Equal(got, want) {
 			t.Errorf("got %v; want %v", got, want)
@@ -172,7 +182,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		// a CNAME record chain should result in a route being added if the chain
 		// matches a routed domain.
 		a.updateDomains([]string{"www.example.com", "example.com"})
-		a.ObserveDNSResponse(dnsCNAMEResponse("192.0.0.9", "www.example.com.", "chain.example.com.", "example.com."))
+		if err := a.ObserveDNSResponse(dnsCNAMEResponse("192.0.0.9", "www.example.com.", "chain.example.com.", "example.com.")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		wantRoutes = append(wantRoutes, netip.MustParsePrefix("192.0.0.9/32"))
 		if got, want := rc.Routes(), wantRoutes; !slices.Equal(got, want) {
@@ -181,7 +193,9 @@ func TestObserveDNSResponse(t *testing.T) {
 
 		// a CNAME record chain should result in a route being added if the chain
 		// even if only found in the middle of the chain
-		a.ObserveDNSResponse(dnsCNAMEResponse("192.0.0.10", "outside.example.org.", "www.example.com.", "example.org."))
+		if err := a.ObserveDNSResponse(dnsCNAMEResponse("192.0.0.10", "outside.example.org.", "www.example.com.", "example.org.")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		wantRoutes = append(wantRoutes, netip.MustParsePrefix("192.0.0.10/32"))
 		if got, want := rc.Routes(), wantRoutes; !slices.Equal(got, want) {
@@ -190,14 +204,18 @@ func TestObserveDNSResponse(t *testing.T) {
 
 		wantRoutes = append(wantRoutes, netip.MustParsePrefix("2001:db8::1/128"))
 
-		a.ObserveDNSResponse(dnsResponse("example.com.", "2001:db8::1"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "2001:db8::1")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		if got, want := rc.Routes(), wantRoutes; !slices.Equal(got, want) {
 			t.Errorf("got %v; want %v", got, want)
 		}
 
 		// don't re-advertise routes that have already been advertised
-		a.ObserveDNSResponse(dnsResponse("example.com.", "2001:db8::1"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "2001:db8::1")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		if !slices.Equal(rc.Routes(), wantRoutes) {
 			t.Errorf("rc.Routes(): got %v; want %v", rc.Routes(), wantRoutes)
@@ -207,7 +225,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		pfx := netip.MustParsePrefix("192.0.2.0/24")
 		a.updateRoutes([]netip.Prefix{pfx})
 		wantRoutes = append(wantRoutes, pfx)
-		a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.2.1"))
+		if err := a.ObserveDNSResponse(dnsResponse("example.com.", "192.0.2.1")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		if !slices.Equal(rc.Routes(), wantRoutes) {
 			t.Errorf("rc.Routes(): got %v; want %v", rc.Routes(), wantRoutes)
@@ -230,7 +250,9 @@ func TestWildcardDomains(t *testing.T) {
 		}
 
 		a.updateDomains([]string{"*.example.com"})
-		a.ObserveDNSResponse(dnsResponse("foo.example.com.", "192.0.0.8"))
+		if err := a.ObserveDNSResponse(dnsResponse("foo.example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		a.Wait(ctx)
 		if got, want := rc.Routes(), []netip.Prefix{netip.MustParsePrefix("192.0.0.8/32")}; !slices.Equal(got, want) {
 			t.Errorf("routes: got %v; want %v", got, want)
@@ -438,10 +460,16 @@ func TestUpdateDomainRouteRemoval(t *testing.T) {
 		// adding domains doesn't immediately cause any routes to be advertised
 		assertRoutes("update domains", []netip.Prefix{}, []netip.Prefix{})
 
-		a.ObserveDNSResponse(dnsResponse("a.example.com.", "1.2.3.1"))
-		a.ObserveDNSResponse(dnsResponse("a.example.com.", "1.2.3.2"))
-		a.ObserveDNSResponse(dnsResponse("b.example.com.", "1.2.3.3"))
-		a.ObserveDNSResponse(dnsResponse("b.example.com.", "1.2.3.4"))
+		for _, res := range [][]byte{
+			dnsResponse("a.example.com.", "1.2.3.1"),
+			dnsResponse("a.example.com.", "1.2.3.2"),
+			dnsResponse("b.example.com.", "1.2.3.3"),
+			dnsResponse("b.example.com.", "1.2.3.4"),
+		} {
+			if err := a.ObserveDNSResponse(res); err != nil {
+				t.Errorf("ObserveDNSResponse: %v", err)
+			}
+		}
 		a.Wait(ctx)
 		// observing dns responses causes routes to be advertised
 		assertRoutes("observed dns", prefixes("1.2.3.1/32", "1.2.3.2/32", "1.2.3.3/32", "1.2.3.4/32"), []netip.Prefix{})
@@ -487,10 +515,16 @@ func TestUpdateWildcardRouteRemoval(t *testing.T) {
 		// adding domains doesn't immediately cause any routes to be advertised
 		assertRoutes("update domains", []netip.Prefix{}, []netip.Prefix{})
 
-		a.ObserveDNSResponse(dnsResponse("a.example.com.", "1.2.3.1"))
-		a.ObserveDNSResponse(dnsResponse("a.example.com.", "1.2.3.2"))
-		a.ObserveDNSResponse(dnsResponse("1.b.example.com.", "1.2.3.3"))
-		a.ObserveDNSResponse(dnsResponse("2.b.example.com.", "1.2.3.4"))
+		for _, res := range [][]byte{
+			dnsResponse("a.example.com.", "1.2.3.1"),
+			dnsResponse("a.example.com.", "1.2.3.2"),
+			dnsResponse("1.b.example.com.", "1.2.3.3"),
+			dnsResponse("2.b.example.com.", "1.2.3.4"),
+		} {
+			if err := a.ObserveDNSResponse(res); err != nil {
+				t.Errorf("ObserveDNSResponse: %v", err)
+			}
+		}
 		a.Wait(ctx)
 		// observing dns responses causes routes to be advertised
 		assertRoutes("observed dns", prefixes("1.2.3.1/32", "1.2.3.2/32", "1.2.3.3/32", "1.2.3.4/32"), []netip.Prefix{})

ipn/ipnlocal/local.go

@@ -7276,17 +7276,17 @@ func (b *LocalBackend) DoSelfUpdate() {
 
 // ObserveDNSResponse passes a DNS response from the PeerAPI DNS server to the
 // App Connector to enable route discovery.
-func (b *LocalBackend) ObserveDNSResponse(res []byte) {
+func (b *LocalBackend) ObserveDNSResponse(res []byte) error {
 	var appConnector *appc.AppConnector
 	b.mu.Lock()
 	if b.appConnector == nil {
 		b.mu.Unlock()
-		return
+		return nil
 	}
 	appConnector = b.appConnector
 	b.mu.Unlock()
 
-	appConnector.ObserveDNSResponse(res)
+	return appConnector.ObserveDNSResponse(res)
 }
 
 // ErrDisallowedAutoRoute is returned by AdvertiseRoute when a route that is not allowed is requested.

ipn/ipnlocal/local_test.go

@@ -1372,7 +1372,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		b := newTestBackend(t)
 
 		// ensure no error when no app connector is configured
-		b.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8"))
+		if err := b.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 
 		rc := &appctest.RouteCollector{}
 		if shouldStore {
@@ -1383,7 +1385,9 @@ func TestObserveDNSResponse(t *testing.T) {
 		b.appConnector.UpdateDomains([]string{"example.com"})
 		b.appConnector.Wait(context.Background())
 
-		b.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8"))
+		if err := b.ObserveDNSResponse(dnsResponse("example.com.", "192.0.0.8")); err != nil {
+			t.Errorf("ObserveDNSResponse: %v", err)
+		}
 		b.appConnector.Wait(context.Background())
 		wantRoutes := []netip.Prefix{netip.MustParsePrefix("192.0.0.8/32")}
 		if !slices.Equal(rc.Routes(), wantRoutes) {

ipn/ipnlocal/peerapi.go

@@ -932,7 +932,11 @@ func (h *peerAPIHandler) handleDNSQuery(w http.ResponseWriter, r *http.Request)
 	// instead to avoid re-parsing the DNS response for improved performance in
 	// the future.
 	if h.ps.b.OfferingAppConnector() {
-		h.ps.b.ObserveDNSResponse(res)
+		if err := h.ps.b.ObserveDNSResponse(res); err != nil {
+			h.logf("ObserveDNSResponse error: %v", err)
+			// This is not fatal, we probably just failed to parse the upstream
+			// response. Return it to the caller anyway.
+		}
 	}
 
 	if pretty {