[v14] filter expired requests from cache reads

lib/services/access_request_cache.go

@@ -205,7 +205,15 @@ func (c *AccessRequestCache) ListMatchingAccessRequests(ctx context.Context, req
 
 	// perform the traversal until we've seen all items or fill the page
 	var rsp proto.ListAccessRequestsResponse
+	now := time.Now()
+	var expired int
 	traverse(index, req.StartKey, "", func(r *types.AccessRequestV3) (continueTraversal bool) {
+		if !r.Expiry().IsZero() && now.After(r.Expiry()) {
+			expired++
+			// skip requests that appear expired. some backends can take up to 48 hours to expired items
+			// and access requests showing up past their expiry time is particularly confusing.
+			return true
+		}
 		if !req.Filter.Match(r) || !match(r) {
 			return true
 		}
@@ -229,6 +237,12 @@ func (c *AccessRequestCache) ListMatchingAccessRequests(ctx context.Context, req
 		rsp.AccessRequests = rsp.AccessRequests[:limit]
 	}
 
+	if expired > 0 {
+		// this is a debug-level log since some amount of delay between expiry and backend cleanup is expected, but
+		// very large and/or disproportionate numbers of stale access requests might be a symptom of a deeper issue.
+		log.Debugf("Omitting %d expired access requests from cache read.", expired)
+	}
+
 	return &rsp, nil
 }
 

lib/services/access_request_cache_test.go

@@ -252,3 +252,105 @@ func TestAccessRequestCacheBasics(t *testing.T) {
 		}
 	}
 }
+
+func TestAccessRequestCacheExpiryFiltering(t *testing.T) {
+	t.Parallel()
+
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	bk, err := memory.New(memory.Config{
+		// set backend into mirror mode so that it does not expire items
+		// automatically.
+		Mirror: true,
+	})
+	require.NoError(t, err)
+
+	svcs := accessRequestServices{
+		Events:           local.NewEventsService(bk),
+		DynamicAccessExt: local.NewDynamicAccessService(bk),
+	}
+
+	cache, err := services.NewAccessRequestCache(services.AccessRequestCacheConfig{
+		Events: svcs,
+		Getter: svcs,
+	})
+	require.NoError(t, err)
+
+	// describe a set of test requests, some of which are expired
+	rrs := []struct {
+		name    string
+		id      string
+		expired bool
+	}{
+		{
+			id:      "00000000-0000-0000-0000-000000000005",
+			name:    "bob",
+			expired: true,
+		},
+		{
+			id:      "00000000-0000-0000-0000-000000000004",
+			name:    "bob",
+			expired: false,
+		},
+		{
+			id:      "00000000-0000-0000-0000-000000000003",
+			name:    "alice",
+			expired: true,
+		},
+		{
+			id:      "00000000-0000-0000-0000-000000000002",
+			name:    "alice",
+			expired: false,
+		},
+		{
+			id:      "00000000-0000-0000-0000-000000000001",
+			name:    "jan",
+			expired: true,
+		},
+	}
+
+	// insert test requests into backend, and aggregate the IDs of the subset that
+	// are unexpired so that we can check them against cache reads later.
+	var unexpiredRequestIDs []string
+	for _, rr := range rrs {
+		r, err := types.NewAccessRequest(rr.id, rr.name, "some-role")
+		require.NoError(t, err)
+
+		if rr.expired {
+			r.SetExpiry(time.Now().Add(-time.Minute * 30).UTC())
+		} else {
+			unexpiredRequestIDs = append(unexpiredRequestIDs, rr.id)
+			r.SetExpiry(time.Now().Add(time.Minute * 30).UTC())
+		}
+		_, err = svcs.CreateAccessRequestV2(ctx, r)
+		require.NoError(t, err)
+	}
+
+	// verify that once cache replication completes, only the unexpired requests are served
+	timeout := time.After(time.Second * 30)
+	for {
+		rsp, err := cache.ListAccessRequests(ctx, &proto.ListAccessRequestsRequest{
+			Limit: int32(len(rrs)),
+		})
+		require.NoError(t, err)
+
+		if len(rsp.AccessRequests) >= len(unexpiredRequestIDs) {
+			// once cache is returning the expected number of requests, verify that
+			// the set of requests returned is exactly the unexpired subset.
+			var returnedRequestIDs []string
+			for _, req := range rsp.AccessRequests {
+				returnedRequestIDs = append(returnedRequestIDs, req.GetName())
+			}
+
+			require.ElementsMatch(t, unexpiredRequestIDs, returnedRequestIDs)
+			break
+		}
+
+		select {
+		case <-timeout:
+			require.FailNow(t, "timeout waiting for access request cache to populate")
+		case <-time.After(time.Millisecond * 200):
+		}
+	}
+}