Virtual mtime support for environments that don't support altering mtimes (fixes #831)

AUTHORS

@@ -13,6 +13,7 @@ Brendan Long <self@brendanlong.com>
 Caleb Callaway <enlightened.despot@gmail.com>
 Carsten Hagemann <moter8@gmail.com>
 Cathryne Linenweaver <cathryne.linenweaver@gmail.com> <Cathryne@users.noreply.github.com>
+Chris Howie <me@chrishowie.com>
 Chris Joel <chris@scriptolo.gy>
 Colin Kennedy <moshen.colin@gmail.com>
 Daniel Martí <mvdan@mvdan.cc>

internal/config/config.go

@@ -78,7 +78,6 @@ type FolderConfiguration struct {
 	IgnorePerms     bool                        `xml:"ignorePerms,attr" json:"ignorePerms"`
 	AutoNormalize   bool                        `xml:"autoNormalize,attr" json:"autoNormalize"`
 	Versioning      VersioningConfiguration     `xml:"versioning" json:"versioning"`
-	LenientMtimes   bool                        `xml:"lenientMtimes" json:"lenientMTimes"`
 	Copiers         int                         `xml:"copiers" json:"copiers"` // This defines how many files are handled concurrently.
 	Pullers         int                         `xml:"pullers" json:"pullers"` // Defines how many blocks are fetched at the same time, possibly between separate copier routines.
 	Hashers         int                         `xml:"hashers" json:"hashers"` // Less than one sets the value to the number of cores. These are CPU bound due to hashing.

internal/db/leveldb.go

@@ -45,6 +45,7 @@ const (
 	KeyTypeBlock
 	KeyTypeDeviceStatistic
 	KeyTypeFolderStatistic
+	KeyTypeVirtualMtime
 )
 
 type fileVersion struct {
@@ -314,6 +315,8 @@ func ldbReplace(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo) i
 }
 
 func ldbReplaceWithDelete(db *leveldb.DB, folder, device []byte, fs []protocol.FileInfo, myID uint64) int64 {
+	mtimeRepo := NewVirtualMtimeRepo(db, string(folder))
+
 	return ldbGenericReplace(db, folder, device, fs, func(db dbReader, batch dbWriter, folder, device, name []byte, dbi iterator.Iterator) int64 {
 		var tf FileInfoTruncated
 		err := tf.UnmarshalXDR(dbi.Value())
@@ -337,6 +340,7 @@ func ldbReplaceWithDelete(db *leveldb.DB, folder, device []byte, fs []protocol.F
 				l.Debugf("batch.Put %p %x", batch, dbi.Key())
 			}
 			batch.Put(dbi.Key(), bs)
+			mtimeRepo.DeleteMtime(tf.Name)
 			ldbUpdateGlobal(db, batch, folder, device, deviceKeyName(dbi.Key()), f.Version)
 			return ts
 		}

internal/db/namespaced.go

@@ -111,6 +111,24 @@ func (n NamespacedKV) String(key string) (string, bool) {
 	return string(valBs), true
 }
 
+// PutBytes stores a new byte slice. Any existing value (even if of another type)
+// is overwritten.
+func (n *NamespacedKV) PutBytes(key string, val []byte) {
+	keyBs := append(n.prefix, []byte(key)...)
+	n.db.Put(keyBs, val, nil)
+}
+
+// Bytes returns the stored value as a raw byte slice and a boolean that
+// is false if no value was stored at the key.
+func (n NamespacedKV) Bytes(key string) ([]byte, bool) {
+	keyBs := append(n.prefix, []byte(key)...)
+	valBs, err := n.db.Get(keyBs, nil)
+	if err != nil {
+		return nil, false
+	}
+	return valBs, true
+}
+
 // Delete deletes the specified key. It is allowed to delete a nonexistent
 // key.
 func (n NamespacedKV) Delete(key string) {

internal/db/set.go

@@ -228,6 +228,7 @@ func DropFolder(db *leveldb.DB, folder string) {
 		folder: folder,
 	}
 	bm.Drop()
+	NewVirtualMtimeRepo(db, folder).Drop()
 }
 
 func normalizeFilenames(fs []protocol.FileInfo) {

internal/db/virtualmtime.go

@@ -0,0 +1,86 @@
+// Copyright (C) 2015 The Syncthing Authors.
+//
+// This Source Code Form is subject to the terms of the Mozilla Public
+// License, v. 2.0. If a copy of the MPL was not distributed with this file,
+// You can obtain one at http://mozilla.org/MPL/2.0/.
+
+package db
+
+import (
+	"fmt"
+	"time"
+
+	"github.com/syndtr/goleveldb/leveldb"
+)
+
+// This type encapsulates a repository of mtimes for platforms where file mtimes
+// can't be set to arbitrary values.  For this to work, we need to store both
+// the mtime we tried to set (the "actual" mtime) as well as the mtime the file
+// has when we're done touching it (the "disk" mtime) so that we can tell if it
+// was changed.  So in GetMtime(), it's not sufficient that the record exists --
+// the argument must also equal the "disk" mtime in the record, otherwise it's
+// been touched locally and the "disk" mtime is actually correct.
+
+type VirtualMtimeRepo struct {
+	ns *NamespacedKV
+}
+
+func NewVirtualMtimeRepo(ldb *leveldb.DB, folder string) *VirtualMtimeRepo {
+	prefix := string(KeyTypeVirtualMtime) + folder
+
+	return &VirtualMtimeRepo{
+		ns: NewNamespacedKV(ldb, prefix),
+	}
+}
+
+func (r *VirtualMtimeRepo) UpdateMtime(path string, diskMtime, actualMtime time.Time) {
+	if debug {
+		l.Debugf("virtual mtime: storing values for path:%s disk:%v actual:%v", path, diskMtime, actualMtime)
+	}
+
+	diskBytes, _ := diskMtime.MarshalBinary()
+	actualBytes, _ := actualMtime.MarshalBinary()
+
+	data := append(diskBytes, actualBytes...)
+
+	r.ns.PutBytes(path, data)
+}
+
+func (r *VirtualMtimeRepo) GetMtime(path string, diskMtime time.Time) time.Time {
+	var debugResult string
+
+	if data, exists := r.ns.Bytes(path); exists {
+		var mtime time.Time
+
+		if err := mtime.UnmarshalBinary(data[:len(data)/2]); err != nil {
+			panic(fmt.Sprintf("Can't unmarshal stored mtime at path %v: %v", path, err))
+		}
+
+		if mtime.Equal(diskMtime) {
+			if err := mtime.UnmarshalBinary(data[len(data)/2:]); err != nil {
+				panic(fmt.Sprintf("Can't unmarshal stored mtime at path %v: %v", path, err))
+			}
+
+			debugResult = "got it"
+			diskMtime = mtime
+		} else if debug {
+			debugResult = fmt.Sprintf("record exists, but mismatch inDisk:%v dbDisk:%v", diskMtime, mtime)
+		}
+	} else {
+		debugResult = "record does not exist"
+	}
+
+	if debug {
+		l.Debugf("virtual mtime: value get result:%v path:%s", debugResult, path)
+	}
+
+	return diskMtime
+}
+
+func (r *VirtualMtimeRepo) DeleteMtime(path string) {
+	r.ns.Delete(path)
+}
+
+func (r *VirtualMtimeRepo) Drop() {
+	r.ns.Reset()
+}

internal/db/virtualmtime_test.go

@@ -0,0 +1,80 @@
+// Copyright (C) 2015 The Syncthing Authors.
+//
+// This Source Code Form is subject to the terms of the Mozilla Public
+// License, v. 2.0. If a copy of the MPL was not distributed with this file,
+// You can obtain one at http://mozilla.org/MPL/2.0/.
+
+package db
+
+import (
+	"testing"
+	"time"
+
+	"github.com/syndtr/goleveldb/leveldb"
+	"github.com/syndtr/goleveldb/leveldb/storage"
+)
+
+func TestVirtualMtimeRepo(t *testing.T) {
+	ldb, err := leveldb.Open(storage.NewMemStorage(), nil)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	// A few repos so we can ensure they don't pollute each other
+	repo1 := NewVirtualMtimeRepo(ldb, "folder1")
+	repo2 := NewVirtualMtimeRepo(ldb, "folder2")
+
+	// Since GetMtime() returns its argument if the key isn't found or is outdated, we need a dummy to test with.
+	dummyTime := time.Date(2001, time.February, 3, 4, 5, 6, 0, time.UTC)
+
+	// Some times to test with
+	time1 := time.Date(2001, time.February, 3, 4, 5, 7, 0, time.UTC)
+	time2 := time.Date(2010, time.February, 3, 4, 5, 6, 0, time.UTC)
+
+	file1 := "file1.txt"
+
+	// Files are not present at the start
+
+	if v := repo1.GetMtime(file1, dummyTime); !v.Equal(dummyTime) {
+		t.Errorf("Mtime should be missing (%v) from repo 1 but it's %v", dummyTime, v)
+	}
+
+	if v := repo2.GetMtime(file1, dummyTime); !v.Equal(dummyTime) {
+		t.Errorf("Mtime should be missing (%v) from repo 2 but it's %v", dummyTime, v)
+	}
+
+	repo1.UpdateMtime(file1, time1, time2)
+
+	// Now it should return time2 only when time1 is passed as the argument
+
+	if v := repo1.GetMtime(file1, time1); !v.Equal(time2) {
+		t.Errorf("Mtime should be %v for disk time %v but we got %v", time2, time1, v)
+	}
+
+	if v := repo1.GetMtime(file1, dummyTime); !v.Equal(dummyTime) {
+		t.Errorf("Mtime should be %v for disk time %v but we got %v", dummyTime, dummyTime, v)
+	}
+
+	// repo2 shouldn't know about this file
+
+	if v := repo2.GetMtime(file1, time1); !v.Equal(time1) {
+		t.Errorf("Mtime should be %v for disk time %v in repo 2 but we got %v", time1, time1, v)
+	}
+
+	repo1.DeleteMtime(file1)
+
+	// Now it should be gone
+
+	if v := repo1.GetMtime(file1, time1); !v.Equal(time1) {
+		t.Errorf("Mtime should be %v for disk time %v but we got %v", time1, time1, v)
+	}
+
+	// Try again but with Drop()
+
+	repo1.UpdateMtime(file1, time1, time2)
+	repo1.Drop()
+
+	if v := repo1.GetMtime(file1, time1); !v.Equal(time1) {
+		t.Errorf("Mtime should be %v for disk time %v but we got %v", time1, time1, v)
+	}
+}

internal/model/model.go

@@ -163,10 +163,6 @@ func (m *Model) StartFolderRW(folder string) {
 		p.versioner = factory(folder, cfg.Path(), cfg.Versioning.Params)
 	}
 
-	if cfg.LenientMtimes {
-		l.Infof("Folder %q is running with LenientMtimes workaround. Syncing may not work properly.", folder)
-	}
-
 	go p.Serve()
 }
 
@@ -1222,6 +1218,7 @@ nextSub:
 		TempNamer:     defTempNamer,
 		TempLifetime:  time.Duration(m.cfg.Options().KeepTemporariesH) * time.Hour,
 		CurrentFiler:  cFiler{m, folder},
+		MtimeRepo:     db.NewVirtualMtimeRepo(m.db, folderCfg.ID),
 		IgnorePerms:   folderCfg.IgnorePerms,
 		AutoNormalize: folderCfg.AutoNormalize,
 		Hashers:       m.numHashers(folder),

internal/model/rwfolder.go

@@ -57,19 +57,19 @@ var (
 type rwFolder struct {
 	stateTracker
 
-	model           *Model
-	progressEmitter *ProgressEmitter
+	model            *Model
+	progressEmitter  *ProgressEmitter
+	virtualMtimeRepo *db.VirtualMtimeRepo
 
-	folder        string
-	dir           string
-	scanIntv      time.Duration
-	versioner     versioner.Versioner
-	ignorePerms   bool
-	lenientMtimes bool
-	copiers       int
-	pullers       int
-	shortID       uint64
-	order         config.PullOrder
+	folder      string
+	dir         string
+	scanIntv    time.Duration
+	versioner   versioner.Versioner
+	ignorePerms bool
+	copiers     int
+	pullers     int
+	shortID     uint64
+	order       config.PullOrder
 
 	stop        chan struct{}
 	queue       *jobQueue
@@ -87,18 +87,18 @@ func newRWFolder(m *Model, shortID uint64, cfg config.FolderConfiguration) *rwFo
 			mut:    sync.NewMutex(),
 		},
 
-		model:           m,
-		progressEmitter: m.progressEmitter,
+		model:            m,
+		progressEmitter:  m.progressEmitter,
+		virtualMtimeRepo: db.NewVirtualMtimeRepo(m.db, cfg.ID),
 
-		folder:        cfg.ID,
-		dir:           cfg.Path(),
-		scanIntv:      time.Duration(cfg.RescanIntervalS) * time.Second,
-		ignorePerms:   cfg.IgnorePerms,
-		lenientMtimes: cfg.LenientMtimes,
-		copiers:       cfg.Copiers,
-		pullers:       cfg.Pullers,
-		shortID:       shortID,
-		order:         cfg.Order,
+		folder:      cfg.ID,
+		dir:         cfg.Path(),
+		scanIntv:    time.Duration(cfg.RescanIntervalS) * time.Second,
+		ignorePerms: cfg.IgnorePerms,
+		copiers:     cfg.Copiers,
+		pullers:     cfg.Pullers,
+		shortID:     shortID,
+		order:       cfg.Order,
 
 		stop:        make(chan struct{}),
 		queue:       newJobQueue(),
@@ -861,30 +861,25 @@ func (p *rwFolder) handleFile(file protocol.FileInfo, copyChan chan<- copyBlocks
 
 // shortcutFile sets file mode and modification time, when that's the only
 // thing that has changed.
-func (p *rwFolder) shortcutFile(file protocol.FileInfo) (err error) {
+func (p *rwFolder) shortcutFile(file protocol.FileInfo) error {
 	realName := filepath.Join(p.dir, file.Name)
 	if !p.ignorePerms {
-		err = os.Chmod(realName, os.FileMode(file.Flags&0777))
-		if err != nil {
-			l.Infof("Puller (folder %q, file %q): shortcut: %v", p.folder, file.Name, err)
-			return
+		if err := os.Chmod(realName, os.FileMode(file.Flags&0777)); err != nil {
+			l.Infof("Puller (folder %q, file %q): shortcut: chmod: %v", p.folder, file.Name, err)
+			return err
 		}
 	}
 
 	t := time.Unix(file.Modified, 0)
-	err = os.Chtimes(realName, t, t)
-	if err != nil {
-		if p.lenientMtimes {
-			err = nil
-			// We accept the failure with a warning here and allow the sync to
-			// continue. We'll sync the new mtime back to the other devices later.
-			// If they have the same problem & setting, we might never get in
-			// sync.
-			l.Infof("Puller (folder %q, file %q): shortcut: %v (continuing anyway as requested)", p.folder, file.Name, err)
-		} else {
-			l.Infof("Puller (folder %q, file %q): shortcut: %v", p.folder, file.Name, err)
-			return
+	if err := os.Chtimes(realName, t, t); err != nil {
+		// Try using virtual mtimes
+		info, err := os.Stat(realName)
+		if err != nil {
+			l.Infof("Puller (folder %q, file %q): shortcut: unable to stat file: %v", p.folder, file.Name, err)
+			return err
 		}
+
+		p.virtualMtimeRepo.UpdateMtime(file.Name, info.ModTime(), t)
 	}
 
 	// This may have been a conflict. We should merge the version vectors so
@@ -894,7 +889,7 @@ func (p *rwFolder) shortcutFile(file protocol.FileInfo) (err error) {
 	}
 
 	p.dbUpdates <- file
-	return
+	return nil
 }
 
 // shortcutSymlink changes the symlinks type if necessary.
@@ -1078,15 +1073,11 @@ func (p *rwFolder) performFinish(state *sharedPullerState) {
 	t := time.Unix(state.file.Modified, 0)
 	err = os.Chtimes(state.tempName, t, t)
 	if err != nil {
-		if p.lenientMtimes {
-			// We accept the failure with a warning here and allow the sync to
-			// continue. We'll sync the new mtime back to the other devices later.
-			// If they have the same problem & setting, we might never get in
-			// sync.
-			l.Infof("Puller (folder %q, file %q): final: %v (continuing anyway as requested)", p.folder, state.file.Name, err)
+		// First try using virtual mtimes
+		if info, err := os.Stat(state.tempName); err != nil {
+			l.Infof("Puller (folder %q, file %q): final: unable to stat file: %v", p.folder, state.file.Name, err)
 		} else {
-			l.Warnln("Puller: final:", err)
-			return
+			p.virtualMtimeRepo.UpdateMtime(state.file.Name, info.ModTime(), t)
 		}
 	}
 

internal/scanner/walk.go

@@ -16,6 +16,7 @@ import (
 	"unicode/utf8"
 
 	"github.com/syncthing/protocol"
+	"github.com/syncthing/syncthing/internal/db"
 	"github.com/syncthing/syncthing/internal/ignore"
 	"github.com/syncthing/syncthing/internal/osutil"
 	"github.com/syncthing/syncthing/internal/symlinks"
@@ -52,6 +53,8 @@ type Walker struct {
 	TempLifetime time.Duration
 	// If CurrentFiler is not nil, it is queried for the current file before rescanning.
 	CurrentFiler CurrentFiler
+	// If MtimeRepo is not nil, it is used to provide mtimes on systems that don't support setting arbirtary mtimes.
+	MtimeRepo *db.VirtualMtimeRepo
 	// If IgnorePerms is true, changes to permission bits will not be
 	// detected. Scanned files will get zero permission bits and the
 	// NoPermissionBits flag set.
@@ -138,15 +141,20 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 			return nil
 		}
 
+		mtime := info.ModTime()
+		if w.MtimeRepo != nil {
+			mtime = w.MtimeRepo.GetMtime(rn, mtime)
+		}
+
 		if w.TempNamer != nil && w.TempNamer.IsTemporary(rn) {
 			// A temporary file
 			if debug {
 				l.Debugln("temporary:", rn)
 			}
-			if info.Mode().IsRegular() && info.ModTime().Add(w.TempLifetime).Before(now) {
+			if info.Mode().IsRegular() && mtime.Add(w.TempLifetime).Before(now) {
 				os.Remove(p)
 				if debug {
-					l.Debugln("removing temporary:", rn, info.ModTime())
+					l.Debugln("removing temporary:", rn, mtime)
 				}
 			}
 			return nil
@@ -298,7 +306,7 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 				Name:     rn,
 				Version:  cf.Version.Update(w.ShortID),
 				Flags:    flags,
-				Modified: info.ModTime().Unix(),
+				Modified: mtime.Unix(),
 			}
 			if debug {
 				l.Debugln("dir:", p, f)
@@ -325,13 +333,13 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 				//  - has the same size as previously
 				cf, ok = w.CurrentFiler.CurrentFile(rn)
 				permUnchanged := w.IgnorePerms || !cf.HasPermissionBits() || PermsEqual(cf.Flags, curMode)
-				if ok && permUnchanged && !cf.IsDeleted() && cf.Modified == info.ModTime().Unix() && !cf.IsDirectory() &&
+				if ok && permUnchanged && !cf.IsDeleted() && cf.Modified == mtime.Unix() && !cf.IsDirectory() &&
 					!cf.IsSymlink() && !cf.IsInvalid() && cf.Size() == info.Size() {
 					return nil
 				}
 
 				if debug {
-					l.Debugln("rescan:", cf, info.ModTime().Unix(), info.Mode()&os.ModePerm)
+					l.Debugln("rescan:", cf, mtime.Unix(), info.Mode()&os.ModePerm)
 				}
 			}
 
@@ -344,7 +352,7 @@ func (w *Walker) walkAndHashFiles(fchan chan protocol.FileInfo) filepath.WalkFun
 				Name:     rn,
 				Version:  cf.Version.Update(w.ShortID),
 				Flags:    flags,
-				Modified: info.ModTime().Unix(),
+				Modified: mtime.Unix(),
 			}
 			if debug {
 				l.Debugln("to hash:", p, f)