wip

Signed-off-by: Irbe Krumina <irbe@tailscale.com>

control/controlclient/direct.go

@@ -564,6 +564,12 @@ func (c *Direct) doLogin(ctx context.Context, opt loginOpt) (mustRegen bool, new
 	case opt.URL != "":
 		// Nothing.
 	case regen || persist.PrivateNodeKey.IsZero():
+		if regen {
+			c.logf("TEST: need to regenerate")
+		} else {
+			c.logf("TEST: private node key is zero, persist is %v", persist)
+			c.logf("TEST: private node key is zero, persist is %v", persist)
+		}
 		c.logf("Generating a new nodekey.")
 		persist.OldPrivateNodeKey = persist.PrivateNodeKey
 		tryingNewKey = key.NewNode()

ipn/ipnlocal/local.go

@@ -1995,6 +1995,7 @@ func (b *LocalBackend) Start(opts ipn.Options) error {
 	defer unlock()
 
 	if opts.UpdatePrefs != nil {
+		log.Printf("TESTPREFS: update prefs non-nil")
 		if err := b.checkPrefsLocked(opts.UpdatePrefs); err != nil {
 			return err
 		}
@@ -2061,6 +2062,10 @@ func (b *LocalBackend) Start(opts ipn.Options) error {
 	}
 
 	prefs := b.pm.CurrentPrefs()
+	log.Printf("TESTPREFS persistent prefs: %v", prefs.Persist())
+	if s := prefs.Persist().AsStruct(); s != nil {
+		log.Printf("TESTPREFS persistent prefs private key is %v", s.PrivateNodeKey)
+	}
 	wantRunning := prefs.WantRunning()
 	if wantRunning {
 		if err := b.initMachineKeyLocked(); err != nil {
@@ -6778,6 +6783,7 @@ func (b *LocalBackend) CurrentProfile() ipn.LoginProfile {
 
 // NewProfile creates and switches to the new profile.
 func (b *LocalBackend) NewProfile() error {
+	log.Printf("TESTPREFS: NewProfile LB")
 	unlock := b.lockAndGetUnlock()
 	defer unlock()
 

ipn/ipnlocal/profiles.go

@@ -9,6 +9,7 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
+	"log"
 	"runtime"
 	"slices"
 	"strings"
@@ -203,6 +204,7 @@ func (pm *profileManager) setUnattendedModeAsConfigured() error {
 
 // Reset unloads the current profile, if any.
 func (pm *profileManager) Reset() {
+	log.Printf("TESTPREFS: Reset")
 	pm.currentUserID = ""
 	pm.NewProfile()
 }
@@ -215,6 +217,7 @@ func (pm *profileManager) Reset() {
 // is logged into so that we can keep track of things like their domain name
 // across user switches to disambiguate the same account but a different tailnet.
 func (pm *profileManager) SetPrefs(prefsIn ipn.PrefsView, np ipn.NetworkProfile) error {
+	log.Printf("TESTPREFS: SetPrefs with prefs %v", prefsIn)
 	cp := pm.currentProfile
 	if persist := prefsIn.Persist(); !persist.Valid() || persist.NodeID() == "" || persist.UserProfile().LoginName == "" {
 		// We don't know anything about this profile, so ignore it for now.
@@ -223,6 +226,7 @@ func (pm *profileManager) SetPrefs(prefsIn ipn.PrefsView, np ipn.NetworkProfile)
 
 	// Check if we already have an existing profile that matches the user/node.
 	if existing := pm.findMatchingProfiles(prefsIn); len(existing) > 0 {
+		log.Printf("TESTPREFS: SetPrefs found existing profile")
 		// We already have a profile for this user/node we should reuse it. Also
 		// cleanup any other duplicate profiles.
 		cp = existing[0]
@@ -230,6 +234,7 @@ func (pm *profileManager) SetPrefs(prefsIn ipn.PrefsView, np ipn.NetworkProfile)
 		for _, p := range existing {
 			// Clear the state.
 			if err := pm.store.WriteState(p.Key, nil); err != nil {
+				log.Printf("TESTPREFS: SetPrefs found existing profile, error writing state: %v", err)
 				// We couldn't delete the state, so keep the profile around.
 				continue
 			}
@@ -237,6 +242,8 @@ func (pm *profileManager) SetPrefs(prefsIn ipn.PrefsView, np ipn.NetworkProfile)
 			// in [profileManager.setProfilePrefs] below.
 			delete(pm.knownProfiles, p.ID)
 		}
+	} else {
+		log.Printf("TESTPREFS: SetPrefs not found existing profile")
 	}
 	pm.currentProfile = cp
 	if err := pm.SetProfilePrefs(cp, prefsIn, np); err != nil {
@@ -327,6 +334,7 @@ func newUnusedID(knownProfiles map[ipn.ProfileID]*ipn.LoginProfile) (ipn.Profile
 // profile, such as verifying the caller's access rights or checking
 // if another profile for the same node already exists.
 func (pm *profileManager) setProfilePrefsNoPermCheck(profile *ipn.LoginProfile, clonedPrefs ipn.PrefsView) error {
+	log.Printf("TESTPREFS: setProfilePrefsNoPerm")
 	isCurrentProfile := pm.currentProfile == profile
 	if isCurrentProfile {
 		pm.prefs = clonedPrefs
@@ -423,6 +431,7 @@ func (pm *profileManager) profilePrefs(p *ipn.LoginProfile) (ipn.PrefsView, erro
 // If the profile exists but is not accessible to the current user, it returns an [errProfileAccessDenied].
 // If the profile does not exist, it returns an [errProfileNotFound].
 func (pm *profileManager) SwitchProfile(id ipn.ProfileID) error {
+	log.Printf("TESTPREFS: SwitchProfile")
 	metricSwitchProfile.Add(1)
 
 	kp, ok := pm.knownProfiles[id]
@@ -450,6 +459,7 @@ func (pm *profileManager) SwitchProfile(id ipn.ProfileID) error {
 // It creates a new one and switches to it if the current user does not have a default profile,
 // or returns an error if the default profile is inaccessible or could not be loaded.
 func (pm *profileManager) SwitchToDefaultProfile() error {
+	log.Printf("TESTPREFS: SwitchToDefault")
 	if id := pm.DefaultUserProfileID(pm.currentUserID); id != "" {
 		return pm.SwitchProfile(id)
 	}
@@ -547,6 +557,7 @@ func (pm *profileManager) DeleteProfile(id ipn.ProfileID) error {
 }
 
 func (pm *profileManager) deleteCurrentProfile() error {
+	log.Printf("TESTPREFS: deleteCurrent")
 	if err := pm.checkProfileAccess(pm.currentProfile); err != nil {
 		return err
 	}
@@ -627,6 +638,7 @@ func (pm *profileManager) NewProfile() {
 // NewProfileForUser is like [profileManager.NewProfile], but it switches to the
 // specified user and sets that user as the profile owner for the new profile.
 func (pm *profileManager) NewProfileForUser(uid ipn.WindowsUserID) {
+	log.Printf("TESTPREFS: NewProfileForUser")
 	pm.currentUserID = uid
 
 	metricNewProfile.Add(1)
@@ -641,6 +653,7 @@ func (pm *profileManager) NewProfileForUser(uid ipn.WindowsUserID) {
 // newly created profile immediately. It returns the newly created profile on success,
 // or an error on failure.
 func (pm *profileManager) newProfileWithPrefs(uid ipn.WindowsUserID, prefs ipn.PrefsView, switchNow bool) (*ipn.LoginProfile, error) {
+	log.Printf("TESTPREFS: newProfileWithPrefs")
 	metricNewProfile.Add(1)
 
 	profile := &ipn.LoginProfile{LocalUserID: uid}
@@ -733,6 +746,7 @@ func newProfileManagerWithGOOS(store ipn.StateStore, logf logger.Logf, ht *healt
 	if err != nil {
 		return nil, err
 	}
+	log.Printf("TESTPREFS: newProfileWithGOOS with state key %v", stateKey)
 
 	knownProfiles, err := readKnownProfiles(store)
 	if err != nil {
@@ -748,12 +762,15 @@ func newProfileManagerWithGOOS(store ipn.StateStore, logf logger.Logf, ht *healt
 	}
 
 	if stateKey != "" {
+		log.Printf("TESTPREFS: state key %v exists", stateKey)
 		for _, v := range knownProfiles {
+			log.Printf("TESTPREFS: state key %v exists looking at matching profile %s", stateKey, v)
 			if v.Key == stateKey {
 				pm.currentProfile = v
 			}
 		}
 		if pm.currentProfile == nil {
+			log.Printf("TESTPREFS: current profile is nil")
 			if suf, ok := strings.CutPrefix(string(stateKey), "user-"); ok {
 				pm.currentUserID = ipn.WindowsUserID(suf)
 			}
@@ -776,12 +793,14 @@ func newProfileManagerWithGOOS(store ipn.StateStore, logf logger.Logf, ht *healt
 		// uid passed in from the unix tests. The uid's used for Windows tests
 		// and runtime must be valid Windows security identifier structures.
 	} else if len(knownProfiles) == 0 && goos != "windows" && runtime.GOOS != "windows" {
+		log.Printf("TESTPREFS: no known profiles")
 		// No known profiles, try a migration.
 		pm.dlogf("no known profiles; trying to migrate from legacy prefs")
 		if _, err := pm.migrateFromLegacyPrefs(pm.currentUserID, true); err != nil {
 			return nil, err
 		}
 	} else {
+		log.Printf("TESTPREFS: newProfileWithGOOS new profile")
 		pm.NewProfile()
 	}
 

ipn/store/kubestore/store_kube.go

@@ -7,6 +7,7 @@ package kubestore
 import (
 	"context"
 	"fmt"
+	"log"
 	"net"
 	"os"
 	"strings"
@@ -142,6 +143,7 @@ func (s *Store) loadState() error {
 		}
 		return err
 	}
+	log.Printf("TEST: kube store: got secret: %#+v", secret.Data)
 	s.memory.LoadFromMap(secret.Data)
 	return nil
 }

ipn/store/mem/store_mem.go

@@ -7,6 +7,7 @@ package mem
 import (
 	"bytes"
 	"encoding/json"
+	"log"
 	"sync"
 
 	xmaps "golang.org/x/exp/maps"
@@ -32,18 +33,21 @@ func (s *Store) String() string { return "mem.Store" }
 // ReadState implements the StateStore interface.
 // It returns ipn.ErrStateNotExist if the state does not exist.
 func (s *Store) ReadState(id ipn.StateKey) ([]byte, error) {
+	log.Printf("TEST: ReadState key %v ", id)
 	s.mu.Lock()
 	defer s.mu.Unlock()
 	bs, ok := s.cache[id]
 	if !ok {
 		return nil, ipn.ErrStateNotExist
 	}
+	log.Printf("TEST: ReadState key %v val %v", id, string(bs))
 	return bs, nil
 }
 
 // WriteState implements the StateStore interface.
 // It never returns an error.
 func (s *Store) WriteState(id ipn.StateKey, bs []byte) error {
+	log.Printf("TEST: WriteState key %v ", id)
 	s.mu.Lock()
 	defer s.mu.Unlock()
 	if s.cache == nil {
@@ -57,10 +61,12 @@ func (s *Store) WriteState(id ipn.StateKey, bs []byte) error {
 // Any existing content is cleared, and the provided map is
 // copied into the cache.
 func (s *Store) LoadFromMap(m map[string][]byte) {
+	log.Printf("Store: LoadFromMap")
 	s.mu.Lock()
 	defer s.mu.Unlock()
 	xmaps.Clear(s.cache)
 	for k, v := range m {
+		log.Printf("TEST: setting state key %v %+#v", k, string(v))
 		mak.Set(&s.cache, ipn.StateKey(k), v)
 	}
 	return