diff --git a/internal/p2p/syncengine/engine.go b/internal/p2p/syncengine/engine.go index 3a0089fa..8625a244 100644 --- a/internal/p2p/syncengine/engine.go +++ b/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)) diff --git a/internal/p2p/syncengine/unwritable.go b/internal/p2p/syncengine/unwritable.go new file mode 100644 index 00000000..ffb199c8 --- /dev/null +++ b/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 +} diff --git a/internal/p2p/syncengine/unwritable_test.go b/internal/p2p/syncengine/unwritable_test.go new file mode 100644 index 00000000..9bff96ae --- /dev/null +++ b/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) + } +} diff --git a/internal/p2p/syncengine/unwritable_windows_test.go b/internal/p2p/syncengine/unwritable_windows_test.go new file mode 100644 index 00000000..876ae6b3 --- /dev/null +++ b/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) + } +}