Log event when we find an operation to suspend on

Summary:
As part of our discussion around exploring a Reactive Key Value store architecture, we identified that OperationTracker would be incompatible in its current form.

As a baseline we would like to be able to collect data showing how effective OperationTacker is today. One way to measure that would be: How often does it identify an operation on which we could suspend that is _not_ the fragment's parent operation. This log event will allow us to track that statistic in prod.

Reviewed By: rbalicki2

Differential Revision: D43294511

fbshipit-source-id: 6e6f648234dc95b2b71ecd01b918a16df47a9c87

packages/react-relay/relay-hooks/__tests__/FragmentResource-WithOperationTracker-test.js

@@ -11,7 +11,10 @@
 
 'use strict';
 
+import type {LogEvent} from 'relay-runtime/store/RelayStoreTypes';
+
 const {createFragmentResource} = require('../FragmentResource');
+const invariant = require('invariant');
 const {
   createOperationDescriptor,
   createReaderSelector,
@@ -37,16 +40,19 @@ describe('FragmentResource with Operation Tracker and Missing Data', () => {
   let operationTracker;
   let viewerOperation;
   let nodeOperation;
+  let logger;
 
   beforeEach(() => {
     operationLoader = {
       load: jest.fn(),
       get: jest.fn(),
     };
     operationTracker = new RelayOperationTracker();
+    logger = jest.fn<[LogEvent], void>();
     environment = createMockEnvironment({
       operationTracker,
       operationLoader,
+      log: logger,
     });
     NodeQuery = graphql`
       query FragmentResourceWithOperationTrackerTestNodeQuery($id: ID!) {
@@ -262,6 +268,24 @@ describe('FragmentResource with Operation Tracker and Missing Data', () => {
     }
     // Assert that promise from first read was cached
     expect(cached).toBe(thrown);
+
+    // Assert that we logged a 'pendingoperation.found' event.
+    const pendingOperationFoundEvents = logger.mock.calls
+      .map(([event]) => event)
+      .filter(event => event.name === 'pendingoperation.found');
+
+    expect(pendingOperationFoundEvents.length).toBe(1);
+    const event = pendingOperationFoundEvents[0];
+    invariant(event.name === 'pendingoperation.found');
+    expect(event.fragment.name).toBe(
+      'FragmentResourceWithOperationTrackerTestPlainUserNameRenderer_name',
+    );
+    expect(event.fragmentOwner.node.operation.name).toBe(
+      viewerOperation.request.node.operation.name,
+    );
+    expect(
+      event.pendingOperations.map(owner => owner.node.operation.name),
+    ).toEqual(['FragmentResourceWithOperationTrackerTestNodeQuery']);
   });
 
   it('should read the data from the store once operation fully completed', () => {

packages/relay-runtime/store/RelayStoreTypes.js

@@ -583,6 +583,15 @@ export type LogEvent =
       // Are we reading this result from the fragment resource cache?
       +cached: boolean,
     }
+  | {
+      // Indicates getPendingOperationForFragment identified a pending operation.
+      // Useful for measuring how frequently RelayOperationTracker identifies a
+      // related operation on which to suspend.
+      +name: 'pendingoperation.found',
+      +fragment: ReaderFragment,
+      +fragmentOwner: RequestDescriptor,
+      +pendingOperations: $ReadOnlyArray<RequestDescriptor>,
+    }
   | {
       +name: 'network.info',
       +networkRequestId: number,

packages/relay-runtime/util/getPendingOperationsForFragment.js

@@ -54,6 +54,16 @@ function getPendingOperationsForFragment(
       : `Relay(${pendingOperationName}:${fragmentName})`;
   // $FlowExpectedError[prop-missing] Expando to annotate Promises.
   promise.displayName = promiseDisplayName;
+
+  // In order to monitor the efficacy of RelayOperationTracker, we log
+  // enough information to track whether we are suspending on the fragment
+  // owner's operation, or some other operation.
+  environment.__log({
+    name: 'pendingoperation.found',
+    fragment: fragmentNode,
+    fragmentOwner,
+    pendingOperations,
+  });
   return {promise, pendingOperations};
 }