restic/cmd/restic/cmd_mount_integration_test.go

223 lines
5.8 KiB
Go
Raw Permalink Normal View History

2022-03-28 22:23:47 +02:00
//go:build darwin || freebsd || linux
// +build darwin freebsd linux
package main
import (
"context"
"fmt"
"os"
"path/filepath"
mount: only start next test after mount command cleanup is complete The test did not wait for the mount command to fully shutdown all running goroutines. This caused the go race detector to report a data race related to lock refreshes. ================== WARNING: DATA RACE Write at 0x0000021bdfdb by goroutine 667: github.com/restic/restic/internal/backend/retry.TestFastRetries() /restic/restic/internal/backend/retry/testing.go:7 +0x18f github.com/restic/restic/cmd/restic.withTestEnvironment() /restic/restic/cmd/restic/integration_helpers_test.go:175 +0x183 github.com/restic/restic/cmd/restic.TestMountSameTimestamps() /restic/restic/cmd/restic/integration_fuse_test.go:202 +0xac testing.tRunner() /usr/lib/go/src/testing/testing.go:1446 +0x216 testing.(*T).Run.func1() /usr/lib/go/src/testing/testing.go:1493 +0x47 Previous read at 0x0000021bdfdb by goroutine 609: github.com/restic/restic/internal/backend/retry.(*Backend).retry() /restic/restic/internal/backend/retry/backend_retry.go:72 +0x9e github.com/restic/restic/internal/backend/retry.(*Backend).Remove() /restic/restic/internal/backend/retry/backend_retry.go:149 +0x17d github.com/restic/restic/internal/cache.(*Backend).Remove() /restic/restic/internal/cache/backend.go:38 +0x11d github.com/restic/restic/internal/restic.(*Lock).Unlock() /restic/restic/internal/restic/lock.go:190 +0x249 github.com/restic/restic/cmd/restic.refreshLocks.func1() /restic/restic/cmd/restic/lock.go:86 +0xae runtime.deferreturn() /usr/lib/go/src/runtime/panic.go:476 +0x32 github.com/restic/restic/cmd/restic.lockRepository.func2() /restic/restic/cmd/restic/lock.go:61 +0x71 [...] Goroutine 609 (finished) created at: github.com/restic/restic/cmd/restic.lockRepository() /restic/restic/cmd/restic/lock.go:61 +0x488 github.com/restic/restic/cmd/restic.lockRepo() /restic/restic/cmd/restic/lock.go:25 +0x219 github.com/restic/restic/cmd/restic.runMount() /restic/restic/cmd/restic/cmd_mount.go:126 +0x1f8 github.com/restic/restic/cmd/restic.testRunMount() /restic/restic/cmd/restic/integration_fuse_test.go:61 +0x1ce github.com/restic/restic/cmd/restic.checkSnapshots.func1() /restic/restic/cmd/restic/integration_fuse_test.go:90 +0x124 ==================
2022-11-11 21:40:33 +01:00
"sync"
"testing"
"time"
systemFuse "github.com/anacrolix/fuse"
2017-07-24 17:42:25 +02:00
"github.com/restic/restic/internal/restic"
rtest "github.com/restic/restic/internal/test"
)
2015-07-19 22:53:10 +02:00
const (
mountWait = 20
mountSleep = 100 * time.Millisecond
mountTestSubdir = "snapshots"
)
2016-09-15 21:17:20 +02:00
func snapshotsDirExists(t testing.TB, dir string) bool {
f, err := os.Open(filepath.Join(dir, mountTestSubdir))
if err != nil && os.IsNotExist(err) {
return false
}
2015-07-19 22:53:10 +02:00
2016-09-15 21:17:20 +02:00
if err != nil {
t.Error(err)
}
2015-07-19 22:53:10 +02:00
2016-09-15 21:17:20 +02:00
if err := f.Close(); err != nil {
t.Error(err)
}
2015-07-19 22:53:10 +02:00
2016-09-15 21:17:20 +02:00
return true
}
// waitForMount blocks (max mountWait * mountSleep) until the subdir
// "snapshots" appears in the dir.
func waitForMount(t testing.TB, dir string) {
for i := 0; i < mountWait; i++ {
if snapshotsDirExists(t, dir) {
t.Log("mounted directory is ready")
return
2015-07-19 22:53:10 +02:00
}
time.Sleep(mountSleep)
}
2016-09-15 21:17:20 +02:00
t.Errorf("subdir %q of dir %s never appeared", mountTestSubdir, dir)
2015-07-19 22:53:10 +02:00
}
mount: only start next test after mount command cleanup is complete The test did not wait for the mount command to fully shutdown all running goroutines. This caused the go race detector to report a data race related to lock refreshes. ================== WARNING: DATA RACE Write at 0x0000021bdfdb by goroutine 667: github.com/restic/restic/internal/backend/retry.TestFastRetries() /restic/restic/internal/backend/retry/testing.go:7 +0x18f github.com/restic/restic/cmd/restic.withTestEnvironment() /restic/restic/cmd/restic/integration_helpers_test.go:175 +0x183 github.com/restic/restic/cmd/restic.TestMountSameTimestamps() /restic/restic/cmd/restic/integration_fuse_test.go:202 +0xac testing.tRunner() /usr/lib/go/src/testing/testing.go:1446 +0x216 testing.(*T).Run.func1() /usr/lib/go/src/testing/testing.go:1493 +0x47 Previous read at 0x0000021bdfdb by goroutine 609: github.com/restic/restic/internal/backend/retry.(*Backend).retry() /restic/restic/internal/backend/retry/backend_retry.go:72 +0x9e github.com/restic/restic/internal/backend/retry.(*Backend).Remove() /restic/restic/internal/backend/retry/backend_retry.go:149 +0x17d github.com/restic/restic/internal/cache.(*Backend).Remove() /restic/restic/internal/cache/backend.go:38 +0x11d github.com/restic/restic/internal/restic.(*Lock).Unlock() /restic/restic/internal/restic/lock.go:190 +0x249 github.com/restic/restic/cmd/restic.refreshLocks.func1() /restic/restic/cmd/restic/lock.go:86 +0xae runtime.deferreturn() /usr/lib/go/src/runtime/panic.go:476 +0x32 github.com/restic/restic/cmd/restic.lockRepository.func2() /restic/restic/cmd/restic/lock.go:61 +0x71 [...] Goroutine 609 (finished) created at: github.com/restic/restic/cmd/restic.lockRepository() /restic/restic/cmd/restic/lock.go:61 +0x488 github.com/restic/restic/cmd/restic.lockRepo() /restic/restic/cmd/restic/lock.go:25 +0x219 github.com/restic/restic/cmd/restic.runMount() /restic/restic/cmd/restic/cmd_mount.go:126 +0x1f8 github.com/restic/restic/cmd/restic.testRunMount() /restic/restic/cmd/restic/integration_fuse_test.go:61 +0x1ce github.com/restic/restic/cmd/restic.checkSnapshots.func1() /restic/restic/cmd/restic/integration_fuse_test.go:90 +0x124 ==================
2022-11-11 21:40:33 +01:00
func testRunMount(t testing.TB, gopts GlobalOptions, dir string, wg *sync.WaitGroup) {
defer wg.Done()
opts := MountOptions{
TimeTemplate: time.RFC3339,
}
rtest.OK(t, runMount(context.TODO(), opts, gopts, []string{dir}))
2016-09-15 21:17:20 +02:00
}
func testRunUmount(t testing.TB, dir string) {
2016-09-15 21:32:15 +02:00
var err error
for i := 0; i < mountWait; i++ {
if err = systemFuse.Unmount(dir); err == nil {
2016-09-15 21:32:15 +02:00
t.Logf("directory %v umounted", dir)
return
}
time.Sleep(mountSleep)
}
t.Errorf("unable to umount dir %v, last error was: %v", dir, err)
2016-09-15 21:17:20 +02:00
}
func listSnapshots(t testing.TB, dir string) []string {
snapshotsDir, err := os.Open(filepath.Join(dir, "snapshots"))
rtest.OK(t, err)
2016-09-15 21:17:20 +02:00
names, err := snapshotsDir.Readdirnames(-1)
rtest.OK(t, err)
rtest.OK(t, snapshotsDir.Close())
2016-09-15 21:17:20 +02:00
return names
}
func checkSnapshots(t testing.TB, gopts GlobalOptions, mountpoint string, snapshotIDs restic.IDs, expectedSnapshotsInFuseDir int) {
2016-09-18 18:30:25 +02:00
t.Logf("checking for %d snapshots: %v", len(snapshotIDs), snapshotIDs)
2017-06-18 14:23:35 +02:00
mount: only start next test after mount command cleanup is complete The test did not wait for the mount command to fully shutdown all running goroutines. This caused the go race detector to report a data race related to lock refreshes. ================== WARNING: DATA RACE Write at 0x0000021bdfdb by goroutine 667: github.com/restic/restic/internal/backend/retry.TestFastRetries() /restic/restic/internal/backend/retry/testing.go:7 +0x18f github.com/restic/restic/cmd/restic.withTestEnvironment() /restic/restic/cmd/restic/integration_helpers_test.go:175 +0x183 github.com/restic/restic/cmd/restic.TestMountSameTimestamps() /restic/restic/cmd/restic/integration_fuse_test.go:202 +0xac testing.tRunner() /usr/lib/go/src/testing/testing.go:1446 +0x216 testing.(*T).Run.func1() /usr/lib/go/src/testing/testing.go:1493 +0x47 Previous read at 0x0000021bdfdb by goroutine 609: github.com/restic/restic/internal/backend/retry.(*Backend).retry() /restic/restic/internal/backend/retry/backend_retry.go:72 +0x9e github.com/restic/restic/internal/backend/retry.(*Backend).Remove() /restic/restic/internal/backend/retry/backend_retry.go:149 +0x17d github.com/restic/restic/internal/cache.(*Backend).Remove() /restic/restic/internal/cache/backend.go:38 +0x11d github.com/restic/restic/internal/restic.(*Lock).Unlock() /restic/restic/internal/restic/lock.go:190 +0x249 github.com/restic/restic/cmd/restic.refreshLocks.func1() /restic/restic/cmd/restic/lock.go:86 +0xae runtime.deferreturn() /usr/lib/go/src/runtime/panic.go:476 +0x32 github.com/restic/restic/cmd/restic.lockRepository.func2() /restic/restic/cmd/restic/lock.go:61 +0x71 [...] Goroutine 609 (finished) created at: github.com/restic/restic/cmd/restic.lockRepository() /restic/restic/cmd/restic/lock.go:61 +0x488 github.com/restic/restic/cmd/restic.lockRepo() /restic/restic/cmd/restic/lock.go:25 +0x219 github.com/restic/restic/cmd/restic.runMount() /restic/restic/cmd/restic/cmd_mount.go:126 +0x1f8 github.com/restic/restic/cmd/restic.testRunMount() /restic/restic/cmd/restic/integration_fuse_test.go:61 +0x1ce github.com/restic/restic/cmd/restic.checkSnapshots.func1() /restic/restic/cmd/restic/integration_fuse_test.go:90 +0x124 ==================
2022-11-11 21:40:33 +01:00
var wg sync.WaitGroup
wg.Add(1)
go testRunMount(t, gopts, mountpoint, &wg)
2016-09-18 18:30:25 +02:00
waitForMount(t, mountpoint)
mount: only start next test after mount command cleanup is complete The test did not wait for the mount command to fully shutdown all running goroutines. This caused the go race detector to report a data race related to lock refreshes. ================== WARNING: DATA RACE Write at 0x0000021bdfdb by goroutine 667: github.com/restic/restic/internal/backend/retry.TestFastRetries() /restic/restic/internal/backend/retry/testing.go:7 +0x18f github.com/restic/restic/cmd/restic.withTestEnvironment() /restic/restic/cmd/restic/integration_helpers_test.go:175 +0x183 github.com/restic/restic/cmd/restic.TestMountSameTimestamps() /restic/restic/cmd/restic/integration_fuse_test.go:202 +0xac testing.tRunner() /usr/lib/go/src/testing/testing.go:1446 +0x216 testing.(*T).Run.func1() /usr/lib/go/src/testing/testing.go:1493 +0x47 Previous read at 0x0000021bdfdb by goroutine 609: github.com/restic/restic/internal/backend/retry.(*Backend).retry() /restic/restic/internal/backend/retry/backend_retry.go:72 +0x9e github.com/restic/restic/internal/backend/retry.(*Backend).Remove() /restic/restic/internal/backend/retry/backend_retry.go:149 +0x17d github.com/restic/restic/internal/cache.(*Backend).Remove() /restic/restic/internal/cache/backend.go:38 +0x11d github.com/restic/restic/internal/restic.(*Lock).Unlock() /restic/restic/internal/restic/lock.go:190 +0x249 github.com/restic/restic/cmd/restic.refreshLocks.func1() /restic/restic/cmd/restic/lock.go:86 +0xae runtime.deferreturn() /usr/lib/go/src/runtime/panic.go:476 +0x32 github.com/restic/restic/cmd/restic.lockRepository.func2() /restic/restic/cmd/restic/lock.go:61 +0x71 [...] Goroutine 609 (finished) created at: github.com/restic/restic/cmd/restic.lockRepository() /restic/restic/cmd/restic/lock.go:61 +0x488 github.com/restic/restic/cmd/restic.lockRepo() /restic/restic/cmd/restic/lock.go:25 +0x219 github.com/restic/restic/cmd/restic.runMount() /restic/restic/cmd/restic/cmd_mount.go:126 +0x1f8 github.com/restic/restic/cmd/restic.testRunMount() /restic/restic/cmd/restic/integration_fuse_test.go:61 +0x1ce github.com/restic/restic/cmd/restic.checkSnapshots.func1() /restic/restic/cmd/restic/integration_fuse_test.go:90 +0x124 ==================
2022-11-11 21:40:33 +01:00
defer wg.Wait()
defer testRunUmount(t, mountpoint)
2016-09-18 18:30:25 +02:00
if !snapshotsDirExists(t, mountpoint) {
t.Fatal(`virtual directory "snapshots" doesn't exist`)
}
ids := listSnapshots(t, gopts.Repo)
2016-09-18 18:30:25 +02:00
t.Logf("found %v snapshots in repo: %v", len(ids), ids)
2016-09-18 18:30:25 +02:00
namesInSnapshots := listSnapshots(t, mountpoint)
t.Logf("found %v snapshots in fuse mount: %v", len(namesInSnapshots), namesInSnapshots)
rtest.Assert(t,
expectedSnapshotsInFuseDir == len(namesInSnapshots),
"Invalid number of snapshots: expected %d, got %d", expectedSnapshotsInFuseDir, len(namesInSnapshots))
2015-07-19 15:21:21 +02:00
2016-09-18 18:30:25 +02:00
namesMap := make(map[string]bool)
for _, name := range namesInSnapshots {
namesMap[name] = false
}
2016-09-15 21:17:20 +02:00
// Is "latest" present?
if len(namesMap) != 0 {
_, ok := namesMap["latest"]
if !ok {
t.Errorf("Symlink latest isn't present in fuse dir")
} else {
namesMap["latest"] = true
}
}
_, repo, unlock, err := openWithReadLock(context.TODO(), gopts, false)
rtest.OK(t, err)
defer unlock()
2016-09-18 18:30:25 +02:00
for _, id := range snapshotIDs {
snapshot, err := restic.LoadSnapshot(context.TODO(), repo, id)
rtest.OK(t, err)
2016-09-18 18:30:25 +02:00
ts := snapshot.Time.Format(time.RFC3339)
present, ok := namesMap[ts]
if !ok {
t.Errorf("Snapshot %v (%q) isn't present in fuse dir", id.Str(), ts)
}
2016-09-15 21:17:20 +02:00
2016-09-18 18:30:25 +02:00
for i := 1; present; i++ {
ts = fmt.Sprintf("%s-%d", snapshot.Time.Format(time.RFC3339), i)
present, ok = namesMap[ts]
if !ok {
t.Errorf("Snapshot %v (%q) isn't present in fuse dir", id.Str(), ts)
2016-09-15 21:17:20 +02:00
}
2016-09-18 18:30:25 +02:00
if !present {
break
2016-09-15 21:17:20 +02:00
}
}
2016-09-18 18:30:25 +02:00
namesMap[ts] = true
}
for name, present := range namesMap {
rtest.Assert(t, present, "Directory %s is present in fuse dir but is not a snapshot", name)
2016-09-18 18:30:25 +02:00
}
}
func TestMount(t *testing.T) {
if !rtest.RunFuseTest {
2016-09-18 18:30:25 +02:00
t.Skip("Skipping fuse tests")
}
env, cleanup := withTestEnvironment(t)
// must list snapshots more than once
env.gopts.backendTestHook = nil
defer cleanup()
2017-06-18 14:23:35 +02:00
testRunInit(t, env.gopts)
checkSnapshots(t, env.gopts, env.mountpoint, []restic.ID{}, 0)
rtest.SetupTarTestFixture(t, env.testdata, filepath.Join("testdata", "backup-data.tar.gz"))
// first backup
2018-03-25 23:36:31 +02:00
testRunBackup(t, "", []string{env.testdata}, BackupOptions{}, env.gopts)
snapshotIDs := testRunList(t, "snapshots", env.gopts)
rtest.Assert(t, len(snapshotIDs) == 1,
"expected one snapshot, got %v", snapshotIDs)
checkSnapshots(t, env.gopts, env.mountpoint, snapshotIDs, 2)
// second backup, implicit incremental
2018-03-25 23:36:31 +02:00
testRunBackup(t, "", []string{env.testdata}, BackupOptions{}, env.gopts)
snapshotIDs = testRunList(t, "snapshots", env.gopts)
rtest.Assert(t, len(snapshotIDs) == 2,
"expected two snapshots, got %v", snapshotIDs)
checkSnapshots(t, env.gopts, env.mountpoint, snapshotIDs, 3)
// third backup, explicit incremental
bopts := BackupOptions{Parent: snapshotIDs[0].String()}
2018-03-25 23:36:31 +02:00
testRunBackup(t, "", []string{env.testdata}, bopts, env.gopts)
snapshotIDs = testRunList(t, "snapshots", env.gopts)
rtest.Assert(t, len(snapshotIDs) == 3,
"expected three snapshots, got %v", snapshotIDs)
checkSnapshots(t, env.gopts, env.mountpoint, snapshotIDs, 4)
2016-09-18 18:30:25 +02:00
}
func TestMountSameTimestamps(t *testing.T) {
if !rtest.RunFuseTest {
2016-09-18 18:30:25 +02:00
t.Skip("Skipping fuse tests")
}
env, cleanup := withTestEnvironment(t)
// must list snapshots more than once
env.gopts.backendTestHook = nil
defer cleanup()
2016-09-18 18:30:25 +02:00
rtest.SetupTarTestFixture(t, env.base, filepath.Join("testdata", "repo-same-timestamps.tar.gz"))
2016-09-18 18:30:25 +02:00
ids := []restic.ID{
restic.TestParseID("280303689e5027328889a06d718b729e96a1ce6ae9ef8290bff550459ae611ee"),
restic.TestParseID("75ad6cdc0868e082f2596d5ab8705e9f7d87316f5bf5690385eeff8dbe49d9f5"),
restic.TestParseID("5fd0d8b2ef0fa5d23e58f1e460188abb0f525c0f0c4af8365a1280c807a80a1b"),
}
2016-09-18 18:30:25 +02:00
checkSnapshots(t, env.gopts, env.mountpoint, ids, 4)
}