lib/versioner: Use mtime for version cleanup (fixes #5765) (#5769)

lib/model/model.go

@@ -36,16 +36,6 @@ import (
 	"github.com/thejerf/suture"
 )
 
-var locationLocal *time.Location
-
-func init() {
-	var err error
-	locationLocal, err = time.LoadLocation("Local")
-	if err != nil {
-		panic(err.Error())
-	}
-}
-
 // How many files to send in each Index/IndexUpdate message.
 const (
 	maxBatchSizeBytes = 250 * 1024 // Aim for making index messages no larger than 250 KiB (uncompressed)

lib/model/model_test.go

@@ -2852,7 +2852,7 @@ func TestVersionRestore(t *testing.T) {
 	defer cleanupModel(m)
 	m.ScanFolder("default")
 
-	sentinel, err := time.ParseInLocation(versioner.TimeFormat, "20200101-010101", locationLocal)
+	sentinel, err := time.ParseInLocation(versioner.TimeFormat, "20200101-010101", time.Local)
 	must(t, err)
 	sentinelTag := sentinel.Format(versioner.TimeFormat)
 
@@ -2926,7 +2926,7 @@ func TestVersionRestore(t *testing.T) {
 	}
 
 	makeTime := func(s string) time.Time {
-		tm, err := time.ParseInLocation(versioner.TimeFormat, s, locationLocal)
+		tm, err := time.ParseInLocation(versioner.TimeFormat, s, time.Local)
 		if err != nil {
 			t.Error(err)
 		}
@@ -2960,7 +2960,7 @@ func TestVersionRestore(t *testing.T) {
 		if runtime.GOOS == "windows" {
 			file = filepath.FromSlash(file)
 		}
-		tag := version.In(locationLocal).Truncate(time.Second).Format(versioner.TimeFormat)
+		tag := version.In(time.Local).Truncate(time.Second).Format(versioner.TimeFormat)
 		taggedName := filepath.Join(".stversions", versioner.TagFilename(file, tag))
 		fd, err := filesystem.Open(file)
 		if err != nil {

lib/versioner/simple.go

@@ -8,7 +8,6 @@ package versioner
 
 import (
 	"path/filepath"
-	"sort"
 	"strconv"
 	"time"
 
@@ -70,15 +69,16 @@ func (v Simple) Archive(filePath string) error {
 		return nil
 	}
 
-	// Use all the found filenames. "~" sorts after "." so all old pattern
-	// files will be deleted before any new, which is as it should be.
+	// Use all the found filenames.
 	versions := util.UniqueTrimmedStrings(append(oldVersions, newVersions...))
-	sort.Strings(versions)
 
-	if len(versions) > v.keep {
-		for _, toRemove := range versions[:len(versions)-v.keep] {
+	// Amend with mtime, sort on mtime, delete the oldest first. Mtime,
+	// nowadays at least, is the time when the archiving happened.
+	versionsWithMtimes := versionsToVersionsWithMtime(v.versionsFs, versions)
+	if len(versionsWithMtimes) > v.keep {
+		for _, toRemove := range versionsWithMtimes[:len(versionsWithMtimes)-v.keep] {
 			l.Debugln("cleaning out", toRemove)
-			err = v.versionsFs.Remove(toRemove)
+			err = v.versionsFs.Remove(toRemove.name)
 			if err != nil {
 				l.Warnln("removing old version:", err)
 			}

lib/versioner/staggered.go

@@ -103,7 +103,7 @@ func (v *Staggered) clean() {
 		return
 	}
 
-	versionsPerFile := make(map[string][]string)
+	versionsPerFile := make(map[string][]versionWithMtime)
 	dirTracker := make(emptyDirTracker)
 
 	walkFn := func(path string, f fs.FileInfo, err error) error {
@@ -124,7 +124,10 @@ func (v *Staggered) clean() {
 			return nil
 		}
 
-		versionsPerFile[name] = append(versionsPerFile[name], path)
+		versionsPerFile[name] = append(versionsPerFile[name], versionWithMtime{
+			name:  name,
+			mtime: f.ModTime(),
+		})
 
 		return nil
 	}
@@ -135,7 +138,6 @@ func (v *Staggered) clean() {
 	}
 
 	for _, versionList := range versionsPerFile {
-		// List from filepath.Walk is sorted
 		v.expire(versionList)
 	}
 
@@ -144,7 +146,7 @@ func (v *Staggered) clean() {
 	l.Debugln("Cleaner: Finished cleaning", v.versionsFs)
 }
 
-func (v *Staggered) expire(versions []string) {
+func (v *Staggered) expire(versions []versionWithMtime) {
 	l.Debugln("Versioner: Expiring versions", versions)
 	for _, file := range v.toRemove(versions, time.Now()) {
 		if fi, err := v.versionsFs.Lstat(file); err != nil {
@@ -161,26 +163,24 @@ func (v *Staggered) expire(versions []string) {
 	}
 }
 
-func (v *Staggered) toRemove(versions []string, now time.Time) []string {
+func (v *Staggered) toRemove(versions []versionWithMtime, now time.Time) []string {
 	var prevAge int64
 	firstFile := true
 	var remove []string
-	for _, file := range versions {
-		loc, _ := time.LoadLocation("Local")
-		versionTime, err := time.ParseInLocation(TimeFormat, ExtractTag(file), loc)
-		if err != nil {
-			l.Debugf("Versioner: file name %q is invalid: %v", file, err)
-			continue
-		}
-		age := int64(now.Sub(versionTime).Seconds())
+
+	// The list of versions may or may not be properly sorted. Let's take
+	// off and nuke from orbit, it's the only way to be sure.
+	sort.Slice(versions, func(i, j int) bool {
+		return versions[i].mtime.Before(versions[j].mtime)
+	})
+
+	for _, version := range versions {
+		age := int64(now.Sub(version.mtime).Seconds())
 
 		// If the file is older than the max age of the last interval, remove it
 		if lastIntv := v.interval[len(v.interval)-1]; lastIntv.end > 0 && age > lastIntv.end {
-			l.Debugln("Versioner: File over maximum age -> delete ", file)
-			err = v.versionsFs.Remove(file)
-			if err != nil {
-				l.Warnf("Versioner: can't remove %q: %v", file, err)
-			}
+			l.Debugln("Versioner: File over maximum age -> delete ", version.name)
+			remove = append(remove, version.name)
 			continue
 		}
 
@@ -200,8 +200,8 @@ func (v *Staggered) toRemove(versions []string, now time.Time) []string {
 		}
 
 		if prevAge-age < usedInterval.step {
-			l.Debugln("too many files in step -> delete", file)
-			remove = append(remove, file)
+			l.Debugln("too many files in step -> delete", version.name)
+			remove = append(remove, version.name)
 			continue
 		}
 
@@ -244,8 +244,9 @@ func (v *Staggered) Archive(filePath string) error {
 	// Use all the found filenames.
 	versions := append(oldVersions, newVersions...)
 	versions = util.UniqueTrimmedStrings(versions)
-	sort.Strings(versions)
-	v.expire(versions)
+
+	versionsWithMtimes := versionsToVersionsWithMtime(v.versionsFs, versions)
+	v.expire(versionsWithMtimes)
 
 	return nil
 }

lib/versioner/staggered_test.go

@@ -7,7 +7,6 @@
 package versioner
 
 import (
-	"os"
 	"sort"
 	"strconv"
 	"testing"
@@ -26,29 +25,27 @@ func TestStaggeredVersioningVersionCount(t *testing.T) {
 	{604800, maxAge}, // next year -> 1 week between versions
 	*/
 
-	loc, _ := time.LoadLocation("Local")
-	now, _ := time.ParseInLocation(TimeFormat, "20160415-140000", loc)
-	files := []string{
+	now := parseTime("20160415-140000")
+	versionsWithMtime := []versionWithMtime{
 		// 14:00:00 is "now"
-		"test~20160415-140000", // 0 seconds ago
-		"test~20160415-135959", // 1 second ago
-		"test~20160415-135958", // 2 seconds ago
-		"test~20160415-135900", // 1 minute ago
-		"test~20160415-135859", // 1 minute 1 second ago
-		"test~20160415-135830", // 1 minute 30 seconds ago
-		"test~20160415-135829", // 1 minute 31 seconds ago
-		"test~20160415-135700", // 3 minutes ago
-		"test~20160415-135630", // 3 minutes 30 seconds ago
-		"test~20160415-133000", // 30 minutes ago
-		"test~20160415-132900", // 31 minutes ago
-		"test~20160415-132500", // 35 minutes ago
-		"test~20160415-132000", // 40 minutes ago
-		"test~20160415-130000", // 60 minutes ago
-		"test~20160415-124000", // 80 minutes ago
-		"test~20160415-122000", // 100 minutes ago
-		"test~20160415-110000", // 120 minutes ago
+		{"test~20160415-140000", parseTime("20160415-140000")}, // 0 seconds ago
+		{"test~20160415-135959", parseTime("20160415-135959")}, // 1 second ago
+		{"test~20160415-135958", parseTime("20160415-135958")}, // 2 seconds ago
+		{"test~20160415-135900", parseTime("20160415-135900")}, // 1 minute ago
+		{"test~20160415-135859", parseTime("20160415-135859")}, // 1 minute 1 second ago
+		{"test~20160415-135830", parseTime("20160415-135830")}, // 1 minute 30 seconds ago
+		{"test~20160415-135829", parseTime("20160415-135829")}, // 1 minute 31 seconds ago
+		{"test~20160415-135700", parseTime("20160415-135700")}, // 3 minutes ago
+		{"test~20160415-135630", parseTime("20160415-135630")}, // 3 minutes 30 seconds ago
+		{"test~20160415-133000", parseTime("20160415-133000")}, // 30 minutes ago
+		{"test~20160415-132900", parseTime("20160415-132900")}, // 31 minutes ago
+		{"test~20160415-132500", parseTime("20160415-132500")}, // 35 minutes ago
+		{"test~20160415-132000", parseTime("20160415-132000")}, // 40 minutes ago
+		{"test~20160415-130000", parseTime("20160415-130000")}, // 60 minutes ago
+		{"test~20160415-124000", parseTime("20160415-124000")}, // 80 minutes ago
+		{"test~20160415-122000", parseTime("20160415-122000")}, // 100 minutes ago
+		{"test~20160415-110000", parseTime("20160415-110000")}, // 120 minutes ago
 	}
-	sort.Strings(files)
 
 	delete := []string{
 		"test~20160415-140000", // 0 seconds ago
@@ -60,18 +57,21 @@ func TestStaggeredVersioningVersionCount(t *testing.T) {
 	}
 	sort.Strings(delete)
 
-	os.MkdirAll("testdata/.stversions", 0755)
-	defer os.RemoveAll("testdata")
+	v := NewStaggered("", fs.NewFilesystem(fs.FilesystemTypeFake, "testdata"), map[string]string{
+		"maxAge": strconv.Itoa(365 * 86400),
+	}).(*Staggered)
+	rem := v.toRemove(versionsWithMtime, now)
+	sort.Strings(rem)
 
-	v := NewStaggered("", fs.NewFilesystem(fs.FilesystemTypeBasic, "testdata"), map[string]string{"maxAge": strconv.Itoa(365 * 86400)}).(*Staggered)
-	v.testCleanDone = make(chan struct{})
-	defer v.Stop()
-	go v.Serve()
-
-	<-v.testCleanDone
-
-	rem := v.toRemove(files, now)
 	if diff, equal := messagediff.PrettyDiff(delete, rem); !equal {
 		t.Errorf("Incorrect deleted files; got %v, expected %v\n%v", rem, delete, diff)
 	}
 }
+
+func parseTime(in string) time.Time {
+	t, err := time.ParseInLocation(TimeFormat, in, time.Local)
+	if err != nil {
+		panic(err.Error())
+	}
+	return t
+}

lib/versioner/util.go

@@ -10,6 +10,7 @@ import (
 	"fmt"
 	"path/filepath"
 	"regexp"
+	"sort"
 	"strings"
 	"time"
 
@@ -18,19 +19,10 @@ import (
 	"github.com/syncthing/syncthing/lib/osutil"
 )
 
-var locationLocal *time.Location
 var errDirectory = fmt.Errorf("cannot restore on top of a directory")
 var errNotFound = fmt.Errorf("version not found")
 var errFileAlreadyExists = fmt.Errorf("file already exists")
 
-func init() {
-	var err error
-	locationLocal, err = time.LoadLocation("Local")
-	if err != nil {
-		panic(err.Error())
-	}
-}
-
 // Inserts ~tag just before the extension of the filename.
 func TagFilename(name, tag string) string {
 	dir, file := filepath.Dir(name), filepath.Base(name)
@@ -109,7 +101,7 @@ func retrieveVersions(fileSystem fs.Filesystem) (map[string][]FileVersion, error
 			return nil
 		}
 
-		versionTime, err := time.ParseInLocation(TimeFormat, tag, locationLocal)
+		versionTime, err := time.ParseInLocation(TimeFormat, tag, time.Local)
 		if err != nil {
 			// Can't parse it, welp, continue
 			return nil
@@ -117,8 +109,10 @@ func retrieveVersions(fileSystem fs.Filesystem) (map[string][]FileVersion, error
 
 		if err == nil {
 			files[name] = append(files[name], FileVersion{
-				VersionTime: versionTime.Truncate(time.Second),
-				ModTime:     f.ModTime().Truncate(time.Second),
+				// This looks backwards, but mtime of the file is when we archived it, making that the version time
+				// The mod time of the file before archiving is embedded in the file name.
+				VersionTime: f.ModTime().Truncate(time.Second),
+				ModTime:     versionTime.Truncate(time.Second),
 				Size:        f.Size(),
 			})
 		}
@@ -209,7 +203,7 @@ func restoreFile(src, dst fs.Filesystem, filePath string, versionTime time.Time,
 	}
 
 	filePath = osutil.NativeFilename(filePath)
-	tag := versionTime.In(locationLocal).Truncate(time.Second).Format(TimeFormat)
+	tag := versionTime.In(time.Local).Truncate(time.Second).Format(TimeFormat)
 
 	taggedFilename := TagFilename(filePath, tag)
 	oldTaggedFilename := filePath + tag
@@ -269,3 +263,30 @@ func fsFromParams(folderFs fs.Filesystem, params map[string]string) (versionsFs
 	l.Debugln("%s (%s) folder using %s (%s) versioner dir", folderFs.URI(), folderFs.Type(), versionsFs.URI(), versionsFs.Type())
 	return
 }
+
+type versionWithMtime struct {
+	name  string
+	mtime time.Time
+}
+
+func versionsToVersionsWithMtime(fs fs.Filesystem, versions []string) []versionWithMtime {
+	versionsWithMtimes := make([]versionWithMtime, 0, len(versions))
+
+	for _, version := range versions {
+		if stat, err := fs.Stat(version); err != nil {
+			// Welp, assume it's gone?
+			continue
+		} else {
+			versionsWithMtimes = append(versionsWithMtimes, versionWithMtime{
+				name:  version,
+				mtime: stat.ModTime(),
+			})
+		}
+	}
+
+	sort.Slice(versionsWithMtimes, func(i, j int) bool {
+		return versionsWithMtimes[i].mtime.Before(versionsWithMtimes[j].mtime)
+	})
+
+	return versionsWithMtimes
+}