sync: a save folder that cannot be written is said once, and waited on

internal/p2p/syncengine/engine.go

@@ -142,6 +142,10 @@ type Engine struct {
 	loopMu    sync.Mutex
 	triggered map[string]time.Time
 	pushBacks map[string]pushBack
+	// unwritableMu guards unwritable: per game whose save folder refused a
+	// pull, until when pulls into it wait (unwritable.go).
+	unwritableMu sync.Mutex
+	unwritable   map[string]time.Time
 
 	mu           sync.Mutex
 	activeSyncs  map[string]bool
@@ -346,6 +350,11 @@ func (e *Engine) SyncGame(ctx context.Context, gameID string, onlinePeers []Peer
 			busy = true
 			continue
 		}
+		if errors.Is(err, errSaveUnwritable) {
+			// Said once when it was found (unwritable.go); waiting meanwhile.
+			results[peer.ID] = Result{Status: "unwritable", PeerID: peer.ID, PeerName: peer.Name}
+			continue
+		}
 		if errors.Is(err, ErrPeerPaused) {
 			e.Log("info", fmt.Sprintf("%s has paused syncing; %s will sync with it when it resumes", peer.Name, gameID))
 			results[peer.ID] = Result{Status: "peer_paused", PeerID: peer.ID, PeerName: peer.Name}
@@ -362,7 +371,7 @@ func (e *Engine) SyncGame(ctx context.Context, gameID string, onlinePeers []Peer
 		// divergence from the NEXT sync, causing the peer to silently overwrite
 		// its own changes instead of detecting the conflict and asking.
 		switch res.Status {
-		case "conflict", "error":
+		case "conflict", "error", "unwritable":
 		case "peer_missing", "peer_awaiting_folder", "peer_holding":
 			// The two devices talked and finished, which is what the
 			// per-device stamp has always recorded. But nothing of THIS game
@@ -1587,6 +1596,12 @@ func (e *Engine) createPulledDirsIn(gameID string, root syncRoot, dirsToPull []s
 func (e *Engine) pullFiles(ctx context.Context, peer Peer, gameID string, game store.Game, root syncRoot,
 	localManifest delta.Manifest, remoteData ManifestResponse, filesToPull []string) (retErr error) {
 
+	// A folder that refused the last pull is left alone for a while
+	// (unwritable.go).
+	if until, waiting := e.unwritableUntil(gameID); waiting {
+		return fmt.Errorf("%w (trying again at %s)", errSaveUnwritable, until.Format("15:04"))
+	}
+
 	// This one is load-bearing, unlike the invalidations on the snapshot
 	// paths. Every pulled file is written and then stamped with the PEER'S
 	// modification time (see the Chtimes below), which can be OLDER than what
@@ -1760,7 +1775,7 @@ func (e *Engine) pullFiles(ctx context.Context, peer Peer, gameID string, game s
 		}
 		if err := e.pullFile(ctx, peer, FileRef{GameID: gameID, Root: root.Name, RelPath: relPath}, localFilePath,
 			remoteFile, indices, throttle, tracker, reportProgress); err != nil {
-			return err
+			return e.noteUnwritable(gameID, game.Name, root.Path, filepath.Dir(localFilePath), err)
 		}
 		if remoteFile.MtimeMs > 0 {
 			mtime := time.UnixMilli(int64(remoteFile.MtimeMs))

internal/p2p/syncengine/unwritable.go

@@ -0,0 +1,76 @@
+package syncengine
+
+import (
+	"errors"
+	"fmt"
+	"io/fs"
+	"os"
+	"time"
+)
+
+// A save folder this device may not write to — one under Program Files, for a
+// program not run as administrator — fails every pull into it with "access
+// denied". That is not something the next pass fixes, and every pass from
+// every peer tried again: the same raw error in the activity feed every few
+// seconds, saying nothing about what to do.
+//
+// So it is said once, plainly, with what to do, and pulls into that save wait
+// unwritableRetry before trying again. In memory: a restart, which may come
+// with new rights, tries straight away.
+
+// unwritableRetry is how long pulls into a save folder that could not be
+// written wait before trying it again.
+const unwritableRetry = 30 * time.Minute
+
+// errSaveUnwritable is what a pull into such a folder returns, said already.
+var errSaveUnwritable = errors.New("the save folder cannot be written")
+
+// unwritableUntil reports whether pulls into gameID's save are waiting, and
+// until when.
+func (e *Engine) unwritableUntil(gameID string) (time.Time, bool) {
+	e.unwritableMu.Lock()
+	defer e.unwritableMu.Unlock()
+	until, ok := e.unwritable[gameID]
+	if !ok || time.Now().After(until) {
+		delete(e.unwritable, gameID)
+		return time.Time{}, false
+	}
+	return until, true
+}
+
+// noteUnwritable turns a pull's error into errSaveUnwritable when it is the
+// folder refusing to be written, saying so once; any other error is returned
+// as it is. dir is the folder the file was being written in, saveFolder the
+// game's save folder, as said to the user.
+//
+// "Access denied" alone does not say which: on Windows, replacing a file a
+// running game holds open fails the same way. So the folder is asked
+// directly, with a small file made and removed in it. If that works, the
+// folder takes writes and it was a file in use: the ordinary retry applies.
+func (e *Engine) noteUnwritable(gameID, gameName, saveFolder, dir string, err error) error {
+	if !errors.Is(err, fs.ErrPermission) || folderTakesWrites(dir) {
+		return err
+	}
+	e.unwritableMu.Lock()
+	if e.unwritable == nil {
+		e.unwritable = map[string]time.Time{}
+	}
+	e.unwritable[gameID] = time.Now().Add(unwritableRetry)
+	e.unwritableMu.Unlock()
+	e.Log("error", fmt.Sprintf("%q: OpenSave may not write to its save folder %s (%v). Give OpenSave write access to the folder, or track the game at another one. Trying again in %d minutes.",
+		gameName, saveFolder, err, int(unwritableRetry.Minutes())))
+	return fmt.Errorf("%w: %v", errSaveUnwritable, err)
+}
+
+// folderTakesWrites reports whether a file can be made, and removed again, in
+// dir.
+func folderTakesWrites(dir string) bool {
+	f, err := os.CreateTemp(dir, ".opensave-probe-*")
+	if err != nil {
+		return false
+	}
+	name := f.Name()
+	f.Close()
+	os.Remove(name)
+	return true
+}

internal/p2p/syncengine/unwritable_test.go

@@ -0,0 +1,82 @@
+package syncengine
+
+import (
+	"context"
+	"os"
+	"os/exec"
+	"runtime"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/opensave/opensave/internal/delta"
+)
+
+// makeUnwritable makes a pull into the save fail the way a folder under
+// Program Files does: with "access denied". On Windows a folder denied writing cannot
+// be written; elsewhere a folder without write permission takes no new file.
+func makeUnwritable(t *testing.T, dir string) (restore func()) {
+	t.Helper()
+	if runtime.GOOS == "windows" {
+		// Everyone (S-1-1-0) denied writing in the folder: what a folder under
+		// Program Files is to a program not run as administrator.
+		if out, err := exec.Command("icacls", dir, "/deny", "*S-1-1-0:(OI)(CI)(WD,AD)").CombinedOutput(); err != nil {
+			t.Fatalf("icacls: %v %s", err, out)
+		}
+		restore = func() { exec.Command("icacls", dir, "/remove:d", "*S-1-1-0").Run() }
+		t.Cleanup(restore)
+		return restore
+	}
+	if os.Geteuid() == 0 {
+		t.Skip("root writes anywhere")
+	}
+	if err := os.Chmod(dir, 0o555); err != nil {
+		t.Fatal(err)
+	}
+	restore = func() { os.Chmod(dir, 0o777) }
+	t.Cleanup(restore)
+	return restore
+}
+
+// A save folder that cannot be written is said once, plainly, and pulls into
+// it wait instead of failing on every pass.
+func TestUnwritable_SaidOnceAndNotRetriedEveryPass(t *testing.T) {
+	env := setupEngine(t)
+	write(t, env.localDir, "save.dat", "old")
+	agreed, _ := delta.BuildManifest(env.localDir)
+	env.engine.persistLineage("game1", env.peer.ID, agreed, agreed)
+	if err := env.store.SetAgreedHash("game1", env.peer.ID, agreed.ManifestHash()); err != nil {
+		t.Fatal(err)
+	}
+	write(t, env.remoteDir, "save.dat", "newer from the peer")
+	stampFile(t, env.remoteDir, "save.dat", time.Now().Add(time.Hour))
+	restore := makeUnwritable(t, env.localDir)
+
+	var logs []string
+	env.engine.Log = func(level, msg string) { logs = append(logs, level+": "+msg) }
+
+	for i := 0; i < 3; i++ {
+		res, _ := env.engine.SyncGame(context.Background(), "game1", []Peer{env.peer})
+		t.Logf("pass %d: %+v", i, res[env.peer.ID])
+	}
+	n := 0
+	for _, l := range logs {
+		if strings.Contains(l, "may not write to its save folder") {
+			n++
+		}
+		t.Log(l)
+	}
+	if n != 1 {
+		t.Errorf("the unwritable folder was said %d times over three passes, want once", n)
+	}
+
+	// Rights given, and the wait over: the next pass takes the peer's save.
+	restore()
+	env.engine.unwritableMu.Lock()
+	env.engine.unwritable["game1"] = time.Now().Add(-time.Second)
+	env.engine.unwritableMu.Unlock()
+	res, _ := env.engine.SyncGame(context.Background(), "game1", []Peer{env.peer})
+	if got := readFile(t, env.localDir, "save.dat"); got != "newer from the peer" {
+		t.Errorf("after the wait the save was not taken: %+v, save.dat=%q", res[env.peer.ID], got)
+	}
+}

internal/p2p/syncengine/unwritable_windows_test.go

@@ -0,0 +1,64 @@
+package syncengine
+
+import (
+	"context"
+	"path/filepath"
+	"strings"
+	"testing"
+
+	"golang.org/x/sys/windows"
+
+	"github.com/opensave/opensave/internal/delta"
+)
+
+// A save file the game holds open cannot be replaced either, and Windows says
+// "access denied" for that too. The folder still takes writes, so it is not
+// called unwritable: no message, no wait, and the next pass tries again
+// (asked in review on #114).
+func TestUnwritable_AFileInUseIsNotAnUnwritableFolder(t *testing.T) {
+	env := setupEngine(t)
+	write(t, env.localDir, "save.dat", "old")
+	agreed, _ := delta.BuildManifest(env.localDir)
+	env.engine.persistLineage("game1", env.peer.ID, agreed, agreed)
+	if err := env.store.SetAgreedHash("game1", env.peer.ID, agreed.ManifestHash()); err != nil {
+		t.Fatal(err)
+	}
+	write(t, env.remoteDir, "save.dat", "newer from the peer")
+
+	// Held open for reading and writing but not deleting, as a running game
+	// holds its save: replacing it is then refused as "access denied".
+	p, _ := windows.UTF16PtrFromString(filepath.Join(env.localDir, "save.dat"))
+	h, err := windows.CreateFile(p, windows.GENERIC_READ|windows.GENERIC_WRITE, windows.FILE_SHARE_READ|windows.FILE_SHARE_WRITE, nil, windows.OPEN_EXISTING, windows.FILE_ATTRIBUTE_NORMAL, 0)
+	if err != nil {
+		t.Fatal(err)
+	}
+	held := true
+	defer func() {
+		if held {
+			windows.CloseHandle(h)
+		}
+	}()
+
+	var logs []string
+	env.engine.Log = func(level, msg string) { logs = append(logs, msg) }
+	res, _ := env.engine.SyncGame(context.Background(), "game1", []Peer{env.peer})
+	if r := res[env.peer.ID]; r.Status == "unwritable" {
+		t.Errorf("a file in use was taken for an unwritable folder: %+v", r)
+	}
+	for _, l := range logs {
+		if strings.Contains(l, "may not write to its save folder") {
+			t.Errorf("said the folder cannot be written: %s", l)
+		}
+	}
+	if _, waiting := env.engine.unwritableUntil("game1"); waiting {
+		t.Error("pulls into the save wait, though only a file was in use")
+	}
+
+	// The game lets go: the next pass takes the save at once.
+	windows.CloseHandle(h)
+	held = false
+	env.engine.SyncGame(context.Background(), "game1", []Peer{env.peer})
+	if got := readFile(t, env.localDir, "save.dat"); got != "newer from the peer" {
+		t.Errorf("after the file was let go, save.dat = %q", got)
+	}
+}