[Scheduler] Prevent event log from growing unbounded (#16781)

If a Scheduler profile runs without stopping, the event log will grow
unbounded. Eventually it will run out of memory and the VM will throw
an error.

To prevent this from happening, let's automatically stop the profiler
once the log exceeds a certain limit. We'll also print a warning with
advice to call `stopLoggingProfilingEvents` explicitly.

Author: acdlite

packages/scheduler/src/SchedulerProfiling.js

@@ -44,7 +44,9 @@ if (enableProfiling) {
   profilingState[CURRENT_TASK_ID] = 0;
 }
 
-const INITIAL_EVENT_LOG_SIZE = 1000;
+// Bytes per element is 4
+const INITIAL_EVENT_LOG_SIZE = 131072;
+const MAX_EVENT_LOG_SIZE = 524288; // Equivalent to 2 megabytes
 
 let eventLogSize = 0;
 let eventLogBuffer = null;
@@ -65,10 +67,16 @@ function logEvent(entries) {
     const offset = eventLogIndex;
     eventLogIndex += entries.length;
     if (eventLogIndex + 1 > eventLogSize) {
-      eventLogSize = eventLogIndex + 1;
-      const newEventLog = new Int32Array(
-        eventLogSize * Int32Array.BYTES_PER_ELEMENT,
-      );
+      eventLogSize *= 2;
+      if (eventLogSize > MAX_EVENT_LOG_SIZE) {
+        console.error(
+          "Scheduler Profiling: Event log exceeded maxinum size. Don't " +
+            'forget to call `stopLoggingProfilingEvents()`.',
+        );
+        stopLoggingProfilingEvents();
+        return;
+      }
+      const newEventLog = new Int32Array(eventLogSize * 4);
       newEventLog.set(eventLog);
       eventLogBuffer = newEventLog.buffer;
       eventLog = newEventLog;
@@ -79,14 +87,17 @@ function logEvent(entries) {
 
 export function startLoggingProfilingEvents(): void {
   eventLogSize = INITIAL_EVENT_LOG_SIZE;
-  eventLogBuffer = new ArrayBuffer(eventLogSize * Int32Array.BYTES_PER_ELEMENT);
+  eventLogBuffer = new ArrayBuffer(eventLogSize * 4);
   eventLog = new Int32Array(eventLogBuffer);
   eventLogIndex = 0;
 }
 
 export function stopLoggingProfilingEvents(): ArrayBuffer | null {
   const buffer = eventLogBuffer;
-  eventLogBuffer = eventLog = null;
+  eventLogSize = 0;
+  eventLogBuffer = null;
+  eventLog = null;
+  eventLogIndex = 0;
   return buffer;
 }
 

packages/scheduler/src/__tests__/SchedulerProfiling-test.js

@@ -99,9 +99,12 @@ describe('Scheduler', () => {
   const SchedulerResumeEvent = 8;
 
   function stopProfilingAndPrintFlamegraph() {
-    const eventLog = new Int32Array(
-      Scheduler.unstable_Profiling.stopLoggingProfilingEvents(),
-    );
+    const eventBuffer = Scheduler.unstable_Profiling.stopLoggingProfilingEvents();
+    if (eventBuffer === null) {
+      return '(empty profile)';
+    }
+
+    const eventLog = new Int32Array(eventBuffer);
 
     const tasks = new Map();
     const mainThreadRuns = [];
@@ -496,13 +499,46 @@ Task 2 [Normal]              │    ░░░░░░░░🡐 canceled
     );
   });
 
-  it('resizes event log buffer if there are many events', () => {
-    const tasks = [];
-    for (let i = 0; i < 5000; i++) {
-      tasks.push(scheduleCallback(NormalPriority, () => {}));
+  it('automatically stops profiling and warns if event log gets too big', async () => {
+    Scheduler.unstable_Profiling.startLoggingProfilingEvents();
+
+    spyOnDevAndProd(console, 'error');
+
+    // Increase infinite loop guard limit
+    const originalMaxIterations = global.__MAX_ITERATIONS__;
+    global.__MAX_ITERATIONS__ = 120000;
+
+    let taskId = 1;
+    while (console.error.calls.count() === 0) {
+      taskId++;
+      const task = scheduleCallback(NormalPriority, () => {});
+      cancelCallback(task);
+      expect(Scheduler).toFlushAndYield([]);
     }
-    expect(getProfilingInfo()).toEqual('Suspended, Queue Size: 5000');
-    tasks.forEach(task => cancelCallback(task));
-    expect(getProfilingInfo()).toEqual('Empty Queue');
+
+    expect(console.error).toHaveBeenCalledTimes(1);
+    expect(console.error.calls.argsFor(0)[0]).toBe(
+      "Scheduler Profiling: Event log exceeded maxinum size. Don't forget " +
+        'to call `stopLoggingProfilingEvents()`.',
+    );
+
+    // Should automatically clear profile
+    expect(stopProfilingAndPrintFlamegraph()).toEqual('(empty profile)');
+
+    // Test that we can start a new profile later
+    Scheduler.unstable_Profiling.startLoggingProfilingEvents();
+    scheduleCallback(NormalPriority, () => {
+      Scheduler.unstable_advanceTime(1000);
+    });
+    expect(Scheduler).toFlushAndYield([]);
+
+    // Note: The exact task id is not super important. That just how many tasks
+    // it happens to take before the array is resized.
+    expect(stopProfilingAndPrintFlamegraph()).toEqual(`
+!!! Main thread              │░░░░░░░░░░░░░░░░░░░░
+Task ${taskId} [Normal]          │████████████████████
+`);
+
+    global.__MAX_ITERATIONS__ = originalMaxIterations;
   });
 });

scripts/babel/transform-prevent-infinite-loops.js

@@ -22,10 +22,10 @@ module.exports = ({types: t, template}) => {
   // We set a global so that we can later fail the test
   // even if the error ends up being caught by the code.
   const buildGuard = template(`
-    if (ITERATOR++ > MAX_ITERATIONS) {
+    if (%%iterator%%++ > %%maxIterations%%) {
       global.infiniteLoopError = new RangeError(
         'Potential infinite loop: exceeded ' +
-        MAX_ITERATIONS +
+        %%maxIterations%% +
         ' iterations.'
       );
       throw global.infiniteLoopError;
@@ -36,10 +36,18 @@ module.exports = ({types: t, template}) => {
     visitor: {
       'WhileStatement|ForStatement|DoWhileStatement': (path, file) => {
         const filename = file.file.opts.filename;
-        const MAX_ITERATIONS =
-          filename.indexOf('__tests__') === -1
-            ? MAX_SOURCE_ITERATIONS
-            : MAX_TEST_ITERATIONS;
+        const maxIterations = t.logicalExpression(
+          '||',
+          t.memberExpression(
+            t.identifier('global'),
+            t.identifier('__MAX_ITERATIONS__')
+          ),
+          t.numericLiteral(
+            filename.indexOf('__tests__') === -1
+              ? MAX_SOURCE_ITERATIONS
+              : MAX_TEST_ITERATIONS
+          )
+        );
 
         // An iterator that is incremented with each iteration
         const iterator = path.scope.parent.generateUidIdentifier('loopIt');
@@ -50,8 +58,8 @@ module.exports = ({types: t, template}) => {
         });
         // If statement and throw error if it matches our criteria
         const guard = buildGuard({
-          ITERATOR: iterator,
-          MAX_ITERATIONS: t.numericLiteral(MAX_ITERATIONS),
+          iterator,
+          maxIterations,
         });
         // No block statement e.g. `while (1) 1;`
         if (!path.get('body').isBlockStatement()) {

scripts/jest/preprocessor.js

@@ -22,6 +22,9 @@ const pathToBabelPluginWrapWarning = require.resolve(
 const pathToBabelPluginAsyncToGenerator = require.resolve(
   '@babel/plugin-transform-async-to-generator'
 );
+const pathToTransformInfiniteLoops = require.resolve(
+  '../babel/transform-prevent-infinite-loops'
+);
 const pathToBabelrc = path.join(__dirname, '..', '..', 'babel.config.js');
 const pathToErrorCodes = require.resolve('../error-codes/codes.json');
 
@@ -39,7 +42,7 @@ const babelOptions = {
     // TODO: I have not verified that this actually works.
     require.resolve('@babel/plugin-transform-react-jsx-source'),
 
-    require.resolve('../babel/transform-prevent-infinite-loops'),
+    pathToTransformInfiniteLoops,
 
     // This optimization is important for extremely performance-sensitive (e.g. React source).
     // It's okay to disable it for tests.
@@ -87,6 +90,7 @@ module.exports = {
     pathToBabelrc,
     pathToBabelPluginDevWithCode,
     pathToBabelPluginWrapWarning,
+    pathToTransformInfiniteLoops,
     pathToErrorCodes,
   ]),
 };