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 #19223

Merged

Conversation

@taneliang
Copy link
Contributor

taneliang commented Jul 1, 2020

Summary

This PR adds User Timing marks at key points in the reconciler's execution.

The marks are used by this new concurrent mode profiler tool that @kartik918 and I are building under @bvaughn and @jevakallio's guidance.

image

High level breakdown of this PR:

  • Add a enableSchedulingProfiling feature flag.
  • Add functions that call User Timing APIs to a new SchedulingProfiling.js file. The file follows DebugTracing's structure.
  • Add user timing marks to places where DebugTracing logs.
  • Add user timing marks to most other places where @bvaughn's original draft DebugTracing branch marks.
  • Tests added

More context (and discussions with @bvaughn) available at our internal PR MLH-Fellowship#11 and issue MLH-Fellowship#5.

Similar to DebugTracing, we've only added scheduling profiling calls to the old reconciler fork.

Test Plan

  • yarn test
  • yarn test-prod
  • yarn lint
  • yarn flow dom
  • This test app that I created has a custom build of React with enableSchedulingProfiling and enableDebugTracing set to true. When profiled with Firefox Profiler, the marks are visible in the output.
    image
taneliang and others added 20 commits Jun 17, 2020
Combines those defined in both DebugTracing.js and
[this branch](master...bvaughn:root-event-marksdiff-9c522844edfceec1e53144f429f7103fR123).
…onsistency, add blank lines
@sizebot
Copy link

sizebot commented Jul 1, 2020

Details of bundled changes.

Comparing: b85b476...b766b17

react-art

File Filesize Diff Gzip Diff Prev Size Current Size Prev Gzip Current Gzip ENV
ReactART-prod.js 🔺+1.9% 🔺+2.1% 247.58 KB 252.36 KB 43.77 KB 44.7 KB FB_WWW_PROD
react-art.development.js -0.0% -0.0% 666.97 KB 666.85 KB 142.03 KB 141.98 KB UMD_DEV
react-art.development.js -0.0% -0.0% 569.36 KB 569.24 KB 124.24 KB 124.21 KB NODE_DEV
react-art.production.min.js 0.0% -0.0% 74.53 KB 74.53 KB 23.06 KB 23.05 KB NODE_PROD
ReactART-dev.js +1.1% +0.7% 630.72 KB 637.62 KB 134.4 KB 135.31 KB FB_WWW_DEV

react-dom

File Filesize Diff Gzip Diff Prev Size Current Size Prev Gzip Current Gzip ENV
react-dom.development.js -0.0% -0.0% 876.52 KB 876.4 KB 200.86 KB 200.83 KB NODE_DEV
react-dom-server.node.development.js 0.0% -0.0% 136.84 KB 136.84 KB 36.39 KB 36.39 KB NODE_DEV
ReactDOMForked-profiling.js 0.0% -0.0% 411.74 KB 411.74 KB 76.02 KB 76.02 KB FB_WWW_PROFILING
react-dom-server.browser.development.js 0.0% -0.0% 142.92 KB 142.92 KB 36.59 KB 36.59 KB UMD_DEV
ReactDOMTesting-dev.js -0.0% -0.0% 976.02 KB 975.9 KB 218.46 KB 218.42 KB FB_WWW_DEV
react-dom-test-utils.development.js 0.0% -0.0% 51.13 KB 51.13 KB 14.9 KB 14.89 KB NODE_DEV
ReactTestUtils-dev.js +0.3% +0.2% 45.12 KB 45.25 KB 12.71 KB 12.73 KB FB_WWW_DEV
react-dom.development.js -0.0% -0.0% 920.89 KB 920.77 KB 203.23 KB 203.2 KB UMD_DEV
react-dom.production.min.js 0.0% -0.0% 118.44 KB 118.44 KB 38.82 KB 38.82 KB UMD_PROD
react-dom.profiling.min.js 0.0% -0.0% 122.34 KB 122.34 KB 40.02 KB 40.02 KB UMD_PROFILING
ReactDOMForked-dev.js 0.0% 0.0% 994.44 KB 994.58 KB 221.86 KB 221.89 KB FB_WWW_DEV
ReactDOM-dev.js +0.7% +0.4% 1001.6 KB 1008.5 KB 223.21 KB 224.14 KB FB_WWW_DEV
ReactDOM-prod.js 🔺+1.2% 🔺+1.3% 401.34 KB 406.08 KB 74.27 KB 75.24 KB FB_WWW_PROD
ReactDOM-profiling.js +1.2% +1.3% 411.94 KB 416.68 KB 76.04 KB 77.04 KB FB_WWW_PROFILING
ReactDOMServer-dev.js +0.1% +0.1% 146.72 KB 146.85 KB 37.31 KB 37.34 KB FB_WWW_DEV

Size changes (stable)

Generated by 🚫 dangerJS against b766b17

@sizebot
Copy link

sizebot commented Jul 1, 2020

Details of bundled changes.

Comparing: b85b476...b766b17

react-art

File Filesize Diff Gzip Diff Prev Size Current Size Prev Gzip Current Gzip ENV
ReactART-prod.js 🔺+2.0% 🔺+2.3% 240.44 KB 245.22 KB 42.48 KB 43.44 KB FB_WWW_PROD
react-art.development.js -0.0% -0.0% 689.13 KB 689.01 KB 146.1 KB 146.08 KB UMD_DEV
react-art.production.min.js 0.0% -0.0% 112.52 KB 112.52 KB 34.82 KB 34.82 KB UMD_PROD
react-art.development.js -0.0% -0.0% 590.61 KB 590.49 KB 128.31 KB 128.27 KB NODE_DEV
react-art.production.min.js 0.0% 0.0% 77.42 KB 77.42 KB 23.93 KB 23.93 KB NODE_PROD
ReactART-dev.js +1.1% +0.7% 620.71 KB 627.6 KB 132.36 KB 133.27 KB FB_WWW_DEV

react-dom

File Filesize Diff Gzip Diff Prev Size Current Size Prev Gzip Current Gzip ENV
react-dom.development.js -0.0% -0.0% 908.83 KB 908.71 KB 206.68 KB 206.65 KB NODE_DEV
react-dom-server.node.development.js 0.0% -0.0% 138.35 KB 138.35 KB 36.59 KB 36.59 KB NODE_DEV
react-dom.production.min.js 0.0% -0.0% 123.26 KB 123.26 KB 39.54 KB 39.54 KB NODE_PROD
react-dom-server.browser.development.js 0.0% -0.0% 144.51 KB 144.51 KB 36.79 KB 36.79 KB UMD_DEV
react-dom-server.node.production.min.js 0.0% -0.0% 20.71 KB 20.71 KB 7.67 KB 7.67 KB NODE_PROD
ReactDOMTesting-dev.js -0.0% -0.0% 947.98 KB 947.86 KB 212.57 KB 212.53 KB FB_WWW_DEV
react-dom-test-utils.development.js 0.0% -0.0% 51.15 KB 51.15 KB 14.9 KB 14.9 KB NODE_DEV
react-dom-unstable-fizz.node.production.min.js 0.0% -0.3% 1.17 KB 1.17 KB 668 B 666 B NODE_PROD
react-dom-unstable-fizz.browser.production.min.js 0.0% -0.1% 1.2 KB 1.2 KB 707 B 706 B UMD_PROD
ReactTestUtils-dev.js +0.3% +0.2% 45.12 KB 45.25 KB 12.71 KB 12.74 KB FB_WWW_DEV
react-dom-unstable-fizz.browser.development.js 0.0% +0.1% 4.87 KB 4.87 KB 1.7 KB 1.71 KB NODE_DEV
react-dom.development.js -0.0% -0.0% 954.63 KB 954.51 KB 209.14 KB 209.11 KB UMD_DEV
react-dom.production.min.js 0.0% -0.0% 123.1 KB 123.1 KB 40.23 KB 40.23 KB UMD_PROD
react-dom.profiling.min.js 0.0% -0.0% 127.05 KB 127.05 KB 41.5 KB 41.49 KB UMD_PROFILING
ReactDOMForked-dev.js 0.0% 0.0% 968.89 KB 969.04 KB 216.62 KB 216.65 KB FB_WWW_DEV
react-dom.profiling.min.js 0.0% -0.0% 127.38 KB 127.38 KB 40.76 KB 40.76 KB NODE_PROFILING
ReactDOM-dev.js +0.7% +0.4% 976.05 KB 982.95 KB 217.95 KB 218.88 KB FB_WWW_DEV
ReactDOM-prod.js 🔺+1.2% 🔺+1.3% 390.16 KB 394.9 KB 72.74 KB 73.69 KB FB_WWW_PROD
react-dom-server.browser.development.js 0.0% -0.0% 137.08 KB 137.08 KB 36.34 KB 36.34 KB NODE_DEV
ReactDOM-profiling.js +1.2% +1.3% 400.69 KB 405.43 KB 74.48 KB 75.47 KB FB_WWW_PROFILING
ReactDOMServer-dev.js +0.1% +0.1% 142.68 KB 142.82 KB 36.31 KB 36.34 KB FB_WWW_DEV

Size changes (experimental)

Generated by 🚫 dangerJS against b766b17

if (enableSchedulingProfiling) {
if (supportsUserTiming) {
const id = getWakeableID(wakeable);
const componentStack = getStackByFiberInDevAndProd(fiber) || '';

This comment has been minimized.

Copy link
@gaearon

gaearon Jul 1, 2020

Member

Any concern that this is a bit expensive? I guess we only do that for suspended components.

This comment has been minimized.

Copy link
@gaearon

gaearon Jul 1, 2020

Member

I'm wondering if we should cache stacks for Fibers we've already seen.

Copy link
Contributor

bvaughn left a comment

Great work! 😍

I've left some thoughts and suggestions. I'm also going to tag a couple of others who may want to weigh in on this PR. 😄

Open question for @sebmarkbage: Do we still want to keep these marks (and the debug tracing feature) in the old reconciler fork only? I'm not sure if your initial concern still applies. We'll need to be careful not to wipe both features out when we later merged new->old if so.

packages/shared/ReactFeatureFlags.js Outdated Show resolved Hide resolved
packages/shared/forks/ReactFeatureFlags.www.js Outdated Show resolved Hide resolved
packages/react-reconciler/src/SchedulingProfiling.js Outdated Show resolved Hide resolved
if (supportsUserTiming) {
const id = getWakeableID(wakeable);
const componentStack = getStackByFiberInDevAndProd(fiber) || '';
// TODO (brian) Generate and store temporary ID so DevTools can match up a component stack later.

This comment has been minimized.

Copy link
@bvaughn

bvaughn Jul 1, 2020

Contributor

I like Dan's suggestion of caching component stacks (using a weak map) for fibers we've seen.

Let's move these TODO comments above the calls to getStackByFiberInDevAndProd since it relates to those calls.

The idea behind the "TODO" was that- once this functionality is more tightly integrated into DevTools- try to store a (weak) map of id-to-Fiber here, and then let DevTools compute the component stack asynchronously later, using the Fiber. I'm not sure if that is feasible though, especially with future plans to replace the alternate model.

This comment has been minimized.

Copy link
@gaearon

gaearon Jul 1, 2020

Member

Btw we have something called fiber._debugID. Maybe we can repurpose this?

This comment has been minimized.

Copy link
@bvaughn

bvaughn Jul 1, 2020

Contributor

That sounds like it could work.

I'm not sure what the implications of the alternate -> previous change would be for this idea. It was kind of a half thought out idea anyway. Just something I wanted to put some thought into later because of the cost of getting the component stack.

Component stack calculation has gotten even more expensive recently with the "native" component stacks so... I don't know how I feel about this anymore. It's definitely useful info to have, but maybe it's no longer worth the cost?

@sebmarkbage may have an opinion.

packages/react-reconciler/src/SchedulingProfiling.js Outdated Show resolved Hide resolved
packages/react-reconciler/src/SchedulingProfiling.js Outdated Show resolved Hide resolved
packages/react-reconciler/src/SchedulingProfiling.js Outdated Show resolved Hide resolved
@bvaughn bvaughn requested a review from sebmarkbage Jul 1, 2020
taneliang added 4 commits Jul 2, 2020
Resolves PR comment #19223 (comment)
Resolves PR review comment #19223 (comment)
Resolves PR review comment #19223 (comment)
Resolves PR review comment #19223 (comment)
taneliang and others added 5 commits Jul 2, 2020
Co-authored-by: Brian Vaughn <brian.david.vaughn@gmail.com>
Resolves PR review comment #19223 (comment)
@taneliang
Copy link
Contributor Author

taneliang commented Jul 2, 2020

@bvaughn all done!

@bvaughn
bvaughn approved these changes Jul 2, 2020
Copy link
Contributor

bvaughn left a comment

🥳

@@ -265,6 +267,10 @@ export function updateContainer(
const suspenseConfig = requestCurrentSuspenseConfig();
const lane = requestUpdateLane(current, suspenseConfig);

if (enableSchedulingProfiler) {
markRenderScheduled(current, lane);

This comment has been minimized.

Copy link
@bvaughn

bvaughn Jul 8, 2020

Contributor

Sorry I missed this earlier, but doing a final review before merging and noticed the current param is still being passed (but not used). Can we remove it?

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Looks like we also need to rebase on master one more time and resolve conflicts in a few of the feature flag files. Then I'll merge!

taneliang added 2 commits Jul 8, 2020
@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Not sure why off the top of my head, but the "merge master" commit seems to be causing tests to fail.

Maybe you could undo that commit, and do a rebase instead? That would make it easier to read since d2c090e has a lot of random changes in it.

It's weird though b'c I can't reproduce the error locally.

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Let me kick CI to re-run just in case.

@taneliang
Copy link
Contributor Author

taneliang commented Jul 8, 2020

This is really strange, because I can repro this locally with yarn test --release-channel=stable SchedulingProfiler, and I can also repro this with the earlier commits in this PR even though I'm pretty sure CI was passing at that time.

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Ah, good to note. Sounds like a feature flag problem them. Let me look again.

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Try changing all of your @gate expressions to remove the experimental condition.

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Nice! Great work.

@taneliang
Copy link
Contributor Author

taneliang commented Jul 8, 2020

Thanks, that did it. Interesting though, why was CI passing in the previous commits, since the CI scripts before the last merge should have also run the tests in non-experimental release channels 🤔

@bvaughn bvaughn merged commit 40cddfe into facebook:master Jul 8, 2020
32 checks passed
32 checks passed
Facebook CLA Check Contributor License Agreement is valid!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_build Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_lint_build Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_build Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_build_prod Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_dom_fixtures Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_persistent Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_prod Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_prod_www Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_prod_www_variant Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_www Your tests passed on CircleCI!
Details
ci/circleci: RELEASE_CHANNEL_stable_yarn_test_www_variant Your tests passed on CircleCI!
Details
ci/circleci: process_artifacts Your tests passed on CircleCI!
Details
ci/circleci: process_artifacts_experimental Your tests passed on CircleCI!
Details
ci/circleci: setup Your tests passed on CircleCI!
Details
ci/circleci: sizebot_experimental Your tests passed on CircleCI!
Details
ci/circleci: sizebot_stable Your tests passed on CircleCI!
Details
ci/circleci: yarn_build Your tests passed on CircleCI!
Details
ci/circleci: yarn_flow Your tests passed on CircleCI!
Details
ci/circleci: yarn_lint Your tests passed on CircleCI!
Details
ci/circleci: yarn_lint_build Your tests passed on CircleCI!
Details
ci/circleci: yarn_test Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_build Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_build_devtools Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_build_prod Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_prod Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_prod_www Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_prod_www_variant Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_www Your tests passed on CircleCI!
Details
ci/circleci: yarn_test_www_variant Your tests passed on CircleCI!
Details
ci/codesandbox Building packages succeeded.
Details
@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

@taneliang Unfortunately we've been having some flaky CI troubles the past few days. It's impacted more than just this PR ☹️ One of us is going to have to dig in and figure it out but we haven't yet.

@gaearon
Copy link
Member

gaearon commented Jul 8, 2020

One of us is going to have to dig in and figure it out but we haven't yet.

Didn't we fix it? #19265

The failures were silent before that fix which is why you didn't see them until you updated this branch.

@bvaughn
Copy link
Contributor

bvaughn commented Jul 8, 2020

Nice! I didn't know Dominic had already fixed that. Thanks for the pointer.

@taneliang
Copy link
Contributor Author

taneliang commented Jul 8, 2020

Ah, that explains it, looks like it was pretty subtle. Thanks for the explanation!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

None yet

6 participants
You can’t perform that action at this time.