Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add user timing marks for scheduling profiler tool #11

Closed
wants to merge 39 commits into from
Closed
Show file tree
Hide file tree
Changes from 7 commits
Commits
Show all changes
39 commits
Select commit Hold shift + click to select a range
ec17600
Add enableSchedulingProfiler feature flag
taneliang Jun 17, 2020
3e5f821
Add mark utility functions
taneliang Jun 18, 2020
ed384aa
Rename enableSchedulingProfiler -> enableSchedulingProfiling
taneliang Jun 18, 2020
c5c6bd4
Add all marks except commits and effects
taneliang Jun 18, 2020
054781d
Reduce performance API requirements
taneliang Jun 18, 2020
5fb8525
Add tests for SchedulingProfiling
taneliang Jun 18, 2020
eec07b7
Comment out tests covering Kartik's code
taneliang Jun 18, 2020
560c396
Add tests to cover markRenderAbandoned and fix passive effect marks
taneliang Jun 19, 2020
414866d
Comment out tests covering Kartik's code
taneliang Jun 19, 2020
791dae7
Add remaining user timing marks
kartikcho Jun 19, 2020
63580cd
Re add tests
kartikcho Jun 19, 2020
30d5f7e
Add missing markCommitStopped calls, relocated some mark* calls for c…
taneliang Jun 19, 2020
68d6430
Replace binary lane bitmask with decimal for compactness
taneliang Jun 23, 2020
7ce6931
Reduce test strictness to fix test-prod
taneliang Jun 23, 2020
418d02a
Remove TODO for markRenderScheduled
taneliang Jun 23, 2020
4f6846a
Merge branch 'master' into eliang/scheduling-profiler-marks
taneliang Jun 26, 2020
d3d0459
Add markCommitStarted call to new logCommitStarted location
taneliang Jun 26, 2020
4101fd7
Remove markRenderAbandoned
taneliang Jun 26, 2020
9f64b78
Merge branch 'master' into eliang/scheduling-profiler-marks
taneliang Jun 29, 2020
36e79f4
Merge branch 'master' into eliang/scheduling-profiler-marks
taneliang Jul 1, 2020
1628476
Rename enableSchedulingProfiling -> enableSchedulingProfiler
taneliang Jul 2, 2020
660559d
Remove component name from markRenderScheduled
taneliang Jul 2, 2020
501c4b9
Remove componentName arguments
taneliang Jul 2, 2020
b716ad0
Reorder schedule update info
taneliang Jul 2, 2020
06b038d
Remove component stack from schedule render marks
taneliang Jul 2, 2020
c014d6e
Add missing Wakeable import
taneliang Jul 2, 2020
8fd53ea
Implement component stack cache
taneliang Jul 2, 2020
142d5c1
Add __PROFILE__ to enableDebugTracing
kartikcho Jul 2, 2020
3c477c4
Destructure enableDebugTracing and enableSchedulingProfiling to dynam…
kartikcho Jul 2, 2020
1b12ee5
Rename SchedulingProfiling -> SchedulingProfiler
taneliang Jul 2, 2020
f42b0a0
Add __PROFILE__ to enableSchedulingProfiler instead
taneliang Jul 2, 2020
6a23d18
Use cached fiber.alternate component stacks if present
taneliang Jul 2, 2020
1c5997e
Remove stray redundant empty string fallbacks
taneliang Jul 2, 2020
8e529f4
Reorder --suspense-* mark info
taneliang Jul 2, 2020
4b51d6d
Use single quotes for --commit-stop
taneliang Jul 2, 2020
c104dc0
Move TODO back to getStackByFiberInDevAndProd callsite
taneliang Jul 3, 2020
ca75690
Remove unused fiber markRenderScheduled param
taneliang Jul 8, 2020
d2c090e
Merge branch 'master' into eliang/scheduling-profiler-marks
taneliang Jul 8, 2020
b766b17
Remove @gate experimental condition
taneliang Jul 8, 2020
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
20 changes: 20 additions & 0 deletions packages/react-reconciler/src/ReactFiberClassComponent.old.js
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import {
debugRenderPhaseSideEffectsForStrictMode,
disableLegacyContext,
enableDebugTracing,
enableSchedulingProfiling,
warnAboutDeprecatedLifecycles,
} from 'shared/ReactFeatureFlags';
import ReactStrictModeWarnings from './ReactStrictModeWarnings.old';
Expand Down Expand Up @@ -59,6 +60,10 @@ import {requestCurrentSuspenseConfig} from './ReactFiberSuspenseConfig';
import {logForceUpdateScheduled, logStateUpdateScheduled} from './DebugTracing';

import {disableLogs, reenableLogs} from 'shared/ConsolePatchingDev';
import {
markForceUpdateScheduled,
markStateUpdateScheduled,
} from './SchedulingProfiling';

const fakeInternalInstance = {};
const isArray = Array.isArray;
Expand Down Expand Up @@ -214,6 +219,11 @@ const classComponentUpdater = {
}
}
}

if (enableSchedulingProfiling) {
const name = getComponentName(fiber.type) || 'Unknown';
markStateUpdateScheduled(name, fiber, lane);
}
},
enqueueReplaceState(inst, payload, callback) {
const fiber = getInstance(inst);
Expand Down Expand Up @@ -243,6 +253,11 @@ const classComponentUpdater = {
}
}
}

if (enableSchedulingProfiling) {
const name = getComponentName(fiber.type) || 'Unknown';
markStateUpdateScheduled(name, fiber, lane);
}
},
enqueueForceUpdate(inst, callback) {
const fiber = getInstance(inst);
Expand Down Expand Up @@ -271,6 +286,11 @@ const classComponentUpdater = {
}
}
}

if (enableSchedulingProfiling) {
const name = getComponentName(fiber.type) || 'Unknown';
markForceUpdateScheduled(name, fiber, lane);
}
},
};

Expand Down
7 changes: 7 additions & 0 deletions packages/react-reconciler/src/ReactFiberHooks.old.js
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import type {OpaqueIDType} from './ReactFiberHostConfig';
import ReactSharedInternals from 'shared/ReactSharedInternals';
import {
enableDebugTracing,
enableSchedulingProfiling,
enableNewReconciler,
} from 'shared/ReactFeatureFlags';

Expand Down Expand Up @@ -87,6 +88,7 @@ import {
} from './ReactMutableSource.old';
import {getIsRendering} from './ReactCurrentFiber';
import {logStateUpdateScheduled} from './DebugTracing';
import {markStateUpdateScheduled} from './SchedulingProfiling';

const {ReactCurrentDispatcher, ReactCurrentBatchConfig} = ReactSharedInternals;

Expand Down Expand Up @@ -1750,6 +1752,11 @@ function dispatchAction<S, A>(
}
}
}

if (enableSchedulingProfiling) {
const name = getComponentName(fiber.type) || 'Unknown';
markStateUpdateScheduled(name, fiber, lane);
}
}

export const ContextOnlyDispatcher: Dispatcher = {
Expand Down
12 changes: 12 additions & 0 deletions packages/react-reconciler/src/ReactFiberReconciler.old.js
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ import {
} from './ReactWorkTags';
import getComponentName from 'shared/getComponentName';
import invariant from 'shared/invariant';
import {enableSchedulingProfiling} from 'shared/ReactFeatureFlags';
import ReactSharedInternals from 'shared/ReactSharedInternals';
import {getPublicInstance} from './ReactFiberHostConfig';
import {
Expand Down Expand Up @@ -87,6 +88,7 @@ import {
setRefreshHandler,
findHostInstancesForRefresh,
} from './ReactFiberHotReloading.old';
import {markRenderScheduled} from './SchedulingProfiling';

export {registerMutableSourceForHydration} from './ReactMutableSource.new';
export {createPortal} from './ReactPortal';
Expand Down Expand Up @@ -265,6 +267,16 @@ export function updateContainer(
const suspenseConfig = requestCurrentSuspenseConfig();
const lane = requestUpdateLane(current, suspenseConfig);

// TODO: Confirm that this location and container/lane make sense
if (enableSchedulingProfiling) {
let componentName = 'Unknown';
if (ReactCurrentFiberCurrent !== null) {
componentName =
getComponentName(ReactCurrentFiberCurrent.type) || componentName;
}
markRenderScheduled(componentName, current, lane);
}

const context = getContextForSubtree(parentComponent);
if (container.context === null) {
container.context = context;
Expand Down
11 changes: 10 additions & 1 deletion packages/react-reconciler/src/ReactFiberThrow.old.js
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,10 @@ import {
} from './ReactSideEffectTags';
import {shouldCaptureSuspense} from './ReactFiberSuspenseComponent.old';
import {NoMode, BlockingMode, DebugTracingMode} from './ReactTypeOfMode';
import {enableDebugTracing} from 'shared/ReactFeatureFlags';
import {
enableDebugTracing,
enableSchedulingProfiling,
} from 'shared/ReactFeatureFlags';
import {createCapturedValue} from './ReactCapturedValue';
import {
enqueueCapturedUpdate,
Expand All @@ -55,6 +58,7 @@ import {
} from './ReactFiberWorkLoop.old';
import {logCapturedError} from './ReactFiberErrorLogger';
import {logComponentSuspended} from './DebugTracing';
import {markComponentSuspended} from './SchedulingProfiling';

import {
SyncLane,
Expand Down Expand Up @@ -200,6 +204,11 @@ function throwException(
}
}

if (enableSchedulingProfiling) {
const name = getComponentName(sourceFiber.type) || 'Unknown';
markComponentSuspended(name, sourceFiber, wakeable);
}

if ((sourceFiber.mode & BlockingMode) === NoMode) {
// Reset the memoizedState to what it was before we attempted
// to render it.
Expand Down
44 changes: 44 additions & 0 deletions packages/react-reconciler/src/ReactFiberWorkLoop.old.js
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ import {
warnAboutUnmockedScheduler,
deferRenderPhaseUpdateToNextBatch,
enableDebugTracing,
enableSchedulingProfiling,
} from 'shared/ReactFeatureFlags';
import ReactSharedInternals from 'shared/ReactSharedInternals';
import invariant from 'shared/invariant';
Expand Down Expand Up @@ -56,6 +57,18 @@ import {
logRenderStarted,
logRenderStopped,
} from './DebugTracing';
import {
markCommitStarted,
markCommitStopped,
markLayoutEffectsStarted,
markLayoutEffectsStopped,
markPassiveEffectsStarted,
markPassiveEffectsStopped,
markRenderStarted,
markRenderYielded,
markRenderStopped,
markRenderAbandoned,
} from './SchedulingProfiling';

// The scheduler is imported here *only* to detect whether it's been mocked
import * as Scheduler from 'scheduler';
Expand Down Expand Up @@ -462,6 +475,18 @@ export function scheduleUpdateOnFiber(
return null;
}

if (enableSchedulingProfiling) {
if (
workInProgressRoot !== null &&
// TODO: Confirm that this makes sense
taneliang marked this conversation as resolved.
Show resolved Hide resolved
!includesSomeLane(workInProgressRootRenderLanes, lane)
// Original criterion: expirationTime > renderExpirationTime
// Location: https://github.com/bvaughn/react/blob/root-event-marks/packages/react-reconciler/src/ReactFiberWorkLoop.js#L2846
Copy link
Member Author

@taneliang taneliang Jun 18, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jevakallio Would also appreciate if you could see if this new condition makes sense.

This code marks when a render is cancelled, and the condition replaces an expiration date-based one. I'm not too confident of my understanding of both lanes and expiration times, so this is the best I could come up with.

The marks look like they're in the correct position at least, and I don't see them in unexpected places either.

Update: the screenshots below are outdated: our bitmask is now transmitted in decimal (e.g. --render-start-512)

image

image

image

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This will detect an interruption, but it will also have false positives.

I believe a way to make it have fewer false positives would be to check that there are actually WIP lanes, e.g.

if (
  workInProgressRoot !== null &&
  workInProgressRootRenderLanes !== NoLanes &&
  !includesSomeLane(workInProgressRootRenderLanes, lane)
) {
  // ...
}

But I think this will also still have false positives during hydration. I'm actually not sure of what to do here. Maybe we should just leave this as a "TODO" entirely and we can discuss it with Andrew on the final PR.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh good catch. Checking for WIP lanes makes sense.

I know this doesn't really affect our profiler tool, but I'd love to understand the lanes architecture better: why would there be false positives during hydration?

Copy link
Collaborator

@bvaughn bvaughn Jun 25, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To be clear, I think we should remove this entirely for now. Even with the wip lanes check, I think this would report renders are being "abandoned" when they weren't. Like I said, I'm actually not sure of what to do here 😄 let's talk more about it on the final PR.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

😄 Yeah sounds good. I've removed markRenderAbandoned and this call in 4101fd7, and we can revert it if we figure out a way to do this. Thank you!

) {
markRenderAbandoned();
}
}

// TODO: requestUpdateLanePriority also reads the priority. Pass the
// priority as an argument to that function and this one.
const priorityLevel = getCurrentPriorityLevel();
Expand Down Expand Up @@ -1461,6 +1486,10 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) {
}
}

if (enableSchedulingProfiling) {
markRenderStarted(lanes);
}

do {
try {
workLoopSync();
Expand Down Expand Up @@ -1492,6 +1521,10 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) {
}
}

if (enableSchedulingProfiling) {
markRenderStopped();
}

// Set this to null to indicate there's no in-progress render.
workInProgressRoot = null;
workInProgressRootRenderLanes = NoLanes;
Expand Down Expand Up @@ -1528,6 +1561,10 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) {
}
}

if (enableSchedulingProfiling) {
markRenderStarted(lanes);
}

do {
try {
workLoopConcurrent();
Expand All @@ -1553,9 +1590,16 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) {
// Check if the tree has completed.
if (workInProgress !== null) {
// Still work remaining.
if (enableSchedulingProfiling) {
markRenderYielded();
}
return RootIncomplete;
} else {
// Completed the tree.
if (enableSchedulingProfiling) {
markRenderStopped();
}

// Set this to null to indicate there's no in-progress render.
workInProgressRoot = null;
workInProgressRootRenderLanes = NoLanes;
Expand Down