Add metadata cache tracing and avoid duplicate cache lookups (#23080)

## Summary - Add Sentry tracing around metadata GraphQL cache reads with operation tags and cache-phase attributes. - Record cache hits on the request path so the response hook skips a duplicate lookup after an early return. - Cover the cache-hit, request-miss/response-hit, and allowlist filtering cases with unit tests. Before, even a cache hit performed two Redis reads: ``` onRequest → GET → hit → return cached response onResponse → GET → hit → do nothing ``` GraphQL Yoga still calls onResponse for an early cached response, so that second lookup was redundant in most cases. Now ``` onRequest → GET → hit → mark request in WeakSet → return cached response onResponse → request marked → remove marker → return immediately ``` onResponse cache mechanism is also there to prevent race conditions like: ``` Did another request populate this key while I was executing? yes → keep it no → cache my response ```
2026-07-20 19:22:57 +02:00
parent 6ece4ce1b1
commit 26227eff31
2 changed files with 219 additions and 6 deletions
@@ -0,0 +1,160 @@
+import * as Sentry from '@sentry/node';
+import { type Request } from 'express';
+
+import { useCachedMetadata } from 'src/engine/api/graphql/graphql-config/hooks/use-cached-metadata';
+
+jest.mock('@sentry/node', () => ({
+  getCurrentScope: jest.fn(),
+  setTags: jest.fn(),
+  startSpan: jest.fn(),
+}));
+
+describe('useCachedMetadata', () => {
+  const mockScope = {
+    setTransactionName: jest.fn(),
+  };
+  const mockSpan = {
+    setAttribute: jest.fn(),
+  };
+
+  const expectedSpanOptions = (phase: 'request' | 'response') => ({
+    name: 'metadata GraphQL cache lookup',
+    op: 'cache.get',
+    onlyIfParent: true,
+    attributes: {
+      'cache.phase': phase,
+      'graphql.operation.name': 'FindAllViews',
+      'graphql.operation.type': 'query',
+    },
+  });
+
+  const createRequest = (
+    overrides: Partial<
+      Pick<Request, 'body' | 'locale' | 'userWorkspaceId' | 'workspace'>
+    > = {},
+  ) =>
+    ({
+      body: {
+        operationName: 'FindAllViews',
+        query: 'query FindAllViews { views { id } }',
+      },
+      locale: 'en',
+      userWorkspaceId: 'user-workspace-id',
+      workspace: { id: 'workspace-id', metadataVersion: 3 },
+      ...overrides,
+    }) as Request;
+
+  const createPlugin = ({
+    cacheGetter = jest.fn().mockResolvedValue(undefined),
+    cacheSetter = jest.fn(),
+  } = {}) =>
+    useCachedMetadata({
+      cacheGetter,
+      cacheSetter,
+      operationsToCache: ['FindAllViews'],
+    });
+
+  beforeEach(() => {
+    jest.clearAllMocks();
+    jest.mocked(Sentry.getCurrentScope).mockReturnValue(mockScope as never);
+    jest
+      .mocked(Sentry.startSpan)
+      .mockImplementation((_options, callback) => callback(mockSpan as never));
+  });
+
+  it('reads the cache once when returning a cached response', async () => {
+    const cachedResponse = { data: { views: [{ id: 'view-id' }] } };
+    const cacheGetter = jest.fn().mockResolvedValue(cachedResponse);
+    const cacheSetter = jest.fn();
+    const plugin = createPlugin({ cacheGetter, cacheSetter });
+    const request = createRequest();
+    const serverContext = { req: request };
+    const endResponse = jest.fn();
+
+    await plugin.onRequest?.({ endResponse, serverContext } as never);
+
+    const response = endResponse.mock.calls[0][0] as Response;
+
+    await plugin.onResponse?.({ response, serverContext } as never);
+
+    expect(cacheGetter).toHaveBeenCalledTimes(1);
+    expect(cacheSetter).not.toHaveBeenCalled();
+    expect(await response.json()).toEqual(cachedResponse);
+    expect(Sentry.setTags).toHaveBeenCalledWith({
+      operationName: 'FindAllViews',
+      operation: 'query',
+    });
+    expect(mockScope.setTransactionName).toHaveBeenCalledWith('FindAllViews');
+    expect(Sentry.startSpan).toHaveBeenCalledTimes(1);
+    expect(Sentry.startSpan).toHaveBeenCalledWith(
+      expectedSpanOptions('request'),
+      expect.any(Function),
+    );
+    expect(mockSpan.setAttribute).toHaveBeenCalledWith('cache.hit', true);
+  });
+
+  it('preserves a value populated after the request cache miss', async () => {
+    const responseCachedByAnotherRequest = {
+      data: { views: [{ id: 'view-id' }] },
+    };
+    const cacheGetter = jest
+      .fn()
+      .mockResolvedValueOnce(undefined)
+      .mockResolvedValueOnce(responseCachedByAnotherRequest);
+    const cacheSetter = jest.fn();
+    const plugin = createPlugin({ cacheGetter, cacheSetter });
+    const request = createRequest();
+    const serverContext = { req: request };
+    const response = Response.json({ data: { views: [] } });
+
+    await plugin.onRequest?.({
+      endResponse: jest.fn(),
+      serverContext,
+    } as never);
+    await plugin.onResponse?.({ response, serverContext } as never);
+
+    expect(cacheGetter).toHaveBeenCalledTimes(2);
+    expect(cacheSetter).not.toHaveBeenCalled();
+    expect(Sentry.startSpan).toHaveBeenNthCalledWith(
+      1,
+      expectedSpanOptions('request'),
+      expect.any(Function),
+    );
+    expect(Sentry.startSpan).toHaveBeenNthCalledWith(
+      2,
+      expectedSpanOptions('response'),
+      expect.any(Function),
+    );
+    expect(mockSpan.setAttribute).toHaveBeenNthCalledWith(
+      1,
+      'cache.hit',
+      false,
+    );
+    expect(mockSpan.setAttribute).toHaveBeenNthCalledWith(2, 'cache.hit', true);
+  });
+
+  it('does not trace client-controlled operations outside the cache allowlist', async () => {
+    const cacheGetter = jest.fn();
+    const plugin = createPlugin({ cacheGetter });
+    const request = createRequest({
+      body: {
+        operationName: 'UncachedOperation',
+        query: 'query UncachedOperation { views { id } }',
+      },
+    });
+    const serverContext = { req: request };
+
+    await plugin.onRequest?.({
+      endResponse: jest.fn(),
+      serverContext,
+    } as never);
+    await plugin.onResponse?.({
+      response: Response.json({ data: {} }),
+      serverContext,
+    } as never);
+
+    expect(cacheGetter).not.toHaveBeenCalled();
+    expect(Sentry.setTags).not.toHaveBeenCalled();
+    expect(Sentry.startSpan).not.toHaveBeenCalled();
+  });
+});
@@ -1,5 +1,6 @@
 import { createHash } from 'crypto';

+import * as Sentry from '@sentry/node';
 import { type Request } from 'express';
 import { type Plugin } from 'graphql-yoga';
 import { isDefined } from 'twenty-shared/utils';
@@ -45,6 +46,37 @@ export function useCachedMetadata(config: CacheMetadataPluginConfig): Plugin {
  const getOperationName = (serverContext: any) =>
    serverContext?.req?.body?.operationName;

+  const cacheHitRequests = new WeakSet<Request>();
+
+  const getCachedResponse = ({
+    cacheKey,
+    operationName,
+    phase,
+  }: {
+    cacheKey: string;
+    operationName: string;
+    phase: 'request' | 'response';
+  }) =>
+    Sentry.startSpan(
+      {
+        name: 'metadata GraphQL cache lookup',
+        op: 'cache.get',
+        onlyIfParent: true,
+        attributes: {
+          'cache.phase': phase,
+          'graphql.operation.name': operationName,
+          'graphql.operation.type': 'query',
+        },
+      },
+      async (span) => {
+        const cachedResponse = await config.cacheGetter(cacheKey);
+
+        span.setAttribute('cache.hit', Boolean(cachedResponse));
+
+        return cachedResponse;
+      },
+    );
+
  return {
    onRequest: async ({ endResponse, serverContext }) => {
      // TODO: we should probably override the graphql-yoga request type to include the workspace and locale
@@ -54,17 +86,28 @@ export function useCachedMetadata(config: CacheMetadataPluginConfig): Plugin {
        return;
      }

-      if (!config.operationsToCache.includes(getOperationName(serverContext))) {
+      const operationName = getOperationName(serverContext);
+
+      if (!config.operationsToCache.includes(operationName)) {
        return;
      }

+      Sentry.setTags({ operationName, operation: 'query' });
+      Sentry.getCurrentScope().setTransactionName(operationName);
+
      const cacheKey = computeCacheKey({
-        operationName: getOperationName(serverContext),
+        operationName,
        request,
      });
-      const cachedResponse = await config.cacheGetter(cacheKey);
+      const cachedResponse = await getCachedResponse({
+        cacheKey,
+        operationName,
+        phase: 'request',
+      });

      if (cachedResponse) {
+        cacheHitRequests.add(request);
+
        const earlyResponse = Response.json(cachedResponse);

        return endResponse(earlyResponse);
@@ -77,16 +120,26 @@ export function useCachedMetadata(config: CacheMetadataPluginConfig): Plugin {
        return;
      }

-      if (!config.operationsToCache.includes(getOperationName(serverContext))) {
+      const operationName = getOperationName(serverContext);
+
+      if (!config.operationsToCache.includes(operationName)) {
+        return;
+      }
+
+      if (cacheHitRequests.delete(request)) {
        return;
      }

      const cacheKey = computeCacheKey({
-        operationName: getOperationName(serverContext),
+        operationName,
        request,
      });

-      const cachedResponse = await config.cacheGetter(cacheKey);
+      const cachedResponse = await getCachedResponse({
+        cacheKey,
+        operationName,
+        phase: 'response',
+      });

      if (!cachedResponse) {
        const responseBody = await response.json();