[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.
Andrew Clark committed
Sep 13, 2019 at 15:50 UTC
45898d0be0517b0851beaf2e7df0db3a054a437d
4 files changed
+85
-26
packages/scheduler/src/SchedulerProfiling.js
+18
-7
@@ -44,7 +44,9 @@ if (enableProfiling) {
44
profilingState[CURRENT_TASK_ID] = 0;
45
}
46
47
-const INITIAL_EVENT_LOG_SIZE = 1000;
47
+// Bytes per element is 4
48
+const INITIAL_EVENT_LOG_SIZE = 131072;
49
+const MAX_EVENT_LOG_SIZE = 524288; // Equivalent to 2 megabytes
50
51
let eventLogSize = 0;
52
let eventLogBuffer = null;
@@ -65,10 +67,16 @@ function logEvent(entries) {
67
const offset = eventLogIndex;
68
eventLogIndex += entries.length;
69
if (eventLogIndex + 1 > eventLogSize) {
68
- eventLogSize = eventLogIndex + 1;
69
- const newEventLog = new Int32Array(
70
- eventLogSize * Int32Array.BYTES_PER_ELEMENT,
71
- );
70
+ eventLogSize *= 2;
71
+ if (eventLogSize > MAX_EVENT_LOG_SIZE) {
72
+ console.error(
73
+ "Scheduler Profiling: Event log exceeded maxinum size. Don't " +
74
+ 'forget to call `stopLoggingProfilingEvents()`.',
75
+ );
76
+ stopLoggingProfilingEvents();
77
+ return;
78
+ }
79
+ const newEventLog = new Int32Array(eventLogSize * 4);
80
newEventLog.set(eventLog);
81
eventLogBuffer = newEventLog.buffer;
82
eventLog = newEventLog;
@@ -79,14 +87,17 @@ function logEvent(entries) {
87
88
export function startLoggingProfilingEvents(): void {
89
eventLogSize = INITIAL_EVENT_LOG_SIZE;
82
- eventLogBuffer = new ArrayBuffer(eventLogSize * Int32Array.BYTES_PER_ELEMENT);
90
+ eventLogBuffer = new ArrayBuffer(eventLogSize * 4);
91
eventLog = new Int32Array(eventLogBuffer);
92
eventLogIndex = 0;
93
}
94
95
export function stopLoggingProfilingEvents(): ArrayBuffer | null {
96
const buffer = eventLogBuffer;
89
- eventLogBuffer = eventLog = null;
97
+ eventLogSize = 0;
98
+ eventLogBuffer = null;
99
+ eventLog = null;
100
+ eventLogIndex = 0;
101
return buffer;
102
}
103
packages/scheduler/src/__tests__/SchedulerProfiling-test.js
+46
-10
@@ -99,9 +99,12 @@ describe('Scheduler', () => {
99
const SchedulerResumeEvent = 8;
100
101
function stopProfilingAndPrintFlamegraph() {
102
- const eventLog = new Int32Array(
103
- Scheduler.unstable_Profiling.stopLoggingProfilingEvents(),
104
- );
102
+ const eventBuffer = Scheduler.unstable_Profiling.stopLoggingProfilingEvents();
103
+ if (eventBuffer === null) {
104
+ return '(empty profile)';
105
+ }
106
+
107
+ const eventLog = new Int32Array(eventBuffer);
108
109
const tasks = new Map();
110
const mainThreadRuns = [];
@@ -496,13 +499,46 @@ Task 2 [Normal] │ ░░░░░░░░🡐 canceled
499
);
500
});
501
499
- it('resizes event log buffer if there are many events', () => {
500
- const tasks = [];
501
- for (let i = 0; i < 5000; i++) {
502
- tasks.push(scheduleCallback(NormalPriority, () => {}));
502
+ it('automatically stops profiling and warns if event log gets too big', async () => {
503
+ Scheduler.unstable_Profiling.startLoggingProfilingEvents();
504
+
505
+ spyOnDevAndProd(console, 'error');
506
+
507
+ // Increase infinite loop guard limit
508
+ const originalMaxIterations = global.__MAX_ITERATIONS__;
509
+ global.__MAX_ITERATIONS__ = 120000;
510
+
511
+ let taskId = 1;
512
+ while (console.error.calls.count() === 0) {
513
+ taskId++;
514
+ const task = scheduleCallback(NormalPriority, () => {});
515
+ cancelCallback(task);
516
+ expect(Scheduler).toFlushAndYield([]);
517
}
504
- expect(getProfilingInfo()).toEqual('Suspended, Queue Size: 5000');
505
- tasks.forEach(task => cancelCallback(task));
506
- expect(getProfilingInfo()).toEqual('Empty Queue');
518
+
519
+ expect(console.error).toHaveBeenCalledTimes(1);
520
+ expect(console.error.calls.argsFor(0)[0]).toBe(
521
+ "Scheduler Profiling: Event log exceeded maxinum size. Don't forget " +
522
+ 'to call `stopLoggingProfilingEvents()`.',
523
+ );
524
+
525
+ // Should automatically clear profile
526
+ expect(stopProfilingAndPrintFlamegraph()).toEqual('(empty profile)');
527
+
528
+ // Test that we can start a new profile later
529
+ Scheduler.unstable_Profiling.startLoggingProfilingEvents();
530
+ scheduleCallback(NormalPriority, () => {
531
+ Scheduler.unstable_advanceTime(1000);
532
+ });
533
+ expect(Scheduler).toFlushAndYield([]);
534
+
535
+ // Note: The exact task id is not super important. That just how many tasks
536
+ // it happens to take before the array is resized.
537
+ expect(stopProfilingAndPrintFlamegraph()).toEqual(`
538
+!!! Main thread │░░░░░░░░░░░░░░░░░░░░
539
+Task ${taskId} [Normal] │████████████████████
540
+`);
541
+
542
+ global.__MAX_ITERATIONS__ = originalMaxIterations;
543
});
544
});
scripts/babel/transform-prevent-infinite-loops.js
+16
-8
@@ -22,10 +22,10 @@ module.exports = ({types: t, template}) => {
22
// We set a global so that we can later fail the test
23
// even if the error ends up being caught by the code.
24
const buildGuard = template(`
25
- if (ITERATOR++ > MAX_ITERATIONS) {
25
+ if (%%iterator%%++ > %%maxIterations%%) {
26
global.infiniteLoopError = new RangeError(
27
'Potential infinite loop: exceeded ' +
28
- MAX_ITERATIONS +
28
+ %%maxIterations%% +
29
' iterations.'
30
);
31
throw global.infiniteLoopError;
@@ -36,10 +36,18 @@ module.exports = ({types: t, template}) => {
36
visitor: {
37
'WhileStatement|ForStatement|DoWhileStatement': (path, file) => {
38
const filename = file.file.opts.filename;
39
- const MAX_ITERATIONS =
40
- filename.indexOf('__tests__') === -1
41
- ? MAX_SOURCE_ITERATIONS
42
- : MAX_TEST_ITERATIONS;
39
+ const maxIterations = t.logicalExpression(
40
+ '||',
41
+ t.memberExpression(
42
+ t.identifier('global'),
43
+ t.identifier('__MAX_ITERATIONS__')
44
+ ),
45
+ t.numericLiteral(
46
+ filename.indexOf('__tests__') === -1
47
+ ? MAX_SOURCE_ITERATIONS
48
+ : MAX_TEST_ITERATIONS
49
+ )
50
+ );
51
52
// An iterator that is incremented with each iteration
53
const iterator = path.scope.parent.generateUidIdentifier('loopIt');
@@ -50,8 +58,8 @@ module.exports = ({types: t, template}) => {
58
});
59
// If statement and throw error if it matches our criteria
60
const guard = buildGuard({
53
- ITERATOR: iterator,
54
- MAX_ITERATIONS: t.numericLiteral(MAX_ITERATIONS),
61
+ iterator,
62
+ maxIterations,
63
});
64
// No block statement e.g. `while (1) 1;`
65
if (!path.get('body').isBlockStatement()) {
scripts/jest/preprocessor.js
+5
-1
@@ -22,6 +22,9 @@ const pathToBabelPluginWrapWarning = require.resolve(
22
const pathToBabelPluginAsyncToGenerator = require.resolve(
23
'@babel/plugin-transform-async-to-generator'
24
);
25
+const pathToTransformInfiniteLoops = require.resolve(
26
+ '../babel/transform-prevent-infinite-loops'
27
+);
28
const pathToBabelrc = path.join(__dirname, '..', '..', 'babel.config.js');
29
const pathToErrorCodes = require.resolve('../error-codes/codes.json');
30
@@ -39,7 +42,7 @@ const babelOptions = {
42
// TODO: I have not verified that this actually works.
43
require.resolve('@babel/plugin-transform-react-jsx-source'),
44
42
- require.resolve('../babel/transform-prevent-infinite-loops'),
45
+ pathToTransformInfiniteLoops,
46
47
// This optimization is important for extremely performance-sensitive (e.g. React source).
48
// It's okay to disable it for tests.
@@ -87,6 +90,7 @@ module.exports = {
90
pathToBabelrc,
91
pathToBabelPluginDevWithCode,
92
pathToBabelPluginWrapWarning,
93
+ pathToTransformInfiniteLoops,
94
pathToErrorCodes,
95
]),
96
};