@samitouri / QOS-React-2
Code Commits Issues Pulls Sessions CI/CD
main
main
js 529 lines 16 KB
Raw
1 /**
2 * Copyright (c) Meta Platforms, Inc. and affiliates.
3 *
4 * This source code is licensed under the MIT license found in the
5 * LICENSE file in the root directory of this source tree.
6 *
7 * @emails react-core
8 * @jest-environment node
9 */
10
11 /* eslint-disable no-for-of-loops/no-for-of-loops */
12
13 'use strict';
14
15 let Scheduler;
16 // let runWithPriority;
17 let ImmediatePriority;
18 let UserBlockingPriority;
19 let NormalPriority;
20 let LowPriority;
21 let IdlePriority;
22 let scheduleCallback;
23 let cancelCallback;
24 // let wrapCallback;
25 // let getCurrentPriorityLevel;
26 // let shouldYield;
27 let waitForAll;
28 let waitFor;
29 let waitForThrow;
30
31 function priorityLevelToString(priorityLevel) {
32 switch (priorityLevel) {
33 case ImmediatePriority:
34 return 'Immediate';
35 case UserBlockingPriority:
36 return 'User-blocking';
37 case NormalPriority:
38 return 'Normal';
39 case LowPriority:
40 return 'Low';
41 case IdlePriority:
42 return 'Idle';
43 default:
44 return null;
45 }
46 }
47
48 describe('Scheduler', () => {
49 const {enableProfiling} = require('scheduler/src/SchedulerFeatureFlags');
50 if (!enableProfiling) {
51 // The tests in this suite only apply when profiling is on
52 it('profiling APIs are not available', () => {
53 Scheduler = require('scheduler');
54 expect(Scheduler.unstable_Profiling).toBe(null);
55 });
56 return;
57 }
58
59 beforeEach(() => {
60 jest.resetModules();
61 jest.mock('scheduler', () => require('scheduler/unstable_mock'));
62 Scheduler = require('scheduler');
63
64 // runWithPriority = Scheduler.unstable_runWithPriority;
65 ImmediatePriority = Scheduler.unstable_ImmediatePriority;
66 UserBlockingPriority = Scheduler.unstable_UserBlockingPriority;
67 NormalPriority = Scheduler.unstable_NormalPriority;
68 LowPriority = Scheduler.unstable_LowPriority;
69 IdlePriority = Scheduler.unstable_IdlePriority;
70 scheduleCallback = Scheduler.unstable_scheduleCallback;
71 cancelCallback = Scheduler.unstable_cancelCallback;
72 // wrapCallback = Scheduler.unstable_wrapCallback;
73 // getCurrentPriorityLevel = Scheduler.unstable_getCurrentPriorityLevel;
74 // shouldYield = Scheduler.unstable_shouldYield;
75
76 const InternalTestUtils = require('internal-test-utils');
77 waitForAll = InternalTestUtils.waitForAll;
78 waitFor = InternalTestUtils.waitFor;
79 waitForThrow = InternalTestUtils.waitForThrow;
80 });
81
82 const TaskStartEvent = 1;
83 const TaskCompleteEvent = 2;
84 const TaskErrorEvent = 3;
85 const TaskCancelEvent = 4;
86 const TaskRunEvent = 5;
87 const TaskYieldEvent = 6;
88 const SchedulerSuspendEvent = 7;
89 const SchedulerResumeEvent = 8;
90
91 function stopProfilingAndPrintFlamegraph() {
92 const eventBuffer =
93 Scheduler.unstable_Profiling.stopLoggingProfilingEvents();
94 if (eventBuffer === null) {
95 return '(empty profile)';
96 }
97
98 const eventLog = new Int32Array(eventBuffer);
99
100 const tasks = new Map();
101 const mainThreadRuns = [];
102
103 let isSuspended = true;
104 let i = 0;
105 processLog: while (i < eventLog.length) {
106 const instruction = eventLog[i];
107 const time = eventLog[i + 1];
108 switch (instruction) {
109 case 0: {
110 break processLog;
111 }
112 case TaskStartEvent: {
113 const taskId = eventLog[i + 2];
114 const priorityLevel = eventLog[i + 3];
115 const task = {
116 id: taskId,
117 priorityLevel,
118 label: null,
119 start: time,
120 end: -1,
121 exitStatus: null,
122 runs: [],
123 };
124 tasks.set(taskId, task);
125 i += 4;
126 break;
127 }
128 case TaskCompleteEvent: {
129 if (isSuspended) {
130 throw Error('Task cannot Complete outside the work loop.');
131 }
132 const taskId = eventLog[i + 2];
133 const task = tasks.get(taskId);
134 if (task === undefined) {
135 throw Error('Task does not exist.');
136 }
137 task.end = time;
138 task.exitStatus = 'completed';
139 i += 3;
140 break;
141 }
142 case TaskErrorEvent: {
143 if (isSuspended) {
144 throw Error('Task cannot Error outside the work loop.');
145 }
146 const taskId = eventLog[i + 2];
147 const task = tasks.get(taskId);
148 if (task === undefined) {
149 throw Error('Task does not exist.');
150 }
151 task.end = time;
152 task.exitStatus = 'errored';
153 i += 3;
154 break;
155 }
156 case TaskCancelEvent: {
157 const taskId = eventLog[i + 2];
158 const task = tasks.get(taskId);
159 if (task === undefined) {
160 throw Error('Task does not exist.');
161 }
162 task.end = time;
163 task.exitStatus = 'canceled';
164 i += 3;
165 break;
166 }
167 case TaskRunEvent:
168 case TaskYieldEvent: {
169 if (isSuspended) {
170 throw Error('Task cannot Run or Yield outside the work loop.');
171 }
172 const taskId = eventLog[i + 2];
173 const task = tasks.get(taskId);
174 if (task === undefined) {
175 throw Error('Task does not exist.');
176 }
177 task.runs.push(time);
178 i += 4;
179 break;
180 }
181 case SchedulerSuspendEvent: {
182 if (isSuspended) {
183 throw Error('Scheduler cannot Suspend outside the work loop.');
184 }
185 isSuspended = true;
186 mainThreadRuns.push(time);
187 i += 3;
188 break;
189 }
190 case SchedulerResumeEvent: {
191 if (!isSuspended) {
192 throw Error('Scheduler cannot Resume inside the work loop.');
193 }
194 isSuspended = false;
195 mainThreadRuns.push(time);
196 i += 3;
197 break;
198 }
199 default: {
200 throw Error('Unknown instruction type: ' + instruction);
201 }
202 }
203 }
204
205 // Now we can render the tasks as a flamegraph.
206 const labelColumnWidth = 30;
207 // Scheduler event times are in microseconds
208 const microsecondsPerChar = 50000;
209
210 let result = '';
211
212 const mainThreadLabelColumn = '!!! Main thread ';
213 let mainThreadTimelineColumn = '';
214 let isMainThreadBusy = true;
215 for (const time of mainThreadRuns) {
216 const index = time / microsecondsPerChar;
217 mainThreadTimelineColumn += (isMainThreadBusy ? '█' : '░').repeat(
218 index - mainThreadTimelineColumn.length,
219 );
220 isMainThreadBusy = !isMainThreadBusy;
221 }
222 result += `${mainThreadLabelColumn}│${mainThreadTimelineColumn}\n`;
223
224 const tasksByPriority = Array.from(tasks.values()).sort(
225 (t1, t2) => t1.priorityLevel - t2.priorityLevel,
226 );
227
228 for (const task of tasksByPriority) {
229 let label = task.label;
230 if (label === undefined) {
231 label = 'Task';
232 }
233 let labelColumn = `Task ${task.id} [${priorityLevelToString(
234 task.priorityLevel,
235 )}]`;
236 labelColumn += ' '.repeat(labelColumnWidth - labelColumn.length - 1);
237
238 // Add empty space up until the start mark
239 let timelineColumn = ' '.repeat(task.start / microsecondsPerChar);
240
241 let isRunning = false;
242 for (const time of task.runs) {
243 const index = time / microsecondsPerChar;
244 timelineColumn += (isRunning ? '█' : '░').repeat(
245 index - timelineColumn.length,
246 );
247 isRunning = !isRunning;
248 }
249
250 const endIndex = task.end / microsecondsPerChar;
251 timelineColumn += (isRunning ? '█' : '░').repeat(
252 endIndex - timelineColumn.length,
253 );
254
255 if (task.exitStatus !== 'completed') {
256 timelineColumn += `🡐 ${task.exitStatus}`;
257 }
258
259 result += `${labelColumn}│${timelineColumn}\n`;
260 }
261
262 return '\n' + result;
263 }
264
265 it('creates a basic flamegraph', async () => {
266 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
267
268 Scheduler.unstable_advanceTime(100);
269 scheduleCallback(
270 NormalPriority,
271 () => {
272 Scheduler.unstable_advanceTime(300);
273 Scheduler.log('Yield 1');
274 scheduleCallback(
275 UserBlockingPriority,
276 () => {
277 Scheduler.log('Yield 2');
278 Scheduler.unstable_advanceTime(300);
279 },
280 {label: 'Bar'},
281 );
282 Scheduler.unstable_advanceTime(100);
283 Scheduler.log('Yield 3');
284 return () => {
285 Scheduler.log('Yield 4');
286 Scheduler.unstable_advanceTime(300);
287 };
288 },
289 {label: 'Foo'},
290 );
291 await waitFor(['Yield 1', 'Yield 3']);
292 Scheduler.unstable_advanceTime(100);
293 await waitForAll(['Yield 2', 'Yield 4']);
294
295 expect(stopProfilingAndPrintFlamegraph()).toEqual(
296 `
297 !!! Main thread │██░░░░░░░░██░░░░░░░░░░░░
298 Task 2 [User-blocking] │ ░░░░██████
299 Task 1 [Normal] │ ████████░░░░░░░░██████
300 `,
301 );
302 });
303
304 it('marks when a task is canceled', async () => {
305 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
306
307 const task = scheduleCallback(NormalPriority, () => {
308 Scheduler.log('Yield 1');
309 Scheduler.unstable_advanceTime(300);
310 Scheduler.log('Yield 2');
311 return () => {
312 Scheduler.log('Continuation');
313 Scheduler.unstable_advanceTime(200);
314 };
315 });
316
317 await waitFor(['Yield 1', 'Yield 2']);
318 Scheduler.unstable_advanceTime(100);
319
320 cancelCallback(task);
321
322 Scheduler.unstable_advanceTime(1000);
323 await waitForAll([]);
324 expect(stopProfilingAndPrintFlamegraph()).toEqual(
325 `
326 !!! Main thread │░░░░░░██████████████████████
327 Task 1 [Normal] │██████░░🡐 canceled
328 `,
329 );
330 });
331
332 it('marks when a task errors', async () => {
333 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
334
335 scheduleCallback(NormalPriority, () => {
336 Scheduler.unstable_advanceTime(300);
337 throw Error('Oops');
338 });
339
340 await waitForThrow('Oops');
341 Scheduler.unstable_advanceTime(100);
342
343 Scheduler.unstable_advanceTime(1000);
344 await waitForAll([]);
345 expect(stopProfilingAndPrintFlamegraph()).toEqual(
346 `
347 !!! Main thread │░░░░░░██████████████████████
348 Task 1 [Normal] │██████🡐 errored
349 `,
350 );
351 });
352
353 it('marks when multiple tasks are canceled', async () => {
354 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
355
356 const task1 = scheduleCallback(NormalPriority, () => {
357 Scheduler.log('Yield 1');
358 Scheduler.unstable_advanceTime(300);
359 Scheduler.log('Yield 2');
360 return () => {
361 Scheduler.log('Continuation');
362 Scheduler.unstable_advanceTime(200);
363 };
364 });
365 const task2 = scheduleCallback(NormalPriority, () => {
366 Scheduler.log('Yield 3');
367 Scheduler.unstable_advanceTime(300);
368 Scheduler.log('Yield 4');
369 return () => {
370 Scheduler.log('Continuation');
371 Scheduler.unstable_advanceTime(200);
372 };
373 });
374
375 await waitFor(['Yield 1', 'Yield 2']);
376 Scheduler.unstable_advanceTime(100);
377
378 cancelCallback(task1);
379 cancelCallback(task2);
380
381 // Advance more time. This should not affect the size of the main
382 // thread row, since the Scheduler queue is empty.
383 Scheduler.unstable_advanceTime(1000);
384 await waitForAll([]);
385
386 // The main thread row should end when the callback is cancelled.
387 expect(stopProfilingAndPrintFlamegraph()).toEqual(
388 `
389 !!! Main thread │░░░░░░██████████████████████
390 Task 1 [Normal] │██████░░🡐 canceled
391 Task 2 [Normal] │░░░░░░░░🡐 canceled
392 `,
393 );
394 });
395
396 it('handles cancelling a task that already finished', async () => {
397 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
398
399 const task = scheduleCallback(NormalPriority, () => {
400 Scheduler.log('A');
401 Scheduler.unstable_advanceTime(1000);
402 });
403 await waitForAll(['A']);
404 cancelCallback(task);
405 expect(stopProfilingAndPrintFlamegraph()).toEqual(
406 `
407 !!! Main thread │░░░░░░░░░░░░░░░░░░░░
408 Task 1 [Normal] │████████████████████
409 `,
410 );
411 });
412
413 it('handles cancelling a task multiple times', async () => {
414 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
415
416 scheduleCallback(
417 NormalPriority,
418 () => {
419 Scheduler.log('A');
420 Scheduler.unstable_advanceTime(1000);
421 },
422 {label: 'A'},
423 );
424 Scheduler.unstable_advanceTime(200);
425 const task = scheduleCallback(
426 NormalPriority,
427 () => {
428 Scheduler.log('B');
429 Scheduler.unstable_advanceTime(1000);
430 },
431 {label: 'B'},
432 );
433 Scheduler.unstable_advanceTime(400);
434 cancelCallback(task);
435 cancelCallback(task);
436 cancelCallback(task);
437 await waitForAll(['A']);
438 expect(stopProfilingAndPrintFlamegraph()).toEqual(
439 `
440 !!! Main thread │████████████░░░░░░░░░░░░░░░░░░░░
441 Task 1 [Normal] │░░░░░░░░░░░░████████████████████
442 Task 2 [Normal] │ ░░░░░░░░🡐 canceled
443 `,
444 );
445 });
446
447 it('handles delayed tasks', async () => {
448 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
449 scheduleCallback(
450 NormalPriority,
451 () => {
452 Scheduler.unstable_advanceTime(1000);
453 Scheduler.log('A');
454 },
455 {
456 delay: 1000,
457 },
458 );
459 await waitForAll([]);
460
461 Scheduler.unstable_advanceTime(1000);
462
463 await waitForAll(['A']);
464
465 expect(stopProfilingAndPrintFlamegraph()).toEqual(
466 `
467 !!! Main thread │████████████████████░░░░░░░░░░░░░░░░░░░░
468 Task 1 [Normal] │ ████████████████████
469 `,
470 );
471 });
472
473 it('handles cancelling a delayed task', async () => {
474 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
475 const task = scheduleCallback(NormalPriority, () => Scheduler.log('A'), {
476 delay: 1000,
477 });
478 cancelCallback(task);
479 await waitForAll([]);
480 expect(stopProfilingAndPrintFlamegraph()).toEqual(
481 `
482 !!! Main thread │
483 `,
484 );
485 });
486
487 it('automatically stops profiling and warns if event log gets too big', async () => {
488 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
489
490 spyOnDevAndProd(console, 'error').mockImplementation(() => {});
491
492 // Increase infinite loop guard limit
493 const originalMaxIterations = global.__MAX_ITERATIONS__;
494 global.__MAX_ITERATIONS__ = 120000;
495
496 let taskId = 1;
497 while (console.error.mock.calls.length === 0) {
498 taskId++;
499 const task = scheduleCallback(NormalPriority, () => {});
500 cancelCallback(task);
501 Scheduler.unstable_flushAll();
502 }
503
504 expect(console.error).toHaveBeenCalledTimes(1);
505 expect(console.error.mock.calls[0][0]).toBe(
506 "Scheduler Profiling: Event log exceeded maximum size. Don't forget " +
507 'to call `stopLoggingProfilingEvents()`.',
508 );
509
510 // Should automatically clear profile
511 expect(stopProfilingAndPrintFlamegraph()).toEqual('(empty profile)');
512
513 // Test that we can start a new profile later
514 Scheduler.unstable_Profiling.startLoggingProfilingEvents();
515 scheduleCallback(NormalPriority, () => {
516 Scheduler.unstable_advanceTime(1000);
517 });
518 await waitForAll([]);
519
520 // Note: The exact task id is not super important. That just how many tasks
521 // it happens to take before the array is resized.
522 expect(stopProfilingAndPrintFlamegraph()).toEqual(`
523 !!! Main thread │░░░░░░░░░░░░░░░░░░░░
524 Task ${taskId} [Normal] │████████████████████
525 `);
526
527 global.__MAX_ITERATIONS__ = originalMaxIterations;
528 });
529 });