feat: Add fs.inode.lock_acquisition span to capture parent lock waiting time during lookup

internal/fs/fs.go

@@ -59,6 +59,7 @@ import (
 	"github.com/jacobsa/fuse/fuseutil"
 	"github.com/jacobsa/timeutil"
 	"github.com/spf13/viper"
+	"go.opentelemetry.io/otel/trace"
 )
 
 type ServerConfig struct {
@@ -1225,6 +1226,10 @@ func (fs *fileSystem) lookUpOrCreateChildInode(
 	// Set up a function that will find a lookup result for the child with the
 	// given name. Expects no locks to be held.
 	getLookupResult := func() (*inode.Core, error) {
+		var lockSpan trace.Span
+		if fs.isTracingEnabled {
+			_, lockSpan = fs.traceHandle.StartSpan(ctx, tracing.InodeLockAcquisition)
+		}
 		if fs.newConfig.FileSystem.DisableParallelDirops {
 			parent.Lock()
 			defer parent.Unlock()
@@ -1234,6 +1239,9 @@ func (fs *fileSystem) lookUpOrCreateChildInode(
 			parent.LockForChildLookup()
 			defer parent.UnlockForChildLookup()
 		}
+		if lockSpan != nil {
+			fs.traceHandle.EndSpan(lockSpan)
+		}
 		return parent.LookUpChild(ctx, childName)
 	}
 

internal/fs/tracing_test.go

@@ -38,9 +38,28 @@ import (
 	"go.opentelemetry.io/otel/trace"
 )
 
+type filteringExporter struct {
+	raw *tracetest.InMemoryExporter
+}
+
+func (f *filteringExporter) Reset() {
+	f.raw.Reset()
+}
+
+func (f *filteringExporter) GetSpans() tracetest.SpanStubs {
+	spans := f.raw.GetSpans()
+	var filtered tracetest.SpanStubs
+	for _, s := range spans {
+		if s.Name != "fs.inode.lock_acquisition" {
+			filtered = append(filtered, s)
+		}
+	}
+	return filtered
+}
+
 type TracingTestSuite struct {
 	suite.Suite
-	globalExporter *tracetest.InMemoryExporter
+	globalExporter *filteringExporter
 }
 
 func (s *TracingTestSuite) SetupSuite() {
@@ -89,10 +108,10 @@ func createTestFileSystemWithTraces(ctx context.Context, t *testing.T, ignoreInt
 	return bucket, server
 }
 
-func newInMemoryExporter() *tracetest.InMemoryExporter {
+func newInMemoryExporter() *filteringExporter {
 	ex := tracetest.NewInMemoryExporter()
 	otel.SetTracerProvider(sdktrace.NewTracerProvider(sdktrace.WithSyncer(ex)))
-	return ex
+	return &filteringExporter{raw: ex}
 }
 
 func (s *TracingTestSuite) TestTraceLookupInode() {
@@ -1358,6 +1377,33 @@ func (s *TracingTestSuite) TestTraceSyncFS() {
 	}
 }
 
+func (s *TracingTestSuite) TestTraceLockAcquisition() {
+	s.Run("enabled", func() {
+		ctx := context.Background()
+		t := s.T()
+		bucket, server := createTestFileSystemWithTraces(ctx, t, true)
+		m := wrappers.WithTracing(server, tracing.NewOTELTracer())
+		fileName := "test.txt"
+		content := "test content"
+		createWithContents(ctx, t, bucket, fileName, content)
+		lookUpOp := &fuseops.LookUpInodeOp{
+			Parent: fuseops.RootInodeID,
+			Name:   fileName,
+		}
+
+		err := m.LookUpInode(ctx, lookUpOp)
+		require.NoError(t, err)
+
+		// Bypass the filteringExporter to inspect all spans generated
+		ss := s.globalExporter.raw.GetSpans()
+		require.Len(t, ss, 2)
+		assert.Equal(t, "fs.inode.lock_acquisition", ss[0].Name)
+		assert.Equal(t, trace.SpanKindInternal, ss[0].SpanKind)
+		assert.Equal(t, "fs.inode.lookup", ss[1].Name)
+		assert.Equal(t, trace.SpanKindServer, ss[1].SpanKind)
+	})
+}
+
 func TestTracingTestSuite(t *testing.T) {
 	suite.Run(t, new(TracingTestSuite))
 }

tracing/span_names.go

@@ -50,6 +50,8 @@ const (
 	SetInodeAttributes = "fs.inode.set_attributes"
 	// ForgetInode informs the kernel that it no longer needs to track a specific inode.
 	ForgetInode = "fs.inode.forget"
+	// InodeLockAcquisition measures the time spent waiting to acquire an inode lock (e.g. parent lock).
+	InodeLockAcquisition = "fs.inode.lock_acquisition"
 	// BatchForget allows the kernel to release multiple inode references in a single call.
 	BatchForget = "fs.batch_forget"