From 45898d0be0517b0851beaf2e7df0db3a054a437d Mon Sep 17 00:00:00 2001 From: Andrew Clark Date: Fri, 13 Sep 2019 15:50:25 -0700 Subject: [PATCH] [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. --- packages/scheduler/src/SchedulerProfiling.js | 25 ++++++--- .../src/__tests__/SchedulerProfiling-test.js | 56 +++++++++++++++---- .../babel/transform-prevent-infinite-loops.js | 24 +++++--- scripts/jest/preprocessor.js | 6 +- 4 files changed, 85 insertions(+), 26 deletions(-) diff --git a/packages/scheduler/src/SchedulerProfiling.js b/packages/scheduler/src/SchedulerProfiling.js index aaf4cbeef76be..c0e7dc2afa645 100644 --- a/packages/scheduler/src/SchedulerProfiling.js +++ b/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; } diff --git a/packages/scheduler/src/__tests__/SchedulerProfiling-test.js b/packages/scheduler/src/__tests__/SchedulerProfiling-test.js index fdbadfb77c488..d026823a0f284 100644 --- a/packages/scheduler/src/__tests__/SchedulerProfiling-test.js +++ b/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; }); }); diff --git a/scripts/babel/transform-prevent-infinite-loops.js b/scripts/babel/transform-prevent-infinite-loops.js index b0f637830ee0b..ac8ef57b8a40d 100644 --- a/scripts/babel/transform-prevent-infinite-loops.js +++ b/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()) { diff --git a/scripts/jest/preprocessor.js b/scripts/jest/preprocessor.js index beb46268f4be1..a7c0c377b4c95 100644 --- a/scripts/jest/preprocessor.js +++ b/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, ]), };