add logs for dns routes

client/internal/dns/handler_chain.go

@@ -92,6 +92,8 @@ func (c *HandlerChain) AddHandler(pattern string, handler dns.Handler, priority
 	c.mu.Lock()
 	defer c.mu.Unlock()
 
+	log.Warnf("[DNS-ROUTE] HandlerChain.AddHandler: pattern=%s priority=%d handler=%T", pattern, priority, handler)
+
 	pattern = strings.ToLower(dns.Fqdn(pattern))
 	origPattern := pattern
 	isWildcard := strings.HasPrefix(pattern, "*.")
@@ -108,6 +110,8 @@ func (c *HandlerChain) AddHandler(pattern string, handler dns.Handler, priority
 		matchSubdomains = matcher.MatchSubdomains()
 	}
 
+	log.Warnf("[DNS-ROUTE] HandlerChain.AddHandler: processed pattern=%s origPattern=%s wildcard=%v matchSubdomains=%v priority=%d",
+		pattern, origPattern, isWildcard, matchSubdomains, priority)
 	log.Debugf("adding handler pattern: domain=%s original: domain=%s wildcard=%v match_subdomain=%v priority=%d",
 		pattern, origPattern, isWildcard, matchSubdomains, priority)
 
@@ -123,6 +127,7 @@ func (c *HandlerChain) AddHandler(pattern string, handler dns.Handler, priority
 	pos := c.findHandlerPosition(entry)
 	c.handlers = append(c.handlers[:pos], append([]HandlerEntry{entry}, c.handlers[pos:]...)...)
 
+	log.Warnf("[DNS-ROUTE] HandlerChain.AddHandler: total handlers now=%d", len(c.handlers))
 	c.logHandlers()
 }
 
@@ -212,6 +217,11 @@ func (c *HandlerChain) ServeDNS(w dns.ResponseWriter, r *dns.Msg) {
 		if !c.isHandlerMatch(qname, entry) {
 			continue
 		}
+		// Only log for DNS route handlers to reduce noise
+		if entry.Priority == PriorityDNSRoute {
+			log.Warnf("[DNS-ROUTE] HandlerChain.ServeDNS: matched DNS route handler pattern=%s for domain=%s",
+				entry.OrigPattern, qname)
+		}
 
 		handlerName := entry.OrigPattern
 		if s, ok := entry.Handler.(interface{ String() string }); ok {

client/internal/dns/server.go

@@ -220,6 +220,8 @@ func newDefaultServer(
 // RegisterHandler registers a handler for the given domains with the given priority.
 // Any previously registered handler for the same domain and priority will be replaced.
 func (s *DefaultServer) RegisterHandler(domains domain.List, handler dns.Handler, priority int) {
+	log.Warnf("[DNS-ROUTE] DefaultServer.RegisterHandler: domains=%v priority=%d", domains.SafeString(), priority)
+
 	s.mux.Lock()
 	defer s.mux.Unlock()
 
@@ -230,10 +232,12 @@ func (s *DefaultServer) RegisterHandler(domains domain.List, handler dns.Handler
 		// convert to zone with simple ref counter
 		s.extraDomains[toZone(domain)]++
 	}
+	log.Warnf("[DNS-ROUTE] DefaultServer.RegisterHandler: extraDomains now has %d entries", len(s.extraDomains))
 	s.applyHostConfig()
 }
 
 func (s *DefaultServer) registerHandler(domains []string, handler dns.Handler, priority int) {
+	log.Warnf("[DNS-ROUTE] registerHandler: domains=%v priority=%d handler=%T", domains, priority, handler)
 	log.Debugf("registering handler %s with priority %d for %v", handler, priority, domains)
 
 	for _, domain := range domains {
@@ -242,6 +246,7 @@ func (s *DefaultServer) registerHandler(domains []string, handler dns.Handler, p
 			continue
 		}
 
+		log.Warnf("[DNS-ROUTE] registerHandler: adding to handlerChain domain=%s priority=%d", domain, priority)
 		s.handlerChain.AddHandler(domain, handler, priority)
 	}
 }
@@ -563,6 +568,7 @@ func (s *DefaultServer) enableDNS() error {
 func (s *DefaultServer) applyHostConfig() {
 	// prevent reapplying config if we're shutting down
 	if s.ctx.Err() != nil {
+		log.Warnf("[DNS-ROUTE] applyHostConfig: skipped, context is done")
 		return
 	}
 
@@ -585,6 +591,8 @@ func (s *DefaultServer) applyHostConfig() {
 		}
 	}
 
+	log.Warnf("[DNS-ROUTE] applyHostConfig: routeAll=%v domains=%d extraDomains=%v",
+		config.RouteAll, len(config.Domains), maps.Keys(s.extraDomains))
 	log.Debugf("extra match domains: %v", maps.Keys(s.extraDomains))
 
 	hash, err := hashstructure.Hash(config, hashstructure.FormatV2, &hashstructure.HashOptions{
@@ -594,18 +602,21 @@ func (s *DefaultServer) applyHostConfig() {
 		UseStringer:     true,
 	})
 	if err != nil {
-		log.Warnf("unable to hash the host dns configuration, will apply config anyway: %s", err)
+		log.Warnf("[DNS-ROUTE] applyHostConfig: hash error, applying anyway: %s", err)
 		// Fall through to apply config anyway (fail-safe approach)
 	} else if s.currentConfigHash == hash {
-		log.Debugf("not applying host config as there are no changes")
+		log.Warnf("[DNS-ROUTE] applyHostConfig: skipped, no changes (hash=%d)", hash)
 		return
 	}
 
+	log.Warnf("[DNS-ROUTE] applyHostConfig: applying new config (oldHash=%d newHash=%d)", s.currentConfigHash, hash)
 	log.Debugf("applying host config as there are changes")
 	if err := s.hostManager.applyDNSConfig(config, s.stateManager); err != nil {
+		log.Warnf("[DNS-ROUTE] applyHostConfig: failed to apply: %v", err)
 		log.Errorf("failed to apply DNS host manager update: %v", err)
 		return
 	}
+	log.Warnf("[DNS-ROUTE] applyHostConfig: successfully applied")
 
 	// Only update hash if it was computed successfully and config was applied
 	if err == nil {

client/internal/routemanager/client/client.go

@@ -85,6 +85,8 @@ type Watcher struct {
 func NewWatcher(config WatcherConfig) *Watcher {
 	ctx, cancel := context.WithCancel(config.Context)
 
+	log.Warnf("[DNS-ROUTE] NewWatcher: creating watcher for handler=%s route=%s", config.Handler.String(), config.Route.Network)
+
 	client := &Watcher{
 		ctx:                 ctx,
 		cancel:              cancel,
@@ -283,10 +285,15 @@ func (w *Watcher) startNewPeerStatusWatchers() {
 
 // addAllowedIPs adds the allowed IPs for the current chosen route to the handler.
 func (w *Watcher) addAllowedIPs(route *route.Route) error {
+	log.Warnf("[DNS-ROUTE] Watcher.addAllowedIPs: handler=%s peer=%s network=%s", w.handler.String(), route.Peer, route.Network)
+
 	if err := w.handler.AddAllowedIPs(route.Peer); err != nil {
+		log.Warnf("[DNS-ROUTE] Watcher.addAllowedIPs: failed handler=%s peer=%s: %v", w.handler.String(), route.Peer, err)
 		return fmt.Errorf("add allowed IPs for peer %s: %w", route.Peer, err)
 	}
 
+	log.Warnf("[DNS-ROUTE] Watcher.addAllowedIPs: success handler=%s peer=%s", w.handler.String(), route.Peer)
+
 	if err := w.statusRecorder.AddPeerStateRoute(route.Peer, w.handler.String(), route.GetResourceID()); err != nil {
 		log.Warnf("Failed to update peer state: %v", err)
 	}
@@ -328,14 +335,21 @@ func (w *Watcher) shouldSkipRecalculation(newChosenID route.ID, newStatus router
 }
 
 func (w *Watcher) recalculateRoutes(rsn reason, routerPeerStatuses map[route.ID]routerPeerStatus) error {
+	log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s reason=%d peerStatuses=%d currentChosen=%v",
+		w.handler.String(), rsn, len(routerPeerStatuses), w.currentChosen != nil)
+
 	newChosenID, newStatus := w.getBestRouteFromStatuses(routerPeerStatuses)
+	log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s newChosenID=%s newStatus=%+v",
+		w.handler.String(), newChosenID, newStatus)
 
 	// If no route is chosen, remove the route from the peer
 	if newChosenID == "" {
 		if w.currentChosen == nil {
+			log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s no route chosen and no current, nothing to do", w.handler.String())
 			return nil
 		}
 
+		log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s removing obsolete route", w.handler.String())
 		if err := w.removeAllowedIPs(w.currentChosen, rsn); err != nil {
 			return fmt.Errorf("remove obsolete: %w", err)
 		}
@@ -348,17 +362,21 @@ func (w *Watcher) recalculateRoutes(rsn reason, routerPeerStatuses map[route.ID]
 
 	// If we can skip recalculation for the same route without changes, do nothing
 	if w.shouldSkipRecalculation(newChosenID, newStatus) {
+		log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s skipping recalculation, same route", w.handler.String())
 		return nil
 	}
 
 	// If the chosen route was assigned to a different peer, remove the allowed IPs first
 	if isNew := w.currentChosen == nil; !isNew {
+		log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s removing old route for HA switch", w.handler.String())
 		if err := w.removeAllowedIPs(w.currentChosen, reasonHA); err != nil {
 			return fmt.Errorf("remove old: %w", err)
 		}
 	}
 
 	newChosenRoute := w.routes[newChosenID]
+	log.Warnf("[DNS-ROUTE] Watcher.recalculateRoutes: handler=%s adding new route peer=%s network=%s",
+		w.handler.String(), newChosenRoute.Peer, newChosenRoute.Network)
 	if err := w.addAllowedIPs(newChosenRoute); err != nil {
 		return fmt.Errorf("add new: %w", err)
 	}
@@ -517,6 +535,8 @@ func (w *Watcher) Start() {
 }
 
 func (w *Watcher) handleRouteUpdate(update RoutesUpdate) {
+	log.Warnf("[DNS-ROUTE] Watcher.handleRouteUpdate: handler=%s serial=%d routes=%d",
+		w.handler.String(), update.UpdateSerial, len(update.Routes))
 	log.Debugf("Received a new client network route update for [%v]", w.handler)
 
 	// hash update somehow
@@ -525,12 +545,15 @@ func (w *Watcher) handleRouteUpdate(update RoutesUpdate) {
 	w.updateSerial = update.UpdateSerial
 
 	if isTrueRouteUpdate {
+		log.Warnf("[DNS-ROUTE] Watcher.handleRouteUpdate: handler=%s routes changed, recalculating", w.handler.String())
 		log.Debugf("client network update %v for [%v] contains different routes, recalculating routes", update.UpdateSerial, w.handler)
 		routePeerStatuses := w.getRouterPeerStatuses()
+		log.Warnf("[DNS-ROUTE] Watcher.handleRouteUpdate: handler=%s peerStatuses=%d", w.handler.String(), len(routePeerStatuses))
 		if err := w.recalculateRoutes(reasonRouteUpdate, routePeerStatuses); err != nil {
 			log.Errorf("failed to recalculate routes for network [%v]: %v", w.handler, err)
 		}
 	} else {
+		log.Warnf("[DNS-ROUTE] Watcher.handleRouteUpdate: handler=%s no changes, skipping", w.handler.String())
 		log.Debugf("route update %v for [%v] is not different, skipping route recalculation", update.UpdateSerial, w.handler)
 	}
 
@@ -553,7 +576,20 @@ func (w *Watcher) Stop() {
 }
 
 func HandlerFromRoute(params common.HandlerParams) RouteHandler {
-	switch handlerType(params.Route, params.UseNewDNSRoute) {
+	ht := handlerType(params.Route, params.UseNewDNSRoute)
+	var handlerName string
+	switch ht {
+	case handlerTypeDnsInterceptor:
+		handlerName = "DnsInterceptor"
+	case handlerTypeDynamic:
+		handlerName = "Dynamic"
+	default:
+		handlerName = "Static"
+	}
+	log.Warnf("[DNS-ROUTE] HandlerFromRoute: route=%s isDynamic=%v useNewDNSRoute=%v -> handler=%s",
+		params.Route.Network, params.Route.IsDynamic(), params.UseNewDNSRoute, handlerName)
+
+	switch ht {
 	case handlerTypeDnsInterceptor:
 		return dnsinterceptor.New(params)
 	case handlerTypeDynamic:

client/internal/routemanager/dnsinterceptor/handler.go

@@ -75,6 +75,7 @@ func (d *DnsInterceptor) String() string {
 }
 
 func (d *DnsInterceptor) AddRoute(context.Context) error {
+	log.Warnf("[DNS-ROUTE] Registering DNS interceptor for domains: %v", d.route.Domains.SafeString())
 	d.dnsServer.RegisterHandler(d.route.Domains, d, nbdns.PriorityDNSRoute)
 	return nil
 }
@@ -151,12 +152,16 @@ func (d *DnsInterceptor) addAllowedIPForPrefix(realPrefix netip.Prefix, peerKey
 func (d *DnsInterceptor) addRouteAndAllowedIP(realPrefix netip.Prefix, domain domain.Domain) error {
 	// Routes use fake IPs (so traffic to fake IPs gets routed to interface)
 	routePrefix := d.transformRealToFakePrefix(realPrefix)
+	log.Warnf("[DNS-ROUTE] Adding route for domain=%s realIP=%s routePrefix=%s", domain.SafeString(), realPrefix, routePrefix)
 	if _, err := d.routeRefCounter.Increment(routePrefix, struct{}{}); err != nil {
+		log.Warnf("[DNS-ROUTE] Failed to add route for domain=%s prefix=%s: %v", domain.SafeString(), routePrefix, err)
 		return fmt.Errorf("add route for IP %s: %v", routePrefix, err)
 	}
+	log.Warnf("[DNS-ROUTE] Successfully added route for domain=%s prefix=%s", domain.SafeString(), routePrefix)
 
 	// Add to AllowedIPs if we have a current peer (uses real IPs)
 	if d.currentPeerKey == "" {
+		log.Warnf("[DNS-ROUTE] No current peer key, skipping AllowedIPs for domain=%s", domain.SafeString())
 		return nil
 	}
 
@@ -221,11 +226,17 @@ func (d *DnsInterceptor) ServeDNS(w dns.ResponseWriter, r *dns.Msg) {
 	})
 
 	if len(r.Question) == 0 {
+		log.Warnf("[DNS-ROUTE] ServeDNS: empty question list")
 		return
 	}
 
+	qName := r.Question[0].Name
+	qType := r.Question[0].Qtype
+	log.Warnf("[DNS-ROUTE] ServeDNS: received query for domain=%s type=%d", qName, qType)
+
 	// pass if non A/AAAA query
-	if r.Question[0].Qtype != dns.TypeA && r.Question[0].Qtype != dns.TypeAAAA {
+	if qType != dns.TypeA && qType != dns.TypeAAAA {
+		log.Warnf("[DNS-ROUTE] ServeDNS: skipping non A/AAAA query for domain=%s type=%d", qName, qType)
 		d.continueToNextHandler(w, r, logger, "non A/AAAA query")
 		return
 	}
@@ -235,9 +246,11 @@ func (d *DnsInterceptor) ServeDNS(w dns.ResponseWriter, r *dns.Msg) {
 	d.mu.RUnlock()
 
 	if peerKey == "" {
+		log.Warnf("[DNS-ROUTE] ServeDNS: no current peer key for domain=%s", qName)
 		d.writeDNSError(w, r, logger, "no current peer key")
 		return
 	}
+	log.Warnf("[DNS-ROUTE] ServeDNS: using peer=%s for domain=%s", peerKey, qName)
 
 	upstreamIP, err := d.getUpstreamIP(peerKey)
 	if err != nil {
@@ -307,6 +320,8 @@ func (d *DnsInterceptor) writeMsg(w dns.ResponseWriter, r *dns.Msg, logger *log.
 	r.MsgHdr.Zero = false
 
 	if len(r.Answer) > 0 && len(r.Question) > 0 {
+		log.Warnf("[DNS-ROUTE] writeMsg: processing %d answers for domain=%s", len(r.Answer), r.Question[0].Name)
+
 		origPattern := ""
 		if writer, ok := w.(*nbdns.ResponseWriterChain); ok {
 			origPattern = writer.GetOrigPattern()
@@ -346,12 +361,17 @@ func (d *DnsInterceptor) writeMsg(w dns.ResponseWriter, r *dns.Msg, logger *log.
 			newPrefixes = append(newPrefixes, prefix)
 		}
 
+		log.Warnf("[DNS-ROUTE] writeMsg: extracted %d prefixes for domain=%s: %v", len(newPrefixes), resolvedDomain.SafeString(), newPrefixes)
 		if len(newPrefixes) > 0 {
+			log.Warnf("[DNS-ROUTE] writeMsg: calling updateDomainPrefixes for domain=%s", resolvedDomain.SafeString())
 			if err := d.updateDomainPrefixes(resolvedDomain, originalDomain, newPrefixes, logger); err != nil {
+				log.Warnf("[DNS-ROUTE] writeMsg: updateDomainPrefixes failed for domain=%s: %v", resolvedDomain.SafeString(), err)
 				logger.Errorf("failed to update domain prefixes: %v", err)
 			}
 
 			d.replaceIPsInDNSResponse(r, newPrefixes, logger)
+		} else {
+			log.Warnf("[DNS-ROUTE] writeMsg: no prefixes to add for domain=%s", resolvedDomain.SafeString())
 		}
 	}
 
@@ -382,8 +402,13 @@ func (d *DnsInterceptor) updateDomainPrefixes(resolvedDomain, originalDomain dom
 	d.mu.Lock()
 	defer d.mu.Unlock()
 
+	log.Warnf("[DNS-ROUTE] updateDomainPrefixes: domain=%s (original=%s) newPrefixes=%v currentPeer=%s",
+		resolvedDomain.SafeString(), originalDomain.SafeString(), newPrefixes, d.currentPeerKey)
+
 	oldPrefixes := d.interceptedDomains[resolvedDomain]
 	toAdd, toRemove := determinePrefixChanges(oldPrefixes, newPrefixes)
+	log.Warnf("[DNS-ROUTE] updateDomainPrefixes: domain=%s oldPrefixes=%v toAdd=%v toRemove=%v keepRoute=%v",
+		resolvedDomain.SafeString(), oldPrefixes, toAdd, toRemove, d.route.KeepRoute)
 
 	var merr *multierror.Error
 	var dnatMappings map[netip.Addr]netip.Addr

client/internal/routemanager/manager.go

@@ -173,12 +173,23 @@ func (m *DefaultManager) setupAndroidRoutes(config ManagerConfig) {
 }
 
 func (m *DefaultManager) setupRefCounters(useNoop bool) {
+	i := m.wgInterface.ToInterface()
+	log.Warnf("[DNS-ROUTE] setupRefCounters: wgInterface=%s useNoop=%v", i.Name, useNoop)
+
 	m.routeRefCounter = refcounter.New(
 		func(prefix netip.Prefix, _ struct{}) (struct{}, error) {
-			return struct{}{}, m.sysOps.AddVPNRoute(prefix, m.wgInterface.ToInterface())
+			log.Warnf("[DNS-ROUTE] routeRefCounter.AddFunc called: prefix=%s interface=%s", prefix, i.Name)
+			err := m.sysOps.AddVPNRoute(prefix, i)
+			if err != nil {
+				log.Warnf("[DNS-ROUTE] routeRefCounter.AddFunc failed: prefix=%s err=%v", prefix, err)
+			} else {
+				log.Warnf("[DNS-ROUTE] routeRefCounter.AddFunc success: prefix=%s", prefix)
+			}
+			return struct{}{}, err
 		},
 		func(prefix netip.Prefix, _ struct{}) error {
-			return m.sysOps.RemoveVPNRoute(prefix, m.wgInterface.ToInterface())
+			log.Warnf("[DNS-ROUTE] routeRefCounter.RemoveFunc called: prefix=%s", prefix)
+			return m.sysOps.RemoveVPNRoute(prefix, i)
 		},
 	)
 
@@ -376,6 +387,18 @@ func (m *DefaultManager) UpdateRoutes(
 	clientRoutes route.HAMap,
 	useNewDNSRoute bool,
 ) error {
+	log.Warnf("[DNS-ROUTE] UpdateRoutes: serial=%d serverRoutes=%d clientRoutes=%d useNewDNSRoute=%v",
+		updateSerial, len(serverRoutes), len(clientRoutes), useNewDNSRoute)
+
+	// Log each client route for debugging
+	for id, routes := range clientRoutes {
+		if len(routes) > 0 {
+			r := routes[0]
+			log.Warnf("[DNS-ROUTE] UpdateRoutes: clientRoute id=%s network=%s isDynamic=%v domains=%v peer=%s",
+				id, r.Network, r.IsDynamic(), r.Domains.SafeString(), r.Peer)
+		}
+	}
+
 	select {
 	case <-m.ctx.Done():
 		log.Infof("not updating routes as context is closed")