diff --git a/internal/fs/fs.go b/internal/fs/fs.go index 27640b2397c..73f69951d5c 100644 --- a/internal/fs/fs.go +++ b/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) } diff --git a/internal/fs/tracing_test.go b/internal/fs/tracing_test.go index 343ec2152e6..3c492feac98 100644 --- a/internal/fs/tracing_test.go +++ b/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)) } diff --git a/tracing/span_names.go b/tracing/span_names.go index af6a3de69c3..dd9f85d2f9f 100644 --- a/tracing/span_names.go +++ b/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"