diff --git a/connection.go b/connection.go index 53dbb551..ebb86b73 100644 --- a/connection.go +++ b/connection.go @@ -62,6 +62,7 @@ type Connection struct { cfg MountConfig debugLogger *log.Logger errorLogger *log.Logger + wireLogger io.Writer // The device through which we're talking to the kernel, and the protocol // version that we're using to talk to it. @@ -87,6 +88,18 @@ type opState struct { inMsg *buffer.InMessage outMsg *buffer.OutMessage op interface{} + wlog *WireLogRecord +} + +// Return the current wirelog record from the context if the MountConfig +// contained a non-nil wireLogger, nil otherwise. +func GetWirelog(ctx context.Context) *WireLogRecord { + val := ctx.Value(contextKey) + state, ok := val.(opState) + if ok { + return state.wlog + } + return nil } // Create a connection wrapping the supplied file descriptor connected to the @@ -97,11 +110,13 @@ func newConnection( cfg MountConfig, debugLogger *log.Logger, errorLogger *log.Logger, + wireLogger io.Writer, dev *os.File) (*Connection, error) { c := &Connection{ cfg: cfg, debugLogger: debugLogger, errorLogger: errorLogger, + wireLogger: wireLogger, dev: dev, cancelFuncs: make(map[uint64]func()), } @@ -461,7 +476,11 @@ func (c *Connection) ReadOp() (_ context.Context, op interface{}, _ error) { // Set up a context that remembers information about this op. ctx := c.beginOp(inMsg.Header().Opcode, inMsg.Header().Unique) - ctx = context.WithValue(ctx, contextKey, opState{inMsg, outMsg, op}) + var wlog *WireLogRecord + if c.wireLogger != nil { + wlog = NewWireLogRecord() + } + ctx = context.WithValue(ctx, contextKey, opState{inMsg, outMsg, op, wlog}) // Return the op to the user. return ctx, op, nil @@ -573,6 +592,13 @@ func (c *Connection) Reply(ctx context.Context, opErr error) error { outMsg.Sglist = nil } + if c.wireLogger != nil { + entry, err := formatWireLogEntry(op, opErr, state.wlog) + if err == nil { + c.wireLogger.Write(entry) + } + } + return nil } diff --git a/mount.go b/mount.go index 20cd47af..23db0a8e 100644 --- a/mount.go +++ b/mount.go @@ -80,6 +80,7 @@ func Mount( cfgCopy, config.DebugLogger, config.ErrorLogger, + config.WireLogger, dev) if err != nil { return nil, fmt.Errorf("newConnection: %v", err) diff --git a/mount_config.go b/mount_config.go index e0e64470..f95895ad 100644 --- a/mount_config.go +++ b/mount_config.go @@ -17,6 +17,7 @@ package fuse import ( "context" "fmt" + "io" "log" "runtime" "strings" @@ -47,6 +48,10 @@ type MountConfig struct { // performed. DebugLogger *log.Logger + // A logger to use for logging fuse wire requests. If nil, no wire logging is + // performed. + WireLogger io.Writer + // Linux only. OS X always behaves as if writeback caching is disabled. // // By default on Linux we allow the kernel to perform writeback caching diff --git a/samples/wirelog/testfs.go b/samples/wirelog/testfs.go new file mode 100644 index 00000000..607043a5 --- /dev/null +++ b/samples/wirelog/testfs.go @@ -0,0 +1,154 @@ +// Copyright 2025 Google Inc. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package wirelog + +import ( + "context" + "io" + "os" + "strings" + + "github.com/jacobsa/fuse" + "github.com/jacobsa/fuse/fuseops" + "github.com/jacobsa/fuse/fuseutil" +) + +// NewTestFS returns a simple file system with a root directory and one file "foo". +func NewTestFS() fuse.Server { + return fuseutil.NewFileSystemServer(&testFS{}) +} + +type testFS struct { + fuseutil.NotImplementedFileSystem +} + +const ( + rootInode fuseops.InodeID = fuseops.RootInodeID + iota + fileInode +) + +var fileName string = "foo" +var fileContents string = "bar" +var fileMode os.FileMode = 0444 +var fileHandle fuseops.HandleID = 10 + +func (fs *testFS) LookUpInode( + ctx context.Context, + op *fuseops.LookUpInodeOp) error { + if wlog := fuse.GetWirelog(ctx); wlog != nil { + wlog.Extra["lookup"] = "yes" + } + if op.Parent == rootInode && op.Name == fileName { + op.Entry.Child = fileInode + op.Entry.Attributes = fuseops.InodeAttributes{ + Nlink: 1, + Mode: fileMode, + Size: uint64(len(fileContents)), + } + return nil + } + return fuse.ENOENT +} + +func (fs *testFS) GetInodeAttributes( + ctx context.Context, + op *fuseops.GetInodeAttributesOp) error { + switch op.Inode { + case rootInode: + op.Attributes = fuseops.InodeAttributes{ + Nlink: 1, + Mode: 0555 | os.ModeDir, + } + case fileInode: + op.Attributes = fuseops.InodeAttributes{ + Nlink: 1, + Mode: fileMode, + Size: uint64(len(fileContents)), + } + default: + return fuse.ENOENT + } + return nil +} + +func (fs *testFS) OpenDir( + ctx context.Context, + op *fuseops.OpenDirOp) error { + if op.Inode == rootInode { + return nil + } + return fuse.ENOENT +} + +func (fs *testFS) ReadDir( + ctx context.Context, + op *fuseops.ReadDirOp) error { + if op.Inode != rootInode { + return fuse.ENOENT + } + + entries := []fuseutil.Dirent{ + { + Offset: 1, + Inode: fileInode, + Name: fileName, + Type: fuseutil.DT_File, + }, + } + + if op.Offset > fuseops.DirOffset(len(entries)) { + return nil + } + + for _, e := range entries[op.Offset:] { + n := fuseutil.WriteDirent(op.Dst[op.BytesRead:], e) + if n == 0 { + break + } + op.BytesRead += n + } + return nil +} + +func (fs *testFS) OpenFile( + ctx context.Context, + op *fuseops.OpenFileOp) error { + if op.Inode == fileInode { + op.Handle = fileHandle + return nil + } + return fuse.ENOENT +} + +func (fs *testFS) FlushFile( + ctx context.Context, + op *fuseops.FlushFileOp) error { + return nil +} + +func (fs *testFS) ReadFile( + ctx context.Context, + op *fuseops.ReadFileOp) error { + if op.Inode != fileInode { + return fuse.ENOENT + } + reader := strings.NewReader(fileContents) + var err error + op.BytesRead, err = reader.ReadAt(op.Dst, op.Offset) + if err == io.EOF { + return nil + } + return err +} diff --git a/samples/wirelog/wirelog_test.go b/samples/wirelog/wirelog_test.go new file mode 100644 index 00000000..f5a8ffa5 --- /dev/null +++ b/samples/wirelog/wirelog_test.go @@ -0,0 +1,201 @@ +// Copyright 2025 Google Inc. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package wirelog + +import ( + "bytes" + "context" + "encoding/json" + "os" + "path" + "syscall" + "testing" + "time" + + "github.com/jacobsa/fuse" + "github.com/jacobsa/fuse/fuseops" + . "github.com/jacobsa/ogletest" +) + +func TestWireLog(t *testing.T) { RunTests(t) } + +type WireLogTest struct { + ctx context.Context + dir string + mfs *fuse.MountedFileSystem + buf bytes.Buffer +} + +func init() { RegisterTestSuite(&WireLogTest{}) } + +func (t *WireLogTest) SetUp(ti *TestInfo) { + t.ctx = ti.Ctx + var err error + t.dir, err = os.MkdirTemp("", "wirelog_test") + AssertEq(nil, err) + + // Mount the file system. + t.mfs, err = fuse.Mount(t.dir, NewTestFS(), &fuse.MountConfig{ + WireLogger: &t.buf, + OpContext: t.ctx, + }) + AssertEq(nil, err) +} + +func (t *WireLogTest) TearDown() { + // Ensure unmounted. + if t.mfs != nil { + fuse.Unmount(t.dir) + t.mfs.Join(t.ctx) + } + os.RemoveAll(t.dir) +} + +// Helper to load Args into a struct +func loadArgs(entry fuse.WireLogRecord, dst any) { + b, err := json.Marshal(entry.Args) + AssertEq(nil, err) + err = json.Unmarshal(b, dst) + AssertEq(nil, err) +} + +func (t *WireLogTest) RunWorkloadAndCheckLogs() { + // 1. Stat the file. + filePath := path.Join(t.dir, "foo") + fi, err := os.Stat(filePath) + AssertEq(nil, err) + ExpectEq(3, fi.Size()) + + // 2. Read the file. + content, err := os.ReadFile(filePath) + AssertEq(nil, err) + ExpectEq("bar", string(content)) + + // Unmount to ensure everything is flushed/closed. + err = fuse.Unmount(t.dir) + AssertEq(nil, err) + + // Wait for the connection to close. + err = t.mfs.Join(t.ctx) + AssertEq(nil, err) + + // Mark as joined so TearDown doesn't try again. + t.mfs = nil + + // Parse the logs. + ops := make(map[string][]fuse.WireLogRecord) + decoder := json.NewDecoder(&t.buf) + + for decoder.More() { + var entry fuse.WireLogRecord + err := decoder.Decode(&entry) + AssertEq(nil, err) + ExpectTrue(time.Now().After(entry.StartTime)) + ExpectGt(entry.Duration, 0) + ops[entry.Operation] = append(ops[entry.Operation], entry) + } + + // 1. initOp + entries, ok := ops["initOp"] + AssertTrue(ok) + AssertEq(1, len(entries)) + entry := entries[0] + AssertEq(0, entry.Status) + AssertEq(nil, entry.Context) + + // 2. LookUpInodeOp + entries, ok = ops["LookUpInodeOp"] + AssertTrue(ok) + ExpectGe(len(entries), 1) + entry = entries[0] + ExpectEq(entry.Status, 0) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) + var lookupOp fuseops.LookUpInodeOp + loadArgs(entry, &lookupOp) + ExpectEq(fileName, lookupOp.Name) + ExpectEq(rootInode, lookupOp.Parent) + ExpectEq(fileInode, lookupOp.Entry.Child) + ExpectEq(1, lookupOp.Entry.Attributes.Nlink) + ExpectEq(len(fileContents), lookupOp.Entry.Attributes.Size) + ExpectEq(fileMode, lookupOp.Entry.Attributes.Mode) + ExpectEq("yes", entry.Extra["lookup"]) + + // 3. GetInodeAttributesOp + entries, ok = ops["GetInodeAttributesOp"] + AssertTrue(ok) + ExpectGe(len(entries), 2) + entry = entries[1] // first entry is the root dir + ExpectEq(0, entry.Status) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) + var getattrOp fuseops.GetInodeAttributesOp + loadArgs(entry, &getattrOp) + ExpectEq(fileInode, getattrOp.Inode) + ExpectEq(1, getattrOp.Attributes.Nlink) + ExpectEq(len(fileContents), getattrOp.Attributes.Size) + ExpectEq(fileMode, getattrOp.Attributes.Mode) + + // 4. OpenFileOp + entries, ok = ops["OpenFileOp"] + AssertTrue(ok) + AssertEq(1, len(entries)) + entry = entries[0] + ExpectEq(0, entry.Status) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) + var openOp fuseops.OpenFileOp + loadArgs(entry, &openOp) + ExpectEq(fileInode, openOp.Inode) + ExpectEq(fileHandle, openOp.Handle) + + // 5. ReadFileOp + entries, ok = ops["ReadFileOp"] + AssertTrue(ok) + AssertEq(1, len(entries)) + entry = entries[0] + ExpectEq(0, entry.Status) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) + var readOp fuseops.ReadFileOp + loadArgs(entries[0], &readOp) + ExpectEq(fileInode, readOp.Inode) + ExpectEq(fileHandle, readOp.Handle) + ExpectEq(0, readOp.Offset) + ExpectGt(readOp.Size, 0) + ExpectEq(len(fileContents), readOp.BytesRead) + + // 6. FlushFileOp + entries, ok = ops["FlushFileOp"] + AssertTrue(ok) + AssertEq(1, len(entries)) + entry = entries[0] + ExpectEq(0, entry.Status) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) + var flushOp fuseops.FlushFileOp + loadArgs(entry, &flushOp) + ExpectEq(fileInode, flushOp.Inode) + AssertEq(fileHandle, flushOp.Handle) + + // 7. ReleaseFileHandleOp + entries, ok = ops["ReleaseFileHandleOp"] + AssertTrue(ok) + AssertEq(1, len(entries)) + entry = entries[0] + ExpectEq(entry.Status, syscall.ENOSYS) + AssertNe(nil, entry.Context) + AssertGt(entry.Context.FuseID, 0) +} diff --git a/wirelog.go b/wirelog.go new file mode 100644 index 00000000..2ce7ab12 --- /dev/null +++ b/wirelog.go @@ -0,0 +1,108 @@ +// Copyright 2025 Google Inc. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package fuse + +import ( + "encoding/json" + "errors" + "reflect" + "slices" + "syscall" + "time" + + "github.com/jacobsa/fuse/fuseops" +) + +// NewWireLogRecord creates a new empty WireLogRecord. +func NewWireLogRecord() *WireLogRecord { + return &WireLogRecord{ + StartTime: time.Now(), + Args: make(map[string]any), + Extra: make(map[string]any), + } +} + +// A WireLogRecord is created for each FUSE operation when WireLogger is +// non-nil. Fields are filled in by jacobsa/fuse; file system implementations +// can add their own fields by writing to the Extra map. +type WireLogRecord struct { + Operation string + StartTime time.Time + Duration time.Duration + Status int + Context *fuseops.OpContext + Args map[string]any // Serialized representation of the fuseops.*Op struct + Extra map[string]any // Custom fields added by file system implementation +} + +var ignoredParams = []string{"OpContext", "Dst", "Data"} + +func formatWireLogEntry(op any, opErr error, wlog *WireLogRecord) ([]byte, error) { + v := reflect.ValueOf(op).Elem() + t := v.Type() + + // Operation name and duration + wlog.Operation = t.Name() + wlog.Duration = time.Since(wlog.StartTime) + + // Result of the operation + var errno syscall.Errno + if opErr == nil { + wlog.Status = 0 + } else if errors.As(opErr, &errno) { + wlog.Status = int(errno) + } + + // Separate section for the operation context + if f := v.FieldByName("OpContext"); f.IsValid() { + if ctx, ok := f.Interface().(fuseops.OpContext); ok { + wlog.Context = &ctx + } + } + + // Copy the the rest of the fields to the "Args" section + args := map[string]any{} + for i := 0; i < v.NumField(); i++ { + f := v.Field(i) + if f.Kind() == reflect.Ptr && f.IsNil() { + continue + } + if f.Kind() == reflect.Func { + continue + } + fieldName := t.Field(i).Name + if slices.Contains(ignoredParams, fieldName) { + continue + } + args[fieldName] = f.Interface() + } + + switch typed := op.(type) { + case *fuseops.ReadFileOp: + args["BytesRead"] = typed.BytesRead + + case *fuseops.WriteFileOp: + args["Size"] = len(typed.Data) + } + + wlog.Args = args + + // Serialize as pretty-printed JSON + buf, err := json.MarshalIndent(wlog, "", " ") + if err == nil { + buf = append(buf, '\n') + } + return buf, err +}