serve nfs: try potential fix for nfs locking #7973

See: https://github.com/willscott/go-nfs/issues/54

cmd/serve/nfs/filesystem.go

@@ -3,6 +3,7 @@
 package nfs
 
 import (
+	"math"
 	"os"
 	"path"
 	"strings"
@@ -13,8 +14,34 @@ import (
 	"github.com/rclone/rclone/fs/log"
 	"github.com/rclone/rclone/vfs"
 	"github.com/rclone/rclone/vfs/vfscommon"
+	"github.com/willscott/go-nfs/file"
 )
 
+// setSys sets the Sys() call up for the vfs.Node passed in
+//
+// The billy abstraction layer does not extend to exposing `uid` and `gid`
+// ownership of files. If ownership is important to your file system, you
+// will need to ensure that the `os.FileInfo` meets additional constraints.
+// In particular, the `Sys()` escape hatch is queried by this library, and
+// if your file system populates a [`syscall.Stat_t`](https://golang.org/pkg/syscall/#Stat_t)
+// concrete struct, the ownership specified in that object will be used.
+// It can also return a file.FileInfo which is easier to manage cross platform
+func setSys(fi os.FileInfo) {
+	node, ok := fi.(vfs.Node)
+	if !ok {
+		fs.Errorf(fi, "internal error: %T is not a vfs.Node", fi)
+	}
+	vfs := node.VFS()
+	// Set the UID and GID for the node passed in from the VFS defaults.
+	stat := file.FileInfo{
+		Nlink:  1,
+		UID:    vfs.Opt.UID,
+		GID:    vfs.Opt.GID,
+		Fileid: math.MaxUint64, // without this mounting doesn't work on Linux
+	}
+	node.SetSys(&stat)
+}
+
 // FS is our wrapper around the VFS to properly support billy.Filesystem interface
 type FS struct {
 	vfs *vfs.VFS
@@ -23,7 +50,14 @@ type FS struct {
 // ReadDir implements read dir
 func (f *FS) ReadDir(path string) (dir []os.FileInfo, err error) {
 	defer log.Trace(path, "")("items=%d, err=%v", &dir, &err)
-	return f.vfs.ReadDir(path)
+	dir, err = f.vfs.ReadDir(path)
+	if err != nil {
+		return nil, err
+	}
+	for _, fi := range dir {
+		setSys(fi)
+	}
+	return dir, nil
 }
 
 // Create implements creating new files
@@ -47,7 +81,12 @@ func (f *FS) OpenFile(filename string, flag int, perm os.FileMode) (node billy.F
 // Stat gets the file stat
 func (f *FS) Stat(filename string) (fi os.FileInfo, err error) {
 	defer log.Trace(filename, "")("fi=%v, err=%v", &fi, &err)
-	return f.vfs.Stat(filename)
+	fi, err = f.vfs.Stat(filename)
+	if err != nil {
+		return nil, err
+	}
+	setSys(fi)
+	return fi, nil
 }
 
 // Rename renames a file
@@ -95,7 +134,12 @@ func (f *FS) MkdirAll(filename string, perm os.FileMode) (err error) {
 // Lstat gets the stats for symlink
 func (f *FS) Lstat(filename string) (fi os.FileInfo, err error) {
 	defer log.Trace(filename, "")("fi=%v, err=%v", &fi, &err)
-	return f.vfs.Stat(filename)
+	fi, err = f.vfs.Stat(filename)
+	if err != nil {
+		return nil, err
+	}
+	setSys(fi)
+	return fi, nil
 }
 
 // Symlink is not supported over NFS

cmd/serve/nfs/handler.go

@@ -24,7 +24,8 @@ type Handler struct {
 }
 
 // NewHandler creates a handler for the provided filesystem
-func NewHandler(vfs *vfs.VFS, opt *Options) (handler nfs.Handler, err error) {
+func NewHandler(ctx context.Context, vfs *vfs.VFS, opt *Options) (handler nfs.Handler, err error) {
+	ci := fs.GetConfig(ctx)
 	h := &Handler{
 		vfs:     vfs,
 		opt:     *opt,
@@ -35,7 +36,20 @@ func NewHandler(vfs *vfs.VFS, opt *Options) (handler nfs.Handler, err error) {
 	if err != nil {
 		return nil, fmt.Errorf("failed to make cache: %w", err)
 	}
-	nfs.SetLogger(&logIntercepter{Level: nfs.DebugLevel})
+	var level nfs.LogLevel
+	switch {
+	case ci.LogLevel >= fs.LogLevelDebug: // Debug level, needs -vv
+		level = nfs.TraceLevel
+	case ci.LogLevel >= fs.LogLevelInfo: // Transfers, needs -v
+		level = nfs.InfoLevel
+	case ci.LogLevel >= fs.LogLevelNotice: // Normal logging, -q suppresses
+		level = nfs.WarnLevel
+	case ci.LogLevel >= fs.LogLevelError: // Error - can't be suppressed
+		level = nfs.ErrorLevel
+	default:
+		level = nfs.WarnLevel
+	}
+	nfs.SetLogger(&logger{level: level})
 	return h, nil
 }
 
@@ -108,120 +122,167 @@ func onUnmount() {
 	}
 }
 
-// logIntercepter intercepts noisy go-nfs logs and reroutes them to DEBUG
+// logger handles go-nfs logs and reroutes them to rclone's logging system
-type logIntercepter struct {
+type logger struct {
-	Level nfs.LogLevel
+	level nfs.LogLevel
 }
 
-// Intercept intercepts go-nfs logs and calls fs.Debugf instead
+// logPrint intercepts go-nfs logs and calls rclone's log system instead
-func (l *logIntercepter) Intercept(args ...interface{}) {
+func (l *logger) logPrint(level fs.LogLevel, args ...interface{}) {
-	args = append([]interface{}{"[NFS DEBUG] "}, args...)
+	fs.LogPrintf(level, "nfs", "%s", fmt.Sprint(args...))
-	argsS := fmt.Sprint(args...)
-	fs.Debugf(nil, "%v", argsS)
 }
 
-// Interceptf intercepts go-nfs logs and calls fs.Debugf instead
+// logPrintf intercepts go-nfs logs and calls rclone's log system instead
-func (l *logIntercepter) Interceptf(format string, args ...interface{}) {
+func (l *logger) logPrintf(level fs.LogLevel, format string, args ...interface{}) {
-	argsS := fmt.Sprint(args...)
+	fs.LogPrintf(level, "nfs", format, args...)
-	// bit of a workaround... the real fix is probably https://github.com/willscott/go-nfs/pull/28
-	if strings.Contains(argsS, "mount.Umnt") {
-		onUnmount()
-	}
-
-	fs.Debugf(nil, "[NFS DEBUG] "+format, args...)
 }
 
 // Debug reroutes go-nfs Debug messages to Intercept
-func (l *logIntercepter) Debug(args ...interface{}) {
+func (l *logger) Debug(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.DebugLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelDebug, args...)
 }
 
-// Debugf reroutes go-nfs Debugf messages to Interceptf
+// Debugf reroutes go-nfs Debugf messages to logPrintf
-func (l *logIntercepter) Debugf(format string, args ...interface{}) {
+func (l *logger) Debugf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.DebugLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelDebug, format, args...)
 }
 
 // Error reroutes go-nfs Error messages to Intercept
-func (l *logIntercepter) Error(args ...interface{}) {
+func (l *logger) Error(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.ErrorLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelError, args...)
 }
 
-// Errorf reroutes go-nfs Errorf messages to Interceptf
+// Errorf reroutes go-nfs Errorf messages to logPrintf
-func (l *logIntercepter) Errorf(format string, args ...interface{}) {
+func (l *logger) Errorf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.ErrorLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelError, format, args...)
 }
 
 // Fatal reroutes go-nfs Fatal messages to Intercept
-func (l *logIntercepter) Fatal(args ...interface{}) {
+func (l *logger) Fatal(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.FatalLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelError, args...)
 }
 
-// Fatalf reroutes go-nfs Fatalf messages to Interceptf
+// Fatalf reroutes go-nfs Fatalf messages to logPrintf
-func (l *logIntercepter) Fatalf(format string, args ...interface{}) {
+func (l *logger) Fatalf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.FatalLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelError, format, args...)
 }
 
 // GetLevel returns the nfs.LogLevel
-func (l *logIntercepter) GetLevel() nfs.LogLevel {
+func (l *logger) GetLevel() nfs.LogLevel {
-	return l.Level
+	return l.level
 }
 
 // Info reroutes go-nfs Info messages to Intercept
-func (l *logIntercepter) Info(args ...interface{}) {
+func (l *logger) Info(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.InfoLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelInfo, args...)
 }
 
-// Infof reroutes go-nfs Infof messages to Interceptf
+// Infof reroutes go-nfs Infof messages to logPrintf
-func (l *logIntercepter) Infof(format string, args ...interface{}) {
+func (l *logger) Infof(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.InfoLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelInfo, format, args...)
 }
 
 // Panic reroutes go-nfs Panic messages to Intercept
-func (l *logIntercepter) Panic(args ...interface{}) {
+func (l *logger) Panic(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.PanicLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelError, args...)
 }
 
-// Panicf reroutes go-nfs Panicf messages to Interceptf
+// Panicf reroutes go-nfs Panicf messages to logPrintf
-func (l *logIntercepter) Panicf(format string, args ...interface{}) {
+func (l *logger) Panicf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.PanicLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelError, format, args...)
 }
 
 // ParseLevel parses the nfs.LogLevel
-func (l *logIntercepter) ParseLevel(level string) (nfs.LogLevel, error) {
+func (l *logger) ParseLevel(level string) (nfs.LogLevel, error) {
 	return nfs.Log.ParseLevel(level)
 }
 
 // Print reroutes go-nfs Print messages to Intercept
-func (l *logIntercepter) Print(args ...interface{}) {
+func (l *logger) Print(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.InfoLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelInfo, args...)
 }
 
 // Printf reroutes go-nfs Printf messages to Intercept
-func (l *logIntercepter) Printf(format string, args ...interface{}) {
+func (l *logger) Printf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.InfoLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelInfo, format, args...)
 }
 
 // SetLevel sets the nfs.LogLevel
-func (l *logIntercepter) SetLevel(level nfs.LogLevel) {
+func (l *logger) SetLevel(level nfs.LogLevel) {
-	l.Level = level
+	l.level = level
 }
 
 // Trace reroutes go-nfs Trace messages to Intercept
-func (l *logIntercepter) Trace(args ...interface{}) {
+func (l *logger) Trace(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.DebugLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelDebug, args...)
 }
 
-// Tracef reroutes go-nfs Tracef messages to Interceptf
+// Tracef reroutes go-nfs Tracef messages to logPrintf
-func (l *logIntercepter) Tracef(format string, args ...interface{}) {
+func (l *logger) Tracef(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	// FIXME BODGE ... the real fix is probably https://github.com/willscott/go-nfs/pull/28
+	// This comes from `Log.Tracef("request: %v", w.req)` in conn.go
+	// DEBUG : nfs: request: RPC #3285799202 (mount.Umnt)
+	argsS := fmt.Sprint(args...)
+	if strings.Contains(argsS, "mount.Umnt") {
+		onUnmount()
+	}
+	if l.level < nfs.DebugLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelDebug, format, args...)
 }
 
 // Warn reroutes go-nfs Warn messages to Intercept
-func (l *logIntercepter) Warn(args ...interface{}) {
+func (l *logger) Warn(args ...interface{}) {
-	l.Intercept(args...)
+	if l.level < nfs.WarnLevel {
+		return
+	}
+	l.logPrint(fs.LogLevelNotice, args...)
 }
 
-// Warnf reroutes go-nfs Warnf messages to Interceptf
+// Warnf reroutes go-nfs Warnf messages to logPrintf
-func (l *logIntercepter) Warnf(format string, args ...interface{}) {
+func (l *logger) Warnf(format string, args ...interface{}) {
-	l.Interceptf(format, args...)
+	if l.level < nfs.WarnLevel {
+		return
+	}
+	l.logPrintf(fs.LogLevelNotice, format, args...)
 }

cmd/serve/nfs/server.go

@@ -37,7 +37,7 @@ func NewServer(ctx context.Context, vfs *vfs.VFS, opt *Options) (s *Server, err
 		ctx: ctx,
 		opt: *opt,
 	}
-	s.handler, err = NewHandler(vfs, opt)
+	s.handler, err = NewHandler(ctx, vfs, opt)
 	if err != nil {
 		return nil, fmt.Errorf("failed to make NFS handler: %w", err)
 	}

go.mod

@@ -70,7 +70,7 @@ require (
 	github.com/stretchr/testify v1.9.0
 	github.com/t3rm1n4l/go-mega v0.0.0-20240219080617-d494b6a8ace7
 	github.com/unknwon/goconfig v1.0.0
-	github.com/willscott/go-nfs v0.0.3-0.20240425122109-91bc38957cc9
+	github.com/willscott/go-nfs v0.0.3-0.20240826115235-e7154b306671
 	github.com/winfsp/cgofuse v1.5.1-0.20221118130120-84c0898ad2e0
 	github.com/xanzy/ssh-agent v0.3.3
 	github.com/youmark/pkcs8 v0.0.0-20201027041543-1326539a0a0a

go.sum

@@ -604,8 +604,8 @@ github.com/ugorji/go/codec v1.2.12 h1:9LC83zGrHhuUA9l16C9AHXAqEV/2wBQ4nkvumAE65E
 github.com/ugorji/go/codec v1.2.12/go.mod h1:UNopzCgEMSXjBc6AOMqYvWC1ktqTAfzJZUZgYf6w6lg=
 github.com/unknwon/goconfig v1.0.0 h1:rS7O+CmUdli1T+oDm7fYj1MwqNWtEJfNj+FqcUHML8U=
 github.com/unknwon/goconfig v1.0.0/go.mod h1:qu2ZQ/wcC/if2u32263HTVC39PeOQRSmidQk3DuDFQ8=
-github.com/willscott/go-nfs v0.0.3-0.20240425122109-91bc38957cc9 h1:IGSoH2aBagQ9VI8ZwbjHYIslta5vXfczegV1B4y9KqY=
+github.com/willscott/go-nfs v0.0.3-0.20240826115235-e7154b306671 h1:dkNcBcQD+0aPOAItCzvfZlGcPwxHIdZ2OF0Qhop2RTc=
-github.com/willscott/go-nfs v0.0.3-0.20240425122109-91bc38957cc9/go.mod h1:Ql2ebUpEFm/a1CAY884di2XZkdcddfHZ6ONrAlhFev0=
+github.com/willscott/go-nfs v0.0.3-0.20240826115235-e7154b306671/go.mod h1:Ql2ebUpEFm/a1CAY884di2XZkdcddfHZ6ONrAlhFev0=
 github.com/willscott/go-nfs-client v0.0.0-20240104095149-b44639837b00 h1:U0DnHRZFzoIV1oFEZczg5XyPut9yxk9jjtax/9Bxr/o=
 github.com/willscott/go-nfs-client v0.0.0-20240104095149-b44639837b00/go.mod h1:Tq++Lr/FgiS3X48q5FETemXiSLGuYMQT2sPjYNPJSwA=
 github.com/winfsp/cgofuse v1.5.1-0.20221118130120-84c0898ad2e0 h1:j3un8DqYvvAOqKI5OPz+/RRVhDFipbPKI4t2Uk5RBJw=