diff --git a/ipn/ipnlocal/profiles.go b/ipn/ipnlocal/profiles.go index 8cdedad7c..f831a4093 100644 --- a/ipn/ipnlocal/profiles.go +++ b/ipn/ipnlocal/profiles.go @@ -24,6 +24,8 @@ import ( var errAlreadyMigrated = errors.New("profile migration already completed") +var debug = envknob.RegisterBool("TS_DEBUG_PROFILES") + // profileManager is a wrapper around a StateStore that manages // multiple profiles and the current profile. type profileManager struct { @@ -42,6 +44,13 @@ type profileManager struct { isNewProfile bool } +func (pm *profileManager) dlogf(format string, args ...any) { + if !debug() { + return + } + pm.logf(format, args...) +} + // CurrentUserID returns the current user ID. It is only non-empty on // Windows where we have a multi-user system. func (pm *profileManager) CurrentUserID() ipn.WindowsUserID { @@ -66,8 +75,10 @@ func (pm *profileManager) SetCurrentUserID(uid ipn.WindowsUserID) error { // Read the CurrentProfileKey from the store which stores // the selected profile for the current user. b, err := pm.store.ReadState(ipn.CurrentProfileKey(string(uid))) + pm.dlogf("SetCurrentUserID: ReadState(%q) = %v, %v", string(uid), len(b), err) if err == ipn.ErrStateNotExist || len(b) == 0 { if runtime.GOOS == "windows" { + pm.dlogf("SetCurrentUserID: windows: migrating from legacy preferences") if err := pm.migrateFromLegacyPrefs(); err != nil && !errors.Is(err, errAlreadyMigrated) { return err } @@ -81,6 +92,7 @@ func (pm *profileManager) SetCurrentUserID(uid ipn.WindowsUserID) error { pk := ipn.StateKey(string(b)) prof := pm.findProfileByKey(pk) if prof == nil { + pm.dlogf("SetCurrentUserID: no profile found for key: %q", pk) pm.NewProfile() return nil } @@ -555,6 +567,7 @@ func newProfileManagerWithGOOS(store ipn.StateStore, logf logger.Logf, goos stri // and runtime must be valid Windows security identifier structures. } else if len(knownProfiles) == 0 && goos != "windows" && runtime.GOOS != "windows" { // No known profiles, try a migration. + pm.dlogf("no known profiles; trying to migrate from legacy prefs") if err := pm.migrateFromLegacyPrefs(); err != nil { return nil, err } @@ -573,11 +586,13 @@ func (pm *profileManager) migrateFromLegacyPrefs() error { metricMigrationError.Add(1) return fmt.Errorf("load legacy prefs: %w", err) } + pm.dlogf("loaded legacy preferences; sentinel=%q", sentinel) if err := pm.SetPrefs(prefs); err != nil { metricMigrationError.Add(1) return fmt.Errorf("migrating _daemon profile: %w", err) } pm.completeMigration(sentinel) + pm.dlogf("completed legacy preferences migration with sentinel=%q", sentinel) metricMigrationSuccess.Add(1) return nil } diff --git a/ipn/ipnlocal/profiles_windows.go b/ipn/ipnlocal/profiles_windows.go index 1661c08d3..22da3ff69 100644 --- a/ipn/ipnlocal/profiles_windows.go +++ b/ipn/ipnlocal/profiles_windows.go @@ -40,6 +40,7 @@ func legacyPrefsDir(uid ipn.WindowsUserID) (string, error) { func (pm *profileManager) loadLegacyPrefs() (string, ipn.PrefsView, error) { userLegacyPrefsDir, err := legacyPrefsDir(pm.currentUserID) if err != nil { + pm.dlogf("no legacy preferences directory for %q: %v", pm.currentUserID, err) return "", ipn.PrefsView{}, err } @@ -47,14 +48,17 @@ func (pm *profileManager) loadLegacyPrefs() (string, ipn.PrefsView, error) { // verify that migration sentinel is not present _, err = os.Stat(migrationSentinel) if err == nil { + pm.dlogf("migration sentinel %q already exists", migrationSentinel) return "", ipn.PrefsView{}, errAlreadyMigrated } if !os.IsNotExist(err) { + pm.dlogf("os.Stat(%q) = %v", migrationSentinel, err) return "", ipn.PrefsView{}, err } prefsPath := filepath.Join(userLegacyPrefsDir, legacyPrefsFile+legacyPrefsExt) prefs, err := ipn.LoadPrefs(prefsPath) + pm.dlogf("ipn.LoadPrefs(%q) = %v, %v", prefsPath, prefs, err) if errors.Is(err, fs.ErrNotExist) { return "", ipn.PrefsView{}, errAlreadyMigrated }