Log on LiveResolver batch start/end

Differential Revision: D44465769 fbshipit-source-id: 141b6cc35e255ba3395022d6f3a7626e8756c377
facebook · Apr 3, 2023 · cf1650e · cf1650e
1 parent d431902
commit cf1650e
Show file tree

Hide file tree

Showing 3 changed files with 58 additions and 2 deletions.
diff --git a/packages/relay-runtime/store/RelayStoreTypes.js b/packages/relay-runtime/store/RelayStoreTypes.js
@@ -717,6 +717,14 @@ export type EntrypointRootConsumeLogEvent = {
   +rootModuleID: string,
 };
 
+export type LiveResolverBatchStartLogEvent = {
+  +name: 'liveresolver.batch.start',
+};
+
+export type LiveResolverBatchEndLogEvent = {
+  +name: 'liveresolver.batch.end',
+};
+
 export type LogEvent =
   | SuspenseFragmentLogEvent
   | SuspenseQueryLogEvent
@@ -743,7 +751,9 @@ export type LogEvent =
   | StoreNotifyStartLogEvent
   | StoreNotifyCompleteLogEvent
   | StoreNotifySubscriptionLogEvent
-  | EntrypointRootConsumeLogEvent;
+  | EntrypointRootConsumeLogEvent
+  | LiveResolverBatchStartLogEvent
+  | LiveResolverBatchEndLogEvent;
 
 export type LogFunction = LogEvent => void;
 export type LogRequestInfoFunction = mixed => void;

diff --git a/packages/relay-runtime/store/__tests__/resolvers/LiveResolvers-test.js b/packages/relay-runtime/store/__tests__/resolvers/LiveResolvers-test.js
@@ -150,14 +150,25 @@ test('Updates can be batched', () => {
     `,
     {},
   );
+  const log = jest.fn();
   const store = new LiveResolverStore(source, {
     gcReleaseBufferSize: 0,
+    log,
   });
   const environment = new RelayModernEnvironment({
     network: RelayNetwork.create(jest.fn()),
     store,
+    log,
   });
 
+  function getBatchLogEventNames(): string[] {
+    return log.mock.calls
+      .map(log => log[0].name)
+      .filter(name => {
+        return name.startsWith('liveresolver.batch');
+      });
+  }
+
   const snapshot = environment.lookup(operation.fragment);
 
   const handler = jest.fn<[Snapshot], void>();
@@ -173,11 +184,18 @@ test('Updates can be batched', () => {
 
   let lastCallCount = handler.mock.calls.length;
 
+  expect(getBatchLogEventNames()).toEqual([]);
+
   // Update _with_ batching.
   store.batchLiveStateUpdates(() => {
     GLOBAL_STORE.dispatch({type: 'INCREMENT'});
   });
 
+  expect(getBatchLogEventNames()).toEqual([
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+  ]);
+
   // We get notified once per batch! :)
   expect(handler.mock.calls.length - lastCallCount).toBe(1);
 
@@ -193,6 +211,13 @@ test('Updates can be batched', () => {
     });
   }).toThrowError('An Example Error');
 
+  expect(getBatchLogEventNames()).toEqual([
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+  ]);
+
   // We still notify our subscribers
   expect(handler.mock.calls.length - lastCallCount).toBe(1);
 
@@ -202,4 +227,16 @@ test('Updates can be batched', () => {
       store.batchLiveStateUpdates(() => {});
     });
   }).toThrow('Unexpected nested call to batchLiveStateUpdates.');
+
+  expect(getBatchLogEventNames()).toEqual([
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+    // Here we can see the nesting
+    'liveresolver.batch.start',
+    'liveresolver.batch.start',
+    'liveresolver.batch.end',
+    'liveresolver.batch.end',
+  ]);
 });
diff --git a/packages/relay-runtime/store/experimental-live-resolvers/LiveResolverStore.js b/packages/relay-runtime/store/experimental-live-resolvers/LiveResolverStore.js
@@ -212,7 +212,16 @@ class LiveResolverStore implements Store {
    * fluxStore.dispatch = wrapped;
    */
   batchLiveStateUpdates(callback: () => void) {
-    this._resolverCache.batchLiveStateUpdates(callback);
+    if (this.__log != null) {
+      this.__log({name: 'liveresolver.batch.start'});
+    }
+    try {
+      this._resolverCache.batchLiveStateUpdates(callback);
+    } finally {
+      if (this.__log != null) {
+        this.__log({name: 'liveresolver.batch.end'});
+      }
+    }
   }
 
   check(