fix/frontend/graphql: log and add trace events for all non-not-found errors that occur when fetching permission syncs

Author: ggilmore

cmd/frontend/internal/authz/resolvers/BUILD.bazel

@@ -31,6 +31,7 @@ go_library(
         "//internal/gqlutil",
         "//internal/licensing",
         "//internal/observation",
+        "//internal/trace",
         "//internal/types",
         "//lib/errors",
         "//lib/pointers",

cmd/frontend/internal/authz/resolvers/permissions_sync_jobs.go

@@ -5,35 +5,41 @@ import (
 
 	"github.com/graph-gophers/graphql-go"
 	"github.com/graph-gophers/graphql-go/relay"
+	"github.com/sourcegraph/log"
 
 	"github.com/sourcegraph/sourcegraph/cmd/frontend/graphqlbackend"
 	"github.com/sourcegraph/sourcegraph/cmd/frontend/graphqlbackend/graphqlutil"
 	"github.com/sourcegraph/sourcegraph/internal/api"
 	"github.com/sourcegraph/sourcegraph/internal/database"
+	"github.com/sourcegraph/sourcegraph/internal/errcode"
 	"github.com/sourcegraph/sourcegraph/internal/gitserver"
 	"github.com/sourcegraph/sourcegraph/internal/gqlutil"
+	"github.com/sourcegraph/sourcegraph/internal/trace"
 	"github.com/sourcegraph/sourcegraph/lib/errors"
 	"github.com/sourcegraph/sourcegraph/lib/pointers"
 )
 
 const permissionsSyncJobIDKind = "PermissionsSyncJob"
 
-func NewPermissionsSyncJobsResolver(db database.DB, args graphqlbackend.ListPermissionsSyncJobsArgs) (*graphqlutil.ConnectionResolver[graphqlbackend.PermissionsSyncJobResolver], error) {
+func NewPermissionsSyncJobsResolver(logger log.Logger, db database.DB, args graphqlbackend.ListPermissionsSyncJobsArgs) (*graphqlutil.ConnectionResolver[graphqlbackend.PermissionsSyncJobResolver], error) {
 	store := &permissionsSyncJobConnectionStore{
-		db:   db,
-		args: args,
+		logger: logger.Scoped("permissions_sync_jobs_resolver"),
+		db:     db,
+		args:   args,
 	}
 
 	if args.UserID != nil && args.RepoID != nil {
 		return nil, errors.New("please provide either userID or repoID, but not both.")
 	}
 
-	return graphqlutil.NewConnectionResolver[graphqlbackend.PermissionsSyncJobResolver](store, &args.ConnectionResolverArgs, nil)
+	return graphqlutil.NewConnectionResolver[graphqlbackend.PermissionsSyncJobResolver](
+		store, &args.ConnectionResolverArgs, nil)
 }
 
 type permissionsSyncJobConnectionStore struct {
-	db   database.DB
-	args graphqlbackend.ListPermissionsSyncJobsArgs
+	db     database.DB
+	args   graphqlbackend.ListPermissionsSyncJobsArgs
+	logger log.Logger
 }
 
 func (s *permissionsSyncJobConnectionStore) ComputeTotal(ctx context.Context) (int32, error) {
@@ -52,20 +58,35 @@ func (s *permissionsSyncJobConnectionStore) ComputeNodes(ctx context.Context, ar
 	}
 
 	resolvers := make([]graphqlbackend.PermissionsSyncJobResolver, 0, len(jobs))
+	var errs []error
 	for _, job := range jobs {
 		syncSubject, err := s.resolveSubject(ctx, job)
 		if err != nil {
-			// NOTE(naman): async cleaning of repos might make repo record unavailable.
-			// That will break the api, as subject will not be resolved. In this case
-			// it is better to not bubble up the error but return the remaining nodes.
+			if !errcode.IsNotFound(err) {
+				// We don't surface errors for deleted repositories or users. It's frequently the case that asynchronous
+				// cleanup jobs will delete repositories and users that are referenced by permissions sync jobs.
+				errs = append(errs, errors.Wrapf(err, "resolving permissions sync job subject for job %d", job.ID))
+			}
+
 			continue
 		}
+
 		resolvers = append(resolvers, &permissionsSyncJobResolver{
 			db:          s.db,
 			job:         job,
 			syncSubject: syncSubject,
 		})
 	}
+
+	if len(errs) > 0 {
+		s.logger.Warn("Failed to resolve permissions sync job subjects", log.Error(errors.Append(nil, errs...)))
+
+		tr := trace.FromContext(ctx)
+		for _, e := range errs {
+			tr.RecordError(e)
+		}
+	}
+
 	return resolvers, nil
 }
 

cmd/frontend/internal/authz/resolvers/permissions_sync_jobs_test.go

@@ -2,14 +2,18 @@ package resolvers
 
 import (
 	"context"
+	"strings"
 	"testing"
 
+	"github.com/sourcegraph/log/logtest"
+	"github.com/stretchr/testify/require"
+
 	"github.com/sourcegraph/sourcegraph/cmd/frontend/graphqlbackend"
 	"github.com/sourcegraph/sourcegraph/cmd/frontend/graphqlbackend/graphqlutil"
 	"github.com/sourcegraph/sourcegraph/internal/database"
 	"github.com/sourcegraph/sourcegraph/internal/database/dbmocks"
 	"github.com/sourcegraph/sourcegraph/internal/types"
-	"github.com/stretchr/testify/require"
+	"github.com/sourcegraph/sourcegraph/lib/errors"
 )
 
 func TestPermissionSyncJobsResolver(t *testing.T) {
@@ -24,8 +28,9 @@ func TestPermissionSyncJobsResolver(t *testing.T) {
 		jobsStore.ListFunc.SetDefaultReturn([]*database.PermissionSyncJob{}, nil)
 
 		db.PermissionSyncJobsFunc.SetDefaultReturn(jobsStore)
+		logger := logtest.NoOp(t)
 
-		resolver, err := NewPermissionsSyncJobsResolver(db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+		resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
 		require.NoError(t, err)
 		jobs, err := resolver.Nodes(ctx)
 		require.NoError(t, err)
@@ -42,12 +47,207 @@ func TestPermissionSyncJobsResolver(t *testing.T) {
 
 		db.PermissionSyncJobsFunc.SetDefaultReturn(jobsStore)
 		db.ReposFunc.SetDefaultReturn(repoStore)
+		logger := logtest.NoOp(t)
 
-		resolver, err := NewPermissionsSyncJobsResolver(db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+		resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
 		require.NoError(t, err)
 		jobs, err := resolver.Nodes(ctx)
 		require.NoError(t, err)
 		require.Len(t, jobs, 1)
 		require.Equal(t, marshalPermissionsSyncJobID(1), jobs[0].ID())
 	})
+
+	t.Run("logs non-not-found errors", func(t *testing.T) {
+		t.Run("repository error", func(t *testing.T) {
+			// Create a mock database
+			db := dbmocks.NewMockDB()
+
+			// Create a mock permissions sync job store
+			jobStore := dbmocks.NewMockPermissionSyncJobStore()
+
+			// Set up the expectations for the job store
+			job := &database.PermissionSyncJob{ID: 1, RepositoryID: 1}
+			jobStore.ListFunc.SetDefaultReturn([]*database.PermissionSyncJob{job}, nil)
+
+			db.PermissionSyncJobsFunc.SetDefaultReturn(jobStore)
+
+			unexpectedError := errors.New("this is a test error")
+
+			reposStore := dbmocks.NewMockRepoStore()
+			reposStore.GetFunc.SetDefaultReturn(nil, unexpectedError)
+			db.ReposFunc.SetDefaultReturn(reposStore)
+
+			logger, dumpLogs := logtest.Captured(t)
+			// Create a permissions sync job connection store
+			resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+			require.NoError(t, err)
+
+			nodes, err := resolver.Nodes(ctx)
+			require.NoError(t, err) // Assert that no error is returned
+			require.Equal(t, 0, len(nodes))
+
+			// Assert that the error is logged
+			logEntries := dumpLogs()
+			var foundLogEntry bool
+			for _, entry := range logEntries {
+				errText, ok := entry.Fields["error"].(string)
+
+				if ok && strings.Contains(errText, unexpectedError.Error()) {
+					foundLogEntry = true
+					break
+				}
+			}
+
+			require.True(t, foundLogEntry, "Expected log entry not found")
+		})
+
+		t.Run("user error", func(t *testing.T) {
+			// Create a mock database
+			db := dbmocks.NewMockDB()
+
+			// Create a mock permissions sync job store
+			jobStore := dbmocks.NewMockPermissionSyncJobStore()
+
+			// Set up the expectations for the job store
+			job := &database.PermissionSyncJob{ID: 1, UserID: 1}
+			jobStore.ListFunc.SetDefaultReturn([]*database.PermissionSyncJob{job}, nil)
+
+			db.PermissionSyncJobsFunc.SetDefaultReturn(jobStore)
+
+			unexpectedError := errors.New("this is a test error")
+
+			userStore := dbmocks.NewMockUserStore()
+			userStore.GetByIDFunc.SetDefaultReturn(nil, unexpectedError)
+			db.UsersFunc.SetDefaultReturn(userStore)
+
+			logger, dumpLogs := logtest.Captured(t)
+			// Create a permissions sync job connection store
+			resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+			require.NoError(t, err)
+
+			nodes, err := resolver.Nodes(ctx)
+			require.NoError(t, err)
+			require.Equal(t, 0, len(nodes))
+
+			// Assert that the error is logged
+			logEntries := dumpLogs()
+			var foundLogEntry bool
+			for _, entry := range logEntries {
+				errText, ok := entry.Fields["error"].(string)
+
+				if ok && strings.Contains(errText, unexpectedError.Error()) {
+					foundLogEntry = true
+					break
+				}
+			}
+
+			require.True(t, foundLogEntry, "Expected log entry not found")
+		})
+	})
+
+	t.Run("skips over not found errors", func(t *testing.T) {
+		t.Run("repository error", func(t *testing.T) {
+
+			// Create a mock
+			db := dbmocks.NewMockDB()
+
+			// Create a mock permissions sync job store
+			jobStore := dbmocks.NewMockPermissionSyncJobStore()
+
+			// Set up the expectations for the job store
+			job := &database.PermissionSyncJob{ID: 1, RepositoryID: 1}
+			jobStore.ListFunc.SetDefaultReturn([]*database.PermissionSyncJob{job}, nil)
+
+			db.PermissionSyncJobsFunc.SetDefaultReturn(jobStore)
+
+			notFoundError := testNotFoundError{}
+
+			repoStore := dbmocks.NewMockRepoStore()
+			repoStore.GetFunc.SetDefaultReturn(nil, notFoundError)
+			db.ReposFunc.SetDefaultReturn(repoStore)
+
+			logger, dumpLogs := logtest.Captured(t)
+			// Create a permissions sync job connection store
+			resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+			require.NoError(t, err)
+
+			nodes, err := resolver.Nodes(ctx)
+			require.NoError(t, err) // Assert that no error is returned
+			require.Equal(t, 0, len(nodes))
+
+			foundError := false
+			for _, entry := range dumpLogs() {
+				if strings.Contains(entry.Message, notFoundError.Error()) {
+					foundError = true
+					break
+				}
+
+				errText, ok := entry.Fields["error"].(string)
+				if ok && strings.Contains(errText, notFoundError.Error()) {
+					foundError = true
+					break
+				}
+			}
+
+			require.False(t, foundError, "Unexpected error found in logs")
+		})
+
+		t.Run("user error", func(t *testing.T) {
+
+			// Create a mock
+			db := dbmocks.NewMockDB()
+
+			// Create a mock permissions sync job store
+			jobStore := dbmocks.NewMockPermissionSyncJobStore()
+
+			// Set up the expectations for the job store
+			job := &database.PermissionSyncJob{ID: 1, RepositoryID: 1}
+			jobStore.ListFunc.SetDefaultReturn([]*database.PermissionSyncJob{job}, nil)
+
+			db.PermissionSyncJobsFunc.SetDefaultReturn(jobStore)
+
+			notFoundError := testNotFoundError{}
+
+			userStore := dbmocks.NewMockRepoStore()
+			userStore.GetFunc.SetDefaultReturn(nil, notFoundError)
+			db.ReposFunc.SetDefaultReturn(userStore)
+
+			logger, dumpLogs := logtest.Captured(t)
+			// Create a permissions sync job connection store
+			resolver, err := NewPermissionsSyncJobsResolver(logger, db, graphqlbackend.ListPermissionsSyncJobsArgs{ConnectionResolverArgs: args})
+			require.NoError(t, err)
+
+			nodes, err := resolver.Nodes(ctx)
+			require.NoError(t, err) // Assert that no error is returned
+			require.Equal(t, 0, len(nodes))
+
+			foundError := false
+			for _, entry := range dumpLogs() {
+				if strings.Contains(entry.Message, notFoundError.Error()) {
+					foundError = true
+					break
+				}
+
+				errText, ok := entry.Fields["error"].(string)
+				if ok && strings.Contains(errText, notFoundError.Error()) {
+					foundError = true
+					break
+				}
+			}
+
+			require.False(t, foundError, "Unexpected error found in logs")
+		})
+	})
+}
+
+type testNotFoundError struct{}
+
+func (testNotFoundError) NotFound() bool {
+	return true
 }
+
+func (testNotFoundError) Error() string {
+	return "this is a test not found error"
+}
+
+var _ error = testNotFoundError{}

cmd/frontend/internal/authz/resolvers/resolver.go

@@ -663,7 +663,7 @@ func (r *Resolver) PermissionsSyncJobs(ctx context.Context, args graphqlbackend.
 		return nil, err
 	}
 
-	return NewPermissionsSyncJobsResolver(r.db, args)
+	return NewPermissionsSyncJobsResolver(r.logger, r.db, args)
 }
 
 func (r *Resolver) PermissionsSyncingStats(ctx context.Context) (graphqlbackend.PermissionsSyncingStatsResolver, error) {