cmd/syncthing, lib/db: Store upgrade info to throttle queries (fixes #6513) (#6514)

cmd/syncthing/main.go

@@ -30,6 +30,7 @@ import (
 
 	"github.com/syncthing/syncthing/lib/build"
 	"github.com/syncthing/syncthing/lib/config"
+	"github.com/syncthing/syncthing/lib/db"
 	"github.com/syncthing/syncthing/lib/dialer"
 	"github.com/syncthing/syncthing/lib/events"
 	"github.com/syncthing/syncthing/lib/fs"
@@ -147,7 +148,15 @@ var (
 	innerProcess    = os.Getenv("STMONITORED") != ""
 	noDefaultFolder = os.Getenv("STNODEFAULTFOLDER") != ""
 
-	errConcurrentUpgrade = errors.New("upgrade prevented by other running Syncthing instance")
+	upgradeCheckInterval = 5 * time.Minute
+	upgradeRetryInterval = time.Hour
+	upgradeCheckKey      = "lastUpgradeCheck"
+	upgradeTimeKey       = "lastUpgradeTime"
+	upgradeVersionKey    = "lastUpgradeVersion"
+
+	errConcurrentUpgrade    = errors.New("upgrade prevented by other running Syncthing instance")
+	errTooEarlyUpgradeCheck = fmt.Errorf("last upgrade check happened less than %v ago, skipping", upgradeCheckInterval)
+	errTooEarlyUpgrade      = fmt.Errorf("last upgrade happened less than %v ago, skipping", upgradeRetryInterval)
 )
 
 type RuntimeOptions struct {
@@ -399,7 +408,14 @@ func main() {
 	if options.doUpgrade {
 		release, err := checkUpgrade()
 		if err == nil {
-			err = performUpgrade(release)
+			// Use leveldb database locks to protect against concurrent upgrades
+			ldb, err := syncthing.OpenDBBackend(locations.Get(locations.Database), config.TuningAuto)
+			if err != nil {
+				err = upgradeViaRest()
+			} else {
+				_ = ldb.Close()
+				err = upgrade.To(release)
+			}
 		}
 		if err != nil {
 			l.Warnln("Upgrade:", err)
@@ -526,25 +542,6 @@ func checkUpgrade() (upgrade.Release, error) {
 	return release, nil
 }
 
-func performUpgradeDirect(release upgrade.Release) error {
-	// Use leveldb database locks to protect against concurrent upgrades
-	if _, err := syncthing.OpenDBBackend(locations.Get(locations.Database), config.TuningAuto); err != nil {
-		return errConcurrentUpgrade
-	}
-	return upgrade.To(release)
-}
-
-func performUpgrade(release upgrade.Release) error {
-	if err := performUpgradeDirect(release); err != nil {
-		if err != errConcurrentUpgrade {
-			return err
-		}
-		l.Infoln("Attempting upgrade through running Syncthing...")
-		return upgradeViaRest()
-	}
-	return nil
-}
-
 func upgradeViaRest() error {
 	cfg, _ := loadOrDefaultConfig(protocol.EmptyDeviceID, events.NoopLogger)
 	u, err := url.Parse(cfg.GUI().URL())
@@ -627,25 +624,33 @@ func syncthingMain(runtimeOptions RuntimeOptions) {
 		// not, as otherwise they cannot step off the candidate channel.
 	}
 
+	dbFile := locations.Get(locations.Database)
+	ldb, err := syncthing.OpenDBBackend(dbFile, cfg.Options().DatabaseTuning)
+	if err != nil {
+		l.Warnln("Error opening database:", err)
+		os.Exit(1)
+	}
+
 	// Check if auto-upgrades should be done and if yes, do an initial
 	// upgrade immedately. The auto-upgrade routine can only be started
 	// later after App is initialised.
 
 	shouldAutoUpgrade := shouldUpgrade(cfg, runtimeOptions)
 	if shouldAutoUpgrade {
-		// Try to do upgrade directly
+		// try to do upgrade directly and log the error if relevant.
-		release, err := checkUpgrade()
+		release, err := initialAutoUpgradeCheck(db.NewMiscDataNamespace(ldb))
 		if err == nil {
-			if err = performUpgradeDirect(release); err == nil {
+			err = upgrade.To(release)
-				l.Infof("Upgraded to %q, exiting now.", release.Tag)
-				os.Exit(syncthing.ExitUpgrade.AsInt())
-			}
 		}
-		// Log the error if relevant.
 		if err != nil {
-			if _, ok := err.(errNoUpgrade); !ok {
+			if _, ok := err.(errNoUpgrade); ok || err == errTooEarlyUpgradeCheck || err == errTooEarlyUpgrade {
+				l.Debugln("Initial automatic upgrade:", err)
+			} else {
 				l.Infoln("Initial automatic upgrade:", err)
 			}
+		} else {
+			l.Infof("Upgraded to %q, exiting now.", release.Tag)
+			os.Exit(syncthing.ExitUpgrade.AsInt())
 		}
 	}
 
@@ -655,13 +660,6 @@ func syncthingMain(runtimeOptions RuntimeOptions) {
 		setPauseState(cfg, true)
 	}
 
-	dbFile := locations.Get(locations.Database)
-	ldb, err := syncthing.OpenDBBackend(dbFile, cfg.Options().DatabaseTuning)
-	if err != nil {
-		l.Warnln("Error opening database:", err)
-		os.Exit(1)
-	}
-
 	appOpts := runtimeOptions.Options
 	if runtimeOptions.auditEnabled {
 		appOpts.AuditWriter = auditWriter(runtimeOptions.auditFile)
@@ -852,7 +850,7 @@ func shouldUpgrade(cfg config.Wrapper, runtimeOptions RuntimeOptions) bool {
 }
 
 func autoUpgrade(cfg config.Wrapper, app *syncthing.App, evLogger events.Logger) {
-	timer := time.NewTimer(0)
+	timer := time.NewTimer(upgradeCheckInterval)
 	sub := evLogger.Subscribe(events.DeviceConnected)
 	for {
 		select {
@@ -907,6 +905,26 @@ func autoUpgrade(cfg config.Wrapper, app *syncthing.App, evLogger events.Logger)
 	}
 }
 
+func initialAutoUpgradeCheck(misc *db.NamespacedKV) (upgrade.Release, error) {
+	if last, ok, err := misc.Time(upgradeCheckKey); err == nil && ok && time.Since(last) < upgradeCheckInterval {
+		return upgrade.Release{}, errTooEarlyUpgradeCheck
+	}
+	_ = misc.PutTime(upgradeCheckKey, time.Now())
+	release, err := checkUpgrade()
+	if err != nil {
+		return upgrade.Release{}, err
+	}
+	if lastVersion, ok, err := misc.String(upgradeVersionKey); err == nil && ok && lastVersion == release.Tag {
+		// Only check time if we try to upgrade to the same release.
+		if lastTime, ok, err := misc.Time(upgradeTimeKey); err == nil && ok && time.Since(lastTime) < upgradeRetryInterval {
+			return upgrade.Release{}, errTooEarlyUpgrade
+		}
+	}
+	_ = misc.PutString(upgradeVersionKey, release.Tag)
+	_ = misc.PutTime(upgradeTimeKey, time.Now())
+	return release, nil
+}
+
 // cleanConfigDirectory removes old, unused configuration and index formats, a
 // suitable time after they have gone out of fashion.
 func cleanConfigDirectory() {

lib/db/namespaced.go

@@ -16,13 +16,13 @@ import (
 // NamespacedKV is a simple key-value store using a specific namespace within
 // a leveldb.
 type NamespacedKV struct {
-	db     *Lowlevel
+	db     backend.Backend
 	prefix string
 }
 
 // NewNamespacedKV returns a new NamespacedKV that lives in the namespace
 // specified by the prefix.
-func NewNamespacedKV(db *Lowlevel, prefix string) *NamespacedKV {
+func NewNamespacedKV(db backend.Backend, prefix string) *NamespacedKV {
 	return &NamespacedKV{
 		db:     db,
 		prefix: prefix,
@@ -133,18 +133,18 @@ func (n NamespacedKV) prefixedKey(key string) []byte {
 
 // NewDeviceStatisticsNamespace creates a KV namespace for device statistics
 // for the given device.
-func NewDeviceStatisticsNamespace(db *Lowlevel, device string) *NamespacedKV {
+func NewDeviceStatisticsNamespace(db backend.Backend, device string) *NamespacedKV {
 	return NewNamespacedKV(db, string(KeyTypeDeviceStatistic)+device)
 }
 
 // NewFolderStatisticsNamespace creates a KV namespace for folder statistics
 // for the given folder.
-func NewFolderStatisticsNamespace(db *Lowlevel, folder string) *NamespacedKV {
+func NewFolderStatisticsNamespace(db backend.Backend, folder string) *NamespacedKV {
 	return NewNamespacedKV(db, string(KeyTypeFolderStatistic)+folder)
 }
 
 // NewMiscDateNamespace creates a KV namespace for miscellaneous metadata.
-func NewMiscDataNamespace(db *Lowlevel) *NamespacedKV {
+func NewMiscDataNamespace(db backend.Backend) *NamespacedKV {
 	return NewNamespacedKV(db, string(KeyTypeMiscData))
 }