Route diagnostics

client/internal/peer/conn.go

@@ -932,18 +932,22 @@ func (conn *Conn) AgentVersionString() string {
 
 func (conn *Conn) presharedKey(remoteRosenpassKey []byte) *wgtypes.Key {
 	if conn.config.RosenpassConfig.PubKey == nil {
+		conn.Log.Warnf("PSK-DIAG: rosenpass off -> static PSK (present=%v)", conn.config.WgConfig.PreSharedKey != nil)
 		return conn.config.WgConfig.PreSharedKey
 	}
 
 	if remoteRosenpassKey == nil && conn.config.RosenpassConfig.PermissiveMode {
+		conn.Log.Warnf("PSK-DIAG: rosenpass permissive + no remote RP key -> static PSK bridge (present=%v)", conn.config.WgConfig.PreSharedKey != nil)
 		return conn.config.WgConfig.PreSharedKey
 	}
 
 	// If Rosenpass has already set a PSK for this peer, return nil to prevent
 	// UpdatePeer from overwriting the Rosenpass-managed key.
 	if conn.rosenpassInitializedPresharedKeyValidator != nil && conn.rosenpassInitializedPresharedKeyValidator(conn.config.Key) {
+		conn.Log.Warnf("PSK-DIAG: rosenpass initialized -> returning nil (keep existing on-wire PSK; NOT re-set)")
 		return nil
 	}
+	conn.Log.Warnf("PSK-DIAG: rosenpass strict, not yet initialized -> seeding PSK (staticPresent=%v)", conn.config.WgConfig.PreSharedKey != nil)
 
 	// Use NetBird PSK as the seed for Rosenpass. This same PSK is passed to
 	// Rosenpass as PeerConfig.PresharedKey, ensuring the derived post-quantum

client/internal/peer/endpoint.go

@@ -38,6 +38,8 @@ func (e *EndpointUpdater) ConfigureWGEndpoint(addr *net.UDPAddr, presharedKey *w
 	e.mu.Lock()
 	defer e.mu.Unlock()
 
+	e.log.Warnf("PSK-DIAG: ConfigureWGEndpoint endpoint=%s psk_present=%v", addr, presharedKey != nil)
+
 	if e.initiator {
 		e.log.Debugf("configure up WireGuard as initiator")
 		return e.configureAsInitiator(addr, presharedKey)
@@ -51,6 +53,8 @@ func (e *EndpointUpdater) SwitchWGEndpoint(addr *net.UDPAddr, presharedKey *wgty
 	e.mu.Lock()
 	defer e.mu.Unlock()
 
+	e.log.Warnf("PSK-DIAG: SwitchWGEndpoint endpoint=%s psk_present=%v", addr, presharedKey != nil)
+
 	// prevent to run new update while cancel the previous update
 	e.waitForCloseTheDelayedUpdate()
 
@@ -69,6 +73,8 @@ func (e *EndpointUpdater) RemoveEndpointAddress() error {
 	e.mu.Lock()
 	defer e.mu.Unlock()
 
+	e.log.Warnf("PSK-DIAG: RemoveEndpointAddress -> peer re-added with only PublicKey+AllowedIPs; on-wire PSK is dropped")
+
 	e.waitForCloseTheDelayedUpdate()
 	return e.wgConfig.WgInterface.RemoveEndpointAddress(e.wgConfig.RemoteKey)
 }

client/internal/peer/wg_watcher.go

@@ -66,6 +66,7 @@ func (w *WGWatcher) PrepareInitialHandshake() (ok bool) {
 
 	handshake, _ := w.wgState()
 	w.initialHandshake = handshake
+	w.log.Warnf("PSK-DIAG: watcher baseline handshake=%v (zero=%v)", handshake, handshake.IsZero())
 	return true
 }
 
@@ -92,6 +93,7 @@ func (w *WGWatcher) Reset() {
 // wgStateCheck help to check the state of the WireGuard handshake and relay connection
 func (w *WGWatcher) periodicHandshakeCheck(ctx context.Context, onDisconnectedFn func(), onHandshakeSuccessFn func(when time.Time), enabledTime time.Time, initialHandshake time.Time) {
 	w.log.Infof("WireGuard watcher started")
+	w.log.Warnf("WGW-DIAG: watcher started id=%d baseline=%v (zero=%v) firstCheckIn=%v", enabledTime.UnixNano(), initialHandshake, initialHandshake.IsZero(), wgHandshakeOvertime)
 
 	timer := time.NewTimer(wgHandshakeOvertime)
 	defer timer.Stop()
@@ -101,11 +103,17 @@ func (w *WGWatcher) periodicHandshakeCheck(ctx context.Context, onDisconnectedFn
 	for {
 		select {
 		case <-timer.C:
+			w.log.Warnf("WGW-DIAG: check fire id=%d lastHandshake=%v", enabledTime.UnixNano(), lastHandshake)
 			handshake, ok := w.handshakeCheck(lastHandshake)
 			if !ok {
+				// #6626 race check: a superseded/cancelled watcher must not tear
+				// down a now-healthy connection. Log which branch we take so a
+				// bundle shows whether teardowns fire on live vs cancelled ctx.
 				if ctx.Err() != nil {
+					w.log.Warnf("WGW-DIAG: check failed but ctx cancelled -> standing down, NO teardown id=%d", enabledTime.UnixNano())
 					return
 				}
+				w.log.Warnf("WGW-DIAG: check failed, ctx live -> firing onDisconnected (TEARDOWN) id=%d", enabledTime.UnixNano())
 				onDisconnectedFn()
 				return
 			}
@@ -123,15 +131,15 @@ func (w *WGWatcher) periodicHandshakeCheck(ctx context.Context, onDisconnectedFn
 			timer.Reset(resetTime)
 			w.stateDump.WGcheckSuccess()
 
-			w.log.Debugf("WireGuard watcher reset timer: %v", resetTime)
+			w.log.Warnf("WGW-DIAG: check ok id=%d handshake=%v nextCheckIn=%v", enabledTime.UnixNano(), handshake, resetTime)
 		case <-w.resetCh:
-			w.log.Infof("WireGuard watcher received peer reset, restarting handshake timeout")
+			w.log.Warnf("WGW-DIAG: peer reset received, restarting timeout id=%d", enabledTime.UnixNano())
 			lastHandshake = time.Time{}
 			enabledTime = time.Now()
 			timer.Stop()
 			timer.Reset(wgHandshakeOvertime)
 		case <-ctx.Done():
-			w.log.Infof("WireGuard watcher stopped")
+			w.log.Warnf("WGW-DIAG: watcher stopped (ctx done) id=%d", enabledTime.UnixNano())
 			return
 		}
 	}

client/internal/rosenpass/netbird_handler.go

@@ -100,6 +100,7 @@ func (h *NetbirdHandler) outputKey(_ rp.KeyOutputReason, pid rp.PeerID, psk rp.K
 		log.Errorf("Failed to apply rosenpass key: %v", err)
 		return
 	}
+	log.Warnf("PSK-DIAG: rosenpass set PSK on WG for peer %s (updateOnly=%v)", peerKey, isInitialized)
 
 	// Mark peer as isInitialized after the successful first rotation
 	if !isInitialized {

client/internal/routemanager/client/client.go

@@ -231,11 +231,15 @@ func (w *Watcher) getBestRouteFromStatuses(routePeerStatuses map[route.ID]router
 	switch {
 	case chosen == "":
 		var peers []string
-		for _, r := range w.routes {
-			peers = append(peers, r.Peer)
+		for id, r := range w.routes {
+			st := "unknown(no status)"
+			if ps, ok := routePeerStatuses[id]; ok {
+				st = fmt.Sprintf("%s relayed=%v lat=%v", ps.status, ps.relayed, ps.latency)
+			}
+			peers = append(peers, fmt.Sprintf("%s{%s}", r.Peer, st))
 		}
 
-		log.Infof("network [%v] has not been assigned a routing peer as no peers from the list %s are currently available", w.handler, peers)
+		log.Warnf("ROUTE-DIAG: network [%v] no routing peer available yet (all candidates connecting/absent); candidates: %s", w.handler, peers)
 	case chosen != currID:
 		// we compare the current score + 10ms to the chosen score to avoid flapping between routes
 		if currScore != 0 && currScore+0.01 > chosenScore {
@@ -247,7 +251,7 @@ func (w *Watcher) getBestRouteFromStatuses(routePeerStatuses map[route.ID]router
 		if rt := w.routes[chosen]; rt != nil {
 			p = rt.Peer
 		}
-		log.Infof("New chosen route is %s with peer %s with score %f for network [%v]", chosen, p, chosenScore, w.handler)
+		log.Warnf("ROUTE-DIAG: new chosen route %s peer %s score %f for network [%v] (routing peer now usable)", chosen, p, chosenScore, w.handler)
 	}
 
 	return chosen, chosenStatus