From 6ee9baa9c522b4ff77505b920c627b965be39e16 Mon Sep 17 00:00:00 2001 From: Alexander Neumann Date: Sun, 8 May 2016 22:20:46 +0200 Subject: [PATCH] fuse: Add debug logs --- src/restic/fuse/dir.go | 11 +++++++++++ src/restic/fuse/file.go | 6 ++++++ src/restic/fuse/snapshot.go | 10 ++++++++++ 3 files changed, 27 insertions(+) diff --git a/src/restic/fuse/dir.go b/src/restic/fuse/dir.go index 0289a982f..a89617e5f 100644 --- a/src/restic/fuse/dir.go +++ b/src/restic/fuse/dir.go @@ -11,6 +11,7 @@ import ( "golang.org/x/net/context" "restic" + "restic/debug" "restic/repository" ) @@ -27,8 +28,10 @@ type dir struct { } func newDir(repo *repository.Repository, node *restic.Node, ownerIsRoot bool) (*dir, error) { + debug.Log("newDir", "new dir for %v (%v)", node.Name, node.Subtree.Str()) tree, err := restic.LoadTree(repo, *node.Subtree) if err != nil { + debug.Log("newDir", " error loading tree %v: %v", node.Subtree.Str(), err) return nil, err } items := make(map[string]*restic.Node) @@ -65,14 +68,17 @@ func replaceSpecialNodes(repo *repository.Repository, node *restic.Node) ([]*res } func newDirFromSnapshot(repo *repository.Repository, snapshot SnapshotWithId, ownerIsRoot bool) (*dir, error) { + debug.Log("newDirFromSnapshot", "new dir for snapshot %v (%v)", snapshot.ID.Str(), snapshot.Tree.Str()) tree, err := restic.LoadTree(repo, *snapshot.Tree) if err != nil { + debug.Log("newDirFromSnapshot", " loadTree(%v) failed: %v", snapshot.ID.Str(), err) return nil, err } items := make(map[string]*restic.Node) for _, n := range tree.Nodes { nodes, err := replaceSpecialNodes(repo, n) if err != nil { + debug.Log("newDirFromSnapshot", " replaceSpecialNodes(%v) failed: %v", n, err) return nil, err } @@ -98,6 +104,7 @@ func newDirFromSnapshot(repo *repository.Repository, snapshot SnapshotWithId, ow } func (d *dir) Attr(ctx context.Context, a *fuse.Attr) error { + debug.Log("dir.Attr", "called") a.Inode = d.inode a.Mode = os.ModeDir | d.node.Mode @@ -112,6 +119,7 @@ func (d *dir) Attr(ctx context.Context, a *fuse.Attr) error { } func (d *dir) ReadDirAll(ctx context.Context) ([]fuse.Dirent, error) { + debug.Log("dir.ReadDirAll", "called") ret := make([]fuse.Dirent, 0, len(d.items)) for _, node := range d.items { @@ -136,8 +144,10 @@ func (d *dir) ReadDirAll(ctx context.Context) ([]fuse.Dirent, error) { } func (d *dir) Lookup(ctx context.Context, name string) (fs.Node, error) { + debug.Log("dir.Lookup", "Lookup(%v)", name) node, ok := d.items[name] if !ok { + debug.Log("dir.Lookup", " Lookup(%v) -> not found", name) return nil, fuse.ENOENT } switch node.Type { @@ -148,6 +158,7 @@ func (d *dir) Lookup(ctx context.Context, name string) (fs.Node, error) { case "symlink": return newLink(d.repo, node, d.ownerIsRoot) default: + debug.Log("dir.Lookup", " node %v has unknown type %v", name, node.Type) return nil, fuse.ENOENT } } diff --git a/src/restic/fuse/file.go b/src/restic/fuse/file.go index ce7204249..2f5c4b05c 100644 --- a/src/restic/fuse/file.go +++ b/src/restic/fuse/file.go @@ -8,6 +8,7 @@ import ( "restic" "restic/backend" + "restic/debug" "restic/pack" "bazil.org/fuse" @@ -47,6 +48,7 @@ var blobPool = sync.Pool{ } func newFile(repo BlobLoader, node *restic.Node, ownerIsRoot bool) (*file, error) { + debug.Log("newFile", "create new file for %v with %d blobs", node.Name, len(node.Content)) sizes := make([]uint, len(node.Content)) for i, id := range node.Content { size, err := repo.LookupBlobSize(id) @@ -67,6 +69,7 @@ func newFile(repo BlobLoader, node *restic.Node, ownerIsRoot bool) (*file, error } func (f *file) Attr(ctx context.Context, a *fuse.Attr) error { + debug.Log("file.Attr", "Attr(%v)", f.node.Name) a.Inode = f.node.Inode a.Mode = f.node.Mode a.Size = f.node.Size @@ -84,6 +87,7 @@ func (f *file) Attr(ctx context.Context, a *fuse.Attr) error { } func (f *file) getBlobAt(i int) (blob []byte, err error) { + debug.Log("file.getBlobAt", "getBlobAt(%v, %v)", f.node.Name, i) if f.blobs[i] != nil { return f.blobs[i], nil } @@ -100,6 +104,7 @@ func (f *file) getBlobAt(i int) (blob []byte, err error) { blob, err = f.repo.LoadBlob(pack.Data, f.node.Content[i], buf) if err != nil { + debug.Log("file.getBlobAt", "LoadBlob(%v, %v) failed: %v", f.node.Name, f.node.Content[i], err) return nil, err } f.blobs[i] = blob @@ -108,6 +113,7 @@ func (f *file) getBlobAt(i int) (blob []byte, err error) { } func (f *file) Read(ctx context.Context, req *fuse.ReadRequest, resp *fuse.ReadResponse) error { + debug.Log("file.Read", "Read(%v), file size %v", req.Size, f.node.Size) offset := req.Offset // Skip blobs before the offset diff --git a/src/restic/fuse/snapshot.go b/src/restic/fuse/snapshot.go index 162873d84..a384e3fb5 100644 --- a/src/restic/fuse/snapshot.go +++ b/src/restic/fuse/snapshot.go @@ -13,6 +13,7 @@ import ( "restic" "restic/backend" + "restic/debug" "restic/repository" "golang.org/x/net/context" @@ -39,6 +40,7 @@ type SnapshotsDir struct { } func NewSnapshotsDir(repo *repository.Repository, ownerIsRoot bool) *SnapshotsDir { + debug.Log("NewSnapshotsDir", "fuse mount initiated") return &SnapshotsDir{ repo: repo, knownSnapshots: make(map[string]SnapshotWithId), @@ -54,10 +56,12 @@ func (sn *SnapshotsDir) Attr(ctx context.Context, attr *fuse.Attr) error { attr.Uid = uint32(os.Getuid()) attr.Gid = uint32(os.Getgid()) } + debug.Log("SnapshotsDir.Attr", "attr is %v", attr) return nil } func (sn *SnapshotsDir) updateCache(ctx context.Context) error { + debug.Log("SnapshotsDir.updateCache", "called") sn.Lock() defer sn.Unlock() @@ -75,10 +79,12 @@ func (sn *SnapshotsDir) get(name string) (snapshot SnapshotWithId, ok bool) { sn.RLock() snapshot, ok = sn.knownSnapshots[name] sn.RUnlock() + debug.Log("SnapshotsDir.get", "get(%s) -> %v %v", name, snapshot, ok) return snapshot, ok } func (sn *SnapshotsDir) ReadDirAll(ctx context.Context) ([]fuse.Dirent, error) { + debug.Log("SnapshotsDir.ReadDirAll", "called") err := sn.updateCache(ctx) if err != nil { return nil, err @@ -96,21 +102,25 @@ func (sn *SnapshotsDir) ReadDirAll(ctx context.Context) ([]fuse.Dirent, error) { }) } + debug.Log("SnapshotsDir.ReadDirAll", " -> %d entries", len(ret)) return ret, nil } func (sn *SnapshotsDir) Lookup(ctx context.Context, name string) (fs.Node, error) { + debug.Log("SnapshotsDir.updateCache", "Lookup(%s)", name) snapshot, ok := sn.get(name) if !ok { // We don't know about it, update the cache err := sn.updateCache(ctx) if err != nil { + debug.Log("SnapshotsDir.updateCache", " Lookup(%s) -> err %v", name, err) return nil, err } snapshot, ok = sn.get(name) if !ok { // We still don't know about it, this time it really doesn't exist + debug.Log("SnapshotsDir.updateCache", " Lookup(%s) -> not found", name) return nil, fuse.ENOENT } }