[arvados] created: 2.7.0-6174-gb290de5604
git repository hosting
git at public.arvados.org
Mon Mar 11 19:29:53 UTC 2024
at b290de5604e7ccfad230cd1e0547f0c09cc2fe01 (commit)
commit b290de5604e7ccfad230cd1e0547f0c09cc2fe01
Author: Tom Clegg <tom at curii.com>
Date: Mon Mar 11 15:00:06 2024 -0400
21578: Add -log-level flag, log failed fuse calls at debug level.
Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tom at curii.com>
diff --git a/lib/mount/command.go b/lib/mount/command.go
index 7ab518faee..4cb744274b 100644
--- a/lib/mount/command.go
+++ b/lib/mount/command.go
@@ -17,9 +17,11 @@ import (
"git.arvados.org/arvados.git/lib/cmd"
"git.arvados.org/arvados.git/sdk/go/arvados"
"git.arvados.org/arvados.git/sdk/go/arvadosclient"
+ "git.arvados.org/arvados.git/sdk/go/ctxlog"
"git.arvados.org/arvados.git/sdk/go/keepclient"
"github.com/arvados/cgofuse/fuse"
"github.com/ghodss/yaml"
+ "github.com/sirupsen/logrus"
)
var Command = &mountCommand{}
@@ -28,7 +30,7 @@ type mountCommand struct {
// ready, if non-nil, will be closed when the mount is
// initialized. If ready is non-nil, it RunCommand() should
// not be called more than once, or when ready is already
- // closed.
+ // closed. Only intended for testing.
ready chan struct{}
// It is safe to call Unmount only after ready has been
// closed.
@@ -40,19 +42,28 @@ type mountCommand struct {
// The "-d" fuse option (and perhaps other features) ignores the
// stderr argument and prints to os.Stderr instead.
func (c *mountCommand) RunCommand(prog string, args []string, stdin io.Reader, stdout, stderr io.Writer) int {
- logger := log.New(stderr, prog+" ", 0)
+ logger := ctxlog.New(stderr, "text", "info")
+ defer logger.Debug("exiting")
+
flags := flag.NewFlagSet(prog, flag.ContinueOnError)
ro := flags.Bool("ro", false, "read-only")
experimental := flags.Bool("experimental", false, "acknowledge this is an experimental command, and should not be used in production (required)")
cacheSizeStr := flags.String("cache-size", "0", "cache size as percent of home filesystem size (\"5%\") or size (\"10GiB\") or 0 for automatic")
+ logLevel := flags.String("log-level", "info", "logging level (debug, info, ...)")
pprof := flags.String("pprof", "", "serve Go profile data at `[addr]:port`")
if ok, code := cmd.ParseFlags(flags, prog, args, "[FUSE mount options]", stderr); !ok {
return code
}
if !*experimental {
- logger.Printf("error: experimental command %q used without --experimental flag", prog)
+ logger.Errorf("experimental command %q used without --experimental flag", prog)
+ return 2
+ }
+ lvl, err := logrus.ParseLevel(*logLevel)
+ if err != nil {
+ logger.WithError(err).Error("invalid argument for -log-level flag")
return 2
}
+ logger.SetLevel(lvl)
if *pprof != "" {
go func() {
log.Println(http.ListenAndServe(*pprof, nil))
@@ -61,17 +72,17 @@ func (c *mountCommand) RunCommand(prog string, args []string, stdin io.Reader, s
client := arvados.NewClientFromEnv()
if err := yaml.Unmarshal([]byte(*cacheSizeStr), &client.DiskCacheSize); err != nil {
- logger.Printf("error parsing -cache-size argument: %s", err)
+ logger.Errorf("error parsing -cache-size argument: %s", err)
return 2
}
ac, err := arvadosclient.New(client)
if err != nil {
- logger.Print(err)
+ logger.Error(err)
return 1
}
kc, err := keepclient.MakeKeepClient(ac)
if err != nil {
- logger.Print(err)
+ logger.Error(err)
return 1
}
host := fuse.NewFileSystemHost(&keepFS{
@@ -80,9 +91,12 @@ func (c *mountCommand) RunCommand(prog string, args []string, stdin io.Reader, s
ReadOnly: *ro,
Uid: os.Getuid(),
Gid: os.Getgid(),
+ Logger: logger,
ready: c.ready,
})
c.Unmount = host.Unmount
+
+ logger.WithField("mountargs", flags.Args()).Debug("mounting")
ok := host.Mount("", flags.Args())
if !ok {
return 1
diff --git a/lib/mount/fs.go b/lib/mount/fs.go
index 3c2e628d01..dece44d25d 100644
--- a/lib/mount/fs.go
+++ b/lib/mount/fs.go
@@ -15,6 +15,7 @@ import (
"git.arvados.org/arvados.git/sdk/go/arvados"
"git.arvados.org/arvados.git/sdk/go/keepclient"
"github.com/arvados/cgofuse/fuse"
+ "github.com/sirupsen/logrus"
)
// sharedFile wraps arvados.File with a sync.Mutex, so fuse can safely
@@ -33,6 +34,7 @@ type keepFS struct {
ReadOnly bool
Uid int
Gid int
+ Logger logrus.FieldLogger
root arvados.CustomFileSystem
open map[uint64]*sharedFile
@@ -79,6 +81,7 @@ func (fs *keepFS) Init() {
func (fs *keepFS) Create(path string, flags int, mode uint32) (errc int, fh uint64) {
defer fs.debugPanics()
+ fs.debugOp("Create", path)
if fs.ReadOnly {
return -fuse.EROFS, invalidFH
}
@@ -93,6 +96,7 @@ func (fs *keepFS) Create(path string, flags int, mode uint32) (errc int, fh uint
func (fs *keepFS) Open(path string, flags int) (errc int, fh uint64) {
defer fs.debugPanics()
+ fs.debugOp("Open", path)
if fs.ReadOnly && flags&(os.O_RDWR|os.O_WRONLY|os.O_CREATE) != 0 {
return -fuse.EROFS, invalidFH
}
@@ -110,21 +114,30 @@ func (fs *keepFS) Open(path string, flags int) (errc int, fh uint64) {
func (fs *keepFS) Utimens(path string, tmsp []fuse.Timespec) int {
defer fs.debugPanics()
+ fs.debugOp("Utimens", path)
if fs.ReadOnly {
return -fuse.EROFS
}
f, err := fs.root.OpenFile(path, 0, 0)
if err != nil {
- return fs.errCode(err)
+ return fs.errCode("Utimens", path, err)
}
f.Close()
return 0
}
-func (fs *keepFS) errCode(err error) int {
+func (fs *keepFS) errCode(op, path string, err error) (errc int) {
if err == nil {
return 0
}
+ defer func() {
+ fs.Logger.WithFields(logrus.Fields{
+ "op": op,
+ "path": path,
+ "errno": errc,
+ "error": err,
+ }).Debug("fuse call returned error")
+ }()
if errors.Is(err, os.ErrNotExist) {
return -fuse.ENOENT
}
@@ -145,12 +158,13 @@ func (fs *keepFS) errCode(err error) int {
func (fs *keepFS) Mkdir(path string, mode uint32) int {
defer fs.debugPanics()
+ fs.debugOp("Mkdir", path)
if fs.ReadOnly {
return -fuse.EROFS
}
f, err := fs.root.OpenFile(path, os.O_CREATE|os.O_EXCL, os.FileMode(mode)|os.ModeDir)
if err != nil {
- return fs.errCode(err)
+ return fs.errCode("Mkdir", path, err)
}
f.Close()
return 0
@@ -158,11 +172,12 @@ func (fs *keepFS) Mkdir(path string, mode uint32) int {
func (fs *keepFS) Opendir(path string) (errc int, fh uint64) {
defer fs.debugPanics()
+ fs.debugOp("Opendir", path)
f, err := fs.root.OpenFile(path, 0, 0)
if err != nil {
- return fs.errCode(err), invalidFH
+ return fs.errCode("Opendir", path, err), invalidFH
} else if fi, err := f.Stat(); err != nil {
- return fs.errCode(err), invalidFH
+ return fs.errCode("Opendir", path, err), invalidFH
} else if !fi.IsDir() {
f.Close()
return -fuse.ENOTDIR, invalidFH
@@ -172,16 +187,19 @@ func (fs *keepFS) Opendir(path string) (errc int, fh uint64) {
func (fs *keepFS) Releasedir(path string, fh uint64) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Releasedir", path)
return fs.Release(path, fh)
}
func (fs *keepFS) Rmdir(path string) int {
defer fs.debugPanics()
- return fs.errCode(fs.root.Remove(path))
+ fs.debugOp("Rmdir", path)
+ return fs.errCode("Rmdir", path, fs.root.Remove(path))
}
func (fs *keepFS) Release(path string, fh uint64) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Release", path)
fs.Lock()
defer fs.Unlock()
defer delete(fs.open, fh)
@@ -196,22 +214,25 @@ func (fs *keepFS) Release(path string, fh uint64) (errc int) {
func (fs *keepFS) Rename(oldname, newname string) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Rename", oldname+" -> "+newname)
if fs.ReadOnly {
return -fuse.EROFS
}
- return fs.errCode(fs.root.Rename(oldname, newname))
+ return fs.errCode("Rename", oldname+" -> "+newname, fs.root.Rename(oldname, newname))
}
func (fs *keepFS) Unlink(path string) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Unlink", path)
if fs.ReadOnly {
return -fuse.EROFS
}
- return fs.errCode(fs.root.Remove(path))
+ return fs.errCode("Unlink", path, fs.root.Remove(path))
}
func (fs *keepFS) Truncate(path string, size int64, fh uint64) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Truncate", path)
if fs.ReadOnly {
return -fuse.EROFS
}
@@ -219,20 +240,21 @@ func (fs *keepFS) Truncate(path string, size int64, fh uint64) (errc int) {
// Sometimes fh is a valid filehandle and we don't need to
// waste a name lookup.
if f := fs.lookupFH(fh); f != nil {
- return fs.errCode(f.Truncate(size))
+ return fs.errCode("Truncate", path, f.Truncate(size))
}
// Other times, fh is invalid and we need to lookup path.
f, err := fs.root.OpenFile(path, os.O_RDWR, 0)
if err != nil {
- return fs.errCode(err)
+ return fs.errCode("Truncate", path, err)
}
defer f.Close()
- return fs.errCode(f.Truncate(size))
+ return fs.errCode("Truncate", path, f.Truncate(size))
}
func (fs *keepFS) Getattr(path string, stat *fuse.Stat_t, fh uint64) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Getattr", path)
var fi os.FileInfo
var err error
if f := fs.lookupFH(fh); f != nil {
@@ -243,18 +265,20 @@ func (fs *keepFS) Getattr(path string, stat *fuse.Stat_t, fh uint64) (errc int)
fi, err = fs.root.Stat(path)
}
if err != nil {
- return fs.errCode(err)
+ return fs.errCode("Getattr", path, err)
}
fs.fillStat(stat, fi)
return 0
}
func (fs *keepFS) Chmod(path string, mode uint32) (errc int) {
+ defer fs.debugPanics()
+ fs.debugOp("Chmod", path)
if fs.ReadOnly {
return -fuse.EROFS
}
if fi, err := fs.root.Stat(path); err != nil {
- return fs.errCode(err)
+ return fs.errCode("Chmod", path, err)
} else if mode & ^uint32(fuse.S_IFREG|fuse.S_IFDIR|0777) != 0 {
// Refuse to set mode bits other than
// regfile/dir/perms
@@ -298,6 +322,7 @@ func (fs *keepFS) fillStat(stat *fuse.Stat_t, fi os.FileInfo) {
func (fs *keepFS) Write(path string, buf []byte, ofst int64, fh uint64) (n int) {
defer fs.debugPanics()
+ fs.debugOp("Write", path)
if fs.ReadOnly {
return -fuse.EROFS
}
@@ -308,18 +333,18 @@ func (fs *keepFS) Write(path string, buf []byte, ofst int64, fh uint64) (n int)
f.Lock()
defer f.Unlock()
if _, err := f.Seek(ofst, io.SeekStart); err != nil {
- return fs.errCode(err)
+ return fs.errCode("Write", path, err)
}
n, err := f.Write(buf)
if err != nil {
- log.Printf("error writing %q: %s", path, err)
- return fs.errCode(err)
+ return fs.errCode("Write", path, err)
}
return n
}
func (fs *keepFS) Read(path string, buf []byte, ofst int64, fh uint64) (n int) {
defer fs.debugPanics()
+ fs.debugOp("Read", path)
f := fs.lookupFH(fh)
if f == nil {
return -fuse.EBADF
@@ -327,7 +352,7 @@ func (fs *keepFS) Read(path string, buf []byte, ofst int64, fh uint64) (n int) {
f.Lock()
defer f.Unlock()
if _, err := f.Seek(ofst, io.SeekStart); err != nil {
- return fs.errCode(err)
+ return fs.errCode("Read", path, err)
}
n, err := f.Read(buf)
for err == nil && n < len(buf) {
@@ -341,8 +366,7 @@ func (fs *keepFS) Read(path string, buf []byte, ofst int64, fh uint64) (n int) {
n += done
}
if err != nil && err != io.EOF {
- log.Printf("error reading %q: %s", path, err)
- return fs.errCode(err)
+ return fs.errCode("Read", path, err)
}
return n
}
@@ -352,6 +376,7 @@ func (fs *keepFS) Readdir(path string,
ofst int64,
fh uint64) (errc int) {
defer fs.debugPanics()
+ fs.debugOp("Readdir", path)
f := fs.lookupFH(fh)
if f == nil {
return -fuse.EBADF
@@ -361,7 +386,7 @@ func (fs *keepFS) Readdir(path string,
var stat fuse.Stat_t
fis, err := f.Readdir(-1)
if err != nil {
- return fs.errCode(err)
+ return fs.errCode("Readdir", path, err)
}
for _, fi := range fis {
fs.fillStat(&stat, fi)
@@ -372,14 +397,16 @@ func (fs *keepFS) Readdir(path string,
func (fs *keepFS) Fsync(path string, datasync bool, fh uint64) int {
defer fs.debugPanics()
+ fs.debugOp("Fsync", path)
f := fs.lookupFH(fh)
if f == nil {
return -fuse.EBADF
}
- return fs.errCode(f.Sync())
+ return fs.errCode("Fsync", path, f.Sync())
}
func (fs *keepFS) Fsyncdir(path string, datasync bool, fh uint64) int {
+ fs.debugOp("Fsyncdir", path)
return fs.Fsync(path, datasync, fh)
}
@@ -393,3 +420,7 @@ func (fs *keepFS) debugPanics() {
panic(err)
}
}
+
+func (fs *keepFS) debugOp(op, path string) {
+ fs.Logger.WithFields(nil).Tracef("fuse call %s %s", op, path)
+}
diff --git a/lib/mount/fs_test.go b/lib/mount/fs_test.go
index fef2c0f069..442af7a998 100644
--- a/lib/mount/fs_test.go
+++ b/lib/mount/fs_test.go
@@ -9,6 +9,7 @@ import (
"git.arvados.org/arvados.git/sdk/go/arvados"
"git.arvados.org/arvados.git/sdk/go/arvadosclient"
+ "git.arvados.org/arvados.git/sdk/go/ctxlog"
"git.arvados.org/arvados.git/sdk/go/keepclient"
"github.com/arvados/cgofuse/fuse"
check "gopkg.in/check.v1"
@@ -37,6 +38,7 @@ func (*FSSuite) TestOpendir(c *check.C) {
var fs fuse.FileSystemInterface = &keepFS{
Client: client,
KeepClient: kc,
+ Logger: ctxlog.TestLogger(c),
}
fs.Init()
errc, fh := fs.Opendir("/by_id")
-----------------------------------------------------------------------
hooks/post-receive
--
More information about the arvados-commits
mailing list