Skip to content

Commit 15767a8

Browse files
flarnieflarnie
authored
[scheduler] 5/n Error handling in scheduler (facebook#12920)
* Initial failing unit test for error handling in schedule **what is the change?:** see title **why make this change?:** Adding tests for the error handling behavior we are about to add. This test is failing, which gives us the chance to make it pass. Wrote skeletons of some other tests to add. Unit testing this way is really hacky, and I'm also adding to the fixture to test this in the real browser environment. **test plan:** Ran new test, saw it fail! * Add fixture for testing error handling in scheduler **what is the change?:** Added a fixture which does the following - logs in the console to show what happens when you use `requestAnimationFrame` to schedule a series of callbacks and some of them throw errors. Then does the same actions with the `scheduler` and verifies that it behaves in a similar way. Hard to really verify the errors get thrown at the proper time without looking at the console. **why make this change?:** We want the most authentic, accurate test of how errors are handled in the scheduler. That's what this fixture should be. **test plan:** Manually verified that this test does what I expect - right now it's failing but follow up commits will fix that. * Handle errors in scheduler **what is the change?:** We set a flag before calling any callback, and then use a 'try/finally' block to wrap it. Note that we *do not* catch the error, if one is thrown. But, we only unset the flag after the callback successfully finishes. If we reach the 'finally' block and the flag was not unset, then it means an error was thrown. In that case we start a new postMessage callback, to finish calling any other pending callbacks if there is time. **why make this change?:** We need to make sure that an error thrown from one callback doesn't stop other callbacks from firing, but we also don't want to catch or swallow the error because we want engineers to still be able to log and debug errors. **test plan:** New tests added are passing, and we verified that they fail without this change. * Add more tests for error handling in scheduler **what is the change?:** Added tests for more situations where error handling may come up. **why make this change?:** To get additional protection against this being broken in the future. **test plan:** Ran new tests and verified that they fail when error handling fails. * callSafely -> callUnsafely * Fix bugs with error handling in schedule **what is the change?:** - ensure that we properly remove the callback from the linked list, even if it throws an error and is timed out. - ensure that you can call 'cancelScheduledWork' more than once and it is idempotent. **why make this change?:** To fix bugs :) **test plan:** Existing tests pass, and we'll add more tests in a follow up commit. * Unit tests for error handling with timed out callbacks **what is the change?:** More unit tests, to cover behavior which we missed; error handling of timed out callbacks. **why make this change?:** To protect the future!~ **test plan:** Run the new tests. * Adds fixture to test timed out callbacks with scheduler **what is the change?:** See title In the other error handling fixture we compare 'scheduleWork' error handling to 'requestAnimationFrame' and try to get as close as possible. There is no 'timing out' feature with 'requestAnimationFrame' but effectively the 'timing out' feature changes the order in which things are called. So we just changed the order in the 'requestAnimationFrame' version and that works well for illustrating the behavior we expect in the 'scheduleWork' test. **why make this change?:** We need more test coverage of timed out callbacks. **test plan:** Executed the fixture manually in Firefox and Chrome. Results looked good. * fix rebase problems * make fixture compensate for chrome JS speed * ran prettier * Remove 'cancelled' flag on callbackConfig in scheduler, add test **what is the change?:** - Instead of using a 'cancelled' flag on the callbackConfig, it's easier to just check the state of the callbackConfig inside 'cancelScheduledWork' to determine if it's already been cancelled. That way we don't have to remember to set the 'cancelled' flag every time we call a callback or cancel it. One less thing to remember. - We added a test for calling 'cancelScheduledWork' more than once, which would have failed before. Thanks @acdlite for suggesting this in code review. :) **why make this change?:** To increase stability of the schedule module, increase test coverage. **test plan:** Existing tests pass and we added a new test to cover this behavior. * fix typo
1 parent 3118ed9 commit 15767a8

File tree

3 files changed

+624
-30
lines changed

3 files changed

+624
-30
lines changed

‎fixtures/schedule/index.html‎

Lines changed: 177 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,16 @@ <h2>Tests:</h2>
6969
<div><b>Actual:</b></div>
7070
<div id="test-4"></div>
7171
</li>
72+
<li>
73+
<p>When some callbacks throw errors, still calls them all within the same frame</p>
74+
<p><b>IMPORTANT:</b> Open the console when you run this! Inspect the logs there!</p>
75+
<button onClick="runTestFive()">Run Test 5</button>
76+
</li>
77+
<li>
78+
<p>When some callbacks throw errors <b> and some also time out</b>, still calls them all within the same frame</p>
79+
<p><b>IMPORTANT:</b> Open the console when you run this! Inspect the logs there!</p>
80+
<button onClick="runTestSix()">Run Test 6</button>
81+
</li>
7282
</ol>
7383
<script src="../../build/dist/react-scheduler.development.js"></script>
7484
<script src="https://unpkg.com/babel-standalone@6/babel.js"></script>
@@ -134,6 +144,9 @@ <h2>Tests:</h2>
134144
// test 4
135145
[
136146
],
147+
// test 5
148+
[
149+
],
137150
];
138151

139152
const expectedResults = [
@@ -182,6 +195,10 @@ <h2>Tests:</h2>
182195
'cbD called with argument of {"didTimeout":false}',
183196
'frame 3 started... we stop counting now.',
184197
],
198+
// test 5
199+
[
200+
// ... TODO
201+
],
185202
];
186203
function runTestOne() {
187204
// Test 1
@@ -276,7 +293,7 @@ <h2>Tests:</h2>
276293
updateTestResult(4, 'scheduled cbA');
277294
scheduleWork(cbB, {timeout: 100}); // times out later
278295
updateTestResult(4, 'scheduled cbB');
279-
scheduleWork(cbC, {timeout: 2}); // will time out fast
296+
scheduleWork(cbC, {timeout: 1}); // will time out fast
280297
updateTestResult(4, 'scheduled cbC');
281298
scheduleWork(cbD); // won't time out
282299
updateTestResult(4, 'scheduled cbD');
@@ -287,6 +304,165 @@ <h2>Tests:</h2>
287304
displayTestResult(4);
288305
checkTestResult(4);
289306
});
307+
308+
}
309+
310+
// Error handling
311+
312+
function runTestFive() {
313+
// Test 5
314+
// When some callbacks throw errors, still calls them all within the same frame
315+
const cbA = (x) => {
316+
console.log('cbA called with argument of ' + JSON.stringify(x));
317+
}
318+
const cbB = (x) => {
319+
console.log('cbB called with argument of ' + JSON.stringify(x));
320+
console.log('cbB is about to throw an error!');
321+
throw new Error('error B');
322+
}
323+
const cbC = (x) => {
324+
console.log('cbC called with argument of ' + JSON.stringify(x));
325+
}
326+
const cbD = (x) => {
327+
console.log('cbD called with argument of ' + JSON.stringify(x));
328+
console.log('cbD is about to throw an error!');
329+
throw new Error('error D');
330+
}
331+
const cbE = (x) => {
332+
console.log('cbE called with argument of ' + JSON.stringify(x));
333+
console.log('This was the last callback! ------------------');
334+
}
335+
336+
console.log('We are aiming to roughly emulate the way ' +
337+
'`requestAnimationFrame` handles errors from callbacks.');
338+
339+
console.log('about to run the simulation of what it should look like...:');
340+
341+
requestAnimationFrame(() => {
342+
console.log('frame 1 started');
343+
requestAnimationFrame(() => {
344+
console.log('frame 2 started');
345+
requestAnimationFrame(() => {
346+
console.log('frame 3 started... we stop counting now.');
347+
console.log('about to wait a moment and start this again but ' +
348+
'with the scheduler instead of requestAnimationFrame');
349+
setTimeout(runSchedulerCode, 1000);
350+
});
351+
});
352+
});
353+
requestAnimationFrame(cbA);
354+
console.log('scheduled cbA');
355+
requestAnimationFrame(cbB); // will throw error
356+
console.log('scheduled cbB');
357+
requestAnimationFrame(cbC);
358+
console.log('scheduled cbC');
359+
requestAnimationFrame(cbD); // will throw error
360+
console.log('scheduled cbD');
361+
requestAnimationFrame(cbE);
362+
console.log('scheduled cbE');
363+
364+
365+
function runSchedulerCode() {
366+
console.log('-------------------------------------------------------------');
367+
console.log('now lets see what it looks like using the scheduler...:');
368+
requestAnimationFrame(() => {
369+
console.log('frame 1 started');
370+
requestAnimationFrame(() => {
371+
console.log('frame 2 started');
372+
requestAnimationFrame(() => {
373+
console.log('frame 3 started... we stop counting now.');
374+
});
375+
});
376+
});
377+
scheduleWork(cbA);
378+
console.log('scheduled cbA');
379+
scheduleWork(cbB); // will throw error
380+
console.log('scheduled cbB');
381+
scheduleWork(cbC);
382+
console.log('scheduled cbC');
383+
scheduleWork(cbD); // will throw error
384+
console.log('scheduled cbD');
385+
scheduleWork(cbE);
386+
console.log('scheduled cbE');
387+
};
388+
}
389+
390+
function runTestSix() {
391+
// Test 6
392+
// When some callbacks throw errors, still calls them all within the same frame
393+
const cbA = (x) => {
394+
console.log('cbA called with argument of ' + JSON.stringify(x));
395+
console.log('cbA is about to throw an error!');
396+
throw new Error('error A');
397+
}
398+
const cbB = (x) => {
399+
console.log('cbB called with argument of ' + JSON.stringify(x));
400+
}
401+
const cbC = (x) => {
402+
console.log('cbC called with argument of ' + JSON.stringify(x));
403+
}
404+
const cbD = (x) => {
405+
console.log('cbD called with argument of ' + JSON.stringify(x));
406+
console.log('cbD is about to throw an error!');
407+
throw new Error('error D');
408+
}
409+
const cbE = (x) => {
410+
console.log('cbE called with argument of ' + JSON.stringify(x));
411+
console.log('This was the last callback! ------------------');
412+
}
413+
414+
console.log('We are aiming to roughly emulate the way ' +
415+
'`requestAnimationFrame` handles errors from callbacks.');
416+
417+
console.log('about to run the simulation of what it should look like...:');
418+
419+
requestAnimationFrame(() => {
420+
console.log('frame 1 started');
421+
requestAnimationFrame(() => {
422+
console.log('frame 2 started');
423+
requestAnimationFrame(() => {
424+
console.log('frame 3 started... we stop counting now.');
425+
console.log('about to wait a moment and start this again but ' +
426+
'with the scheduler instead of requestAnimationFrame');
427+
setTimeout(runSchedulerCode, 1000);
428+
});
429+
});
430+
});
431+
requestAnimationFrame(cbC);
432+
console.log('scheduled cbC first; simulating timing out');
433+
requestAnimationFrame(cbD); // will throw error
434+
console.log('scheduled cbD first; simulating timing out');
435+
requestAnimationFrame(cbE);
436+
console.log('scheduled cbE first; simulating timing out');
437+
requestAnimationFrame(cbA);
438+
console.log('scheduled cbA'); // will throw error
439+
requestAnimationFrame(cbB);
440+
console.log('scheduled cbB');
441+
442+
443+
function runSchedulerCode() {
444+
console.log('-------------------------------------------------------------');
445+
console.log('now lets see what it looks like using the scheduler...:');
446+
requestAnimationFrame(() => {
447+
console.log('frame 1 started');
448+
requestAnimationFrame(() => {
449+
console.log('frame 2 started');
450+
requestAnimationFrame(() => {
451+
console.log('frame 3 started... we stop counting now.');
452+
});
453+
});
454+
});
455+
scheduleWork(cbA);
456+
console.log('scheduled cbA');
457+
scheduleWork(cbB); // will throw error
458+
console.log('scheduled cbB');
459+
scheduleWork(cbC, {timeout: 1});
460+
console.log('scheduled cbC');
461+
scheduleWork(cbD, {timeout: 1}); // will throw error
462+
console.log('scheduled cbD');
463+
scheduleWork(cbE, {timeout: 1});
464+
console.log('scheduled cbE');
465+
};
290466
}
291467
</script type="text/babel">
292468
</body>

‎packages/react-scheduler/src/ReactScheduler.js‎

Lines changed: 63 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -129,6 +129,33 @@ if (!ExecutionEnvironment.canUseDOM) {
129129
},
130130
};
131131

132+
/**
133+
* Handles the case where a callback errors:
134+
* - don't catch the error, because this changes debugging behavior
135+
* - do start a new postMessage callback, to call any remaining callbacks,
136+
* - but only if there is an error, so there is not extra overhead.
137+
*/
138+
const callUnsafely = function(
139+
callbackConfig: CallbackConfigType,
140+
arg: Deadline,
141+
) {
142+
const callback = callbackConfig.scheduledCallback;
143+
let finishedCalling = false;
144+
try {
145+
callback(arg);
146+
finishedCalling = true;
147+
} finally {
148+
// always remove it from linked list
149+
cancelScheduledWork(callbackConfig);
150+
151+
if (!finishedCalling) {
152+
// an error must have been thrown
153+
isIdleScheduled = true;
154+
window.postMessage(messageKey, '*');
155+
}
156+
}
157+
};
158+
132159
/**
133160
* Checks for timed out callbacks, runs them, and then checks again to see if
134161
* any more have timed out.
@@ -152,32 +179,42 @@ if (!ExecutionEnvironment.canUseDOM) {
152179
// We know that none of them have timed out yet.
153180
return;
154181
}
155-
nextSoonestTimeoutTime = -1; // we will reset it below
156-
157-
// keep checking until we don't find any more timed out callbacks
158-
frameDeadlineObject.didTimeout = true;
182+
// NOTE: we intentionally wait to update the nextSoonestTimeoutTime until
183+
// after successfully calling any timed out callbacks.
184+
// If a timed out callback throws an error, we could get stuck in a state
185+
// where the nextSoonestTimeoutTime was set wrong.
186+
let updatedNextSoonestTimeoutTime = -1; // we will update nextSoonestTimeoutTime below
187+
const timedOutCallbacks = [];
188+
189+
// iterate once to find timed out callbacks and find nextSoonestTimeoutTime
159190
let currentCallbackConfig = headOfPendingCallbacksLinkedList;
160191
while (currentCallbackConfig !== null) {
161192
const timeoutTime = currentCallbackConfig.timeoutTime;
162193
if (timeoutTime !== -1 && timeoutTime <= currentTime) {
163194
// it has timed out!
164-
// call it
165-
const callback = currentCallbackConfig.scheduledCallback;
166-
// TODO: error handling
167-
callback(frameDeadlineObject);
168-
// remove it from linked list
169-
cancelScheduledWork(currentCallbackConfig);
195+
timedOutCallbacks.push(currentCallbackConfig);
170196
} else {
171197
if (
172198
timeoutTime !== -1 &&
173-
(nextSoonestTimeoutTime === -1 ||
174-
timeoutTime < nextSoonestTimeoutTime)
199+
(updatedNextSoonestTimeoutTime === -1 ||
200+
timeoutTime < updatedNextSoonestTimeoutTime)
175201
) {
176-
nextSoonestTimeoutTime = timeoutTime;
202+
updatedNextSoonestTimeoutTime = timeoutTime;
177203
}
178204
}
179205
currentCallbackConfig = currentCallbackConfig.next;
180206
}
207+
208+
if (timedOutCallbacks.length > 0) {
209+
frameDeadlineObject.didTimeout = true;
210+
for (let i = 0, len = timedOutCallbacks.length; i < len; i++) {
211+
callUnsafely(timedOutCallbacks[i], frameDeadlineObject);
212+
}
213+
}
214+
215+
// NOTE: we intentionally wait to update the nextSoonestTimeoutTime until
216+
// after successfully calling any timed out callbacks.
217+
nextSoonestTimeoutTime = updatedNextSoonestTimeoutTime;
181218
};
182219

183220
// We use the postMessage trick to defer idle work until after the repaint.
@@ -206,20 +243,9 @@ if (!ExecutionEnvironment.canUseDOM) {
206243
headOfPendingCallbacksLinkedList !== null
207244
) {
208245
const latestCallbackConfig = headOfPendingCallbacksLinkedList;
209-
// move head of list to next callback
210-
headOfPendingCallbacksLinkedList = latestCallbackConfig.next;
211-
if (headOfPendingCallbacksLinkedList !== null) {
212-
headOfPendingCallbacksLinkedList.prev = null;
213-
} else {
214-
// if headOfPendingCallbacksLinkedList is null,
215-
// then the list must be empty.
216-
// make sure we set the tail to null as well.
217-
tailOfPendingCallbacksLinkedList = null;
218-
}
219246
frameDeadlineObject.didTimeout = false;
220-
const latestCallback = latestCallbackConfig.scheduledCallback;
221-
// TODO: before using this outside of React we need to add error handling
222-
latestCallback(frameDeadlineObject);
247+
// callUnsafely will remove it from the head of the linked list
248+
callUnsafely(latestCallbackConfig, frameDeadlineObject);
223249
currentTime = now();
224250
}
225251
if (headOfPendingCallbacksLinkedList !== null) {
@@ -315,6 +341,15 @@ if (!ExecutionEnvironment.canUseDOM) {
315341
cancelScheduledWork = function(
316342
callbackConfig: CallbackIdType /* CallbackConfigType */,
317343
) {
344+
if (
345+
callbackConfig.prev === null &&
346+
headOfPendingCallbacksLinkedList !== callbackConfig
347+
) {
348+
// this callbackConfig has already been cancelled.
349+
// cancelScheduledWork should be idempotent, a no-op after first call.
350+
return;
351+
}
352+
318353
/**
319354
* There are four possible cases:
320355
* - Head/nodeToRemove/Tail -> null
@@ -331,6 +366,8 @@ if (!ExecutionEnvironment.canUseDOM) {
331366
*/
332367
const next = callbackConfig.next;
333368
const prev = callbackConfig.prev;
369+
callbackConfig.next = null;
370+
callbackConfig.prev = null;
334371
if (next !== null) {
335372
// we have a next
336373

0 commit comments

Comments
 (0)