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

Show React events in the timeline when ReactPerf is active #7549

Merged
merged 2 commits into from Aug 24, 2016

Conversation

Projects
None yet
8 participants
@gaearon
Member

gaearon commented Aug 23, 2016

This was released in React 15.4.0. Read the blog post.


When you open the page with ?react_perf (or manually call ReactPerf.start()), this emits console.time()ings which are interpreted specially by Chrome (and maybe other browsers, I haven’t checked).

Seems like a nice way to visualize what is being mounted / updated / unmounted.

It looks like this in Chrome Timeline:

screen shot 2016-08-23 at 21 42 17

Yay or nay?

Show outdated Hide outdated src/renderers/shared/ReactDebugTool.js
},
onUpdateComponent(debugID) {
checkDebugID(debugID);
emitEvent('onUpdateComponent', debugID);
if (isProfiling && hasAdvancedConsoleFeatures) {

This comment has been minimized.

@gaearon

gaearon Aug 23, 2016

Member

These actually should be before emitEvent for better precision..

@gaearon

gaearon Aug 23, 2016

Member

These actually should be before emitEvent for better precision..

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

👍

@vjeux

vjeux Aug 23, 2016

Contributor

👍

Show outdated Hide outdated src/renderers/shared/ReactDebugTool.js
beginLifeCycleTimer(debugID, timerType);
},
onEndLifeCycleTimer(debugID, timerType) {
checkDebugID(debugID);
endLifeCycleTimer(debugID, timerType);
var displayName = ReactComponentTreeHook.getDisplayName(debugID);

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

missing if check here

@vjeux

vjeux Aug 23, 2016

Contributor

missing if check here

This comment has been minimized.

@gaearon

gaearon Aug 23, 2016

Member

These two are guaranteed to be composites since they have lifecycles.

@gaearon

gaearon Aug 23, 2016

Member

These two are guaranteed to be composites since they have lifecycles.

This comment has been minimized.

@gaearon

gaearon Aug 23, 2016

Member

Oh but you're right, still need to check whether profiling.

@gaearon

gaearon Aug 23, 2016

Member

Oh but you're right, still need to check whether profiling.

Show outdated Hide outdated src/renderers/shared/ReactDebugTool.js
beginLifeCycleTimer(debugID, timerType);
},
onEndLifeCycleTimer(debugID, timerType) {
checkDebugID(debugID);
endLifeCycleTimer(debugID, timerType);
var displayName = ReactComponentTreeHook.getDisplayName(debugID);
var label = displayName + '#' + timerType;
console.timeEnd(label);

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

What happens if you have components that recursively render themselves, would it end an incorrect one? Should we put the debugID in there to make it unique?

@vjeux

vjeux Aug 23, 2016

Contributor

What happens if you have components that recursively render themselves, would it end an incorrect one? Should we put the debugID in there to make it unique?

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

Or if two components are not named and you end up with 'Unknown' https://github.com/facebook/react/blob/master/src/isomorphic/hooks/ReactComponentTreeHook.js#L176

@vjeux

vjeux Aug 23, 2016

Contributor

Or if two components are not named and you end up with 'Unknown' https://github.com/facebook/react/blob/master/src/isomorphic/hooks/ReactComponentTreeHook.js#L176

This comment has been minimized.

@gaearon

gaearon Aug 23, 2016

Member

Good catch.

@gaearon

gaearon Aug 23, 2016

Member

Good catch.

Show outdated Hide outdated src/renderers/shared/ReactDebugTool.js
},
onUpdateComponent(debugID) {
checkDebugID(debugID);
emitEvent('onUpdateComponent', debugID);
if (isProfiling && hasAdvancedConsoleFeatures) {
var element = ReactComponentTreeHook.getElement(debugID);
var isCompositeComponent = typeof element.type === 'function';

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

Not really about your diff but should we have a unique way to check if an element is composite? ReactTestUtil has a different way of testing it:

isCompositeComponent: function(inst) {
if (ReactTestUtils.isDOMComponent(inst)) {
// Accessing inst.setState warns; just return false as that'll be what
// this returns when we have DOM nodes as refs directly
return false;
}
return inst != null &&
typeof inst.render === 'function' &&
typeof inst.setState === 'function';
},

@vjeux

vjeux Aug 23, 2016

Contributor

Not really about your diff but should we have a unique way to check if an element is composite? ReactTestUtil has a different way of testing it:

isCompositeComponent: function(inst) {
if (ReactTestUtils.isDOMComponent(inst)) {
// Accessing inst.setState warns; just return false as that'll be what
// this returns when we have DOM nodes as refs directly
return false;
}
return inst != null &&
typeof inst.render === 'function' &&
typeof inst.setState === 'function';
},

This comment has been minimized.

@gaearon

gaearon Aug 23, 2016

Member

ReactTestUtils checks an instance, not an element, so that’s why it’s different.
I could add a convenience method to the hook but I’d wait for a little more duplication first.

@gaearon

gaearon Aug 23, 2016

Member

ReactTestUtils checks an instance, not an element, so that’s why it’s different.
I could add a convenience method to the hook but I’d wait for a little more duplication first.

This comment has been minimized.

@vjeux

vjeux Aug 23, 2016

Contributor

👍

@vjeux

vjeux Aug 23, 2016

Contributor

👍

@vjeux

This comment has been minimized.

Show comment
Hide comment
@vjeux

vjeux Aug 23, 2016

Contributor

This is awesome, we've had the same view on React Native with systrace and it's been really helpful to track down what was going on during render.

Contributor

vjeux commented Aug 23, 2016

This is awesome, we've had the same view on React Native with systrace and it's been really helpful to track down what was going on during render.

@vjeux

This comment has been minimized.

Show comment
Hide comment
@vjeux

vjeux Aug 23, 2016

Contributor

Outside of the label uniqueness issue and the missing check, sounds good to me :)

Contributor

vjeux commented Aug 23, 2016

Outside of the label uniqueness issue and the missing check, sounds good to me :)

@ghost ghost added the CLA Signed label Aug 23, 2016

@jakepusateri

This comment has been minimized.

Show comment
Hide comment
@jakepusateri

jakepusateri Aug 24, 2016

I think performance.measure should be able to produce that same view without logging to the console: https://twitter.com/igrigorik/status/690636030727159808

I think performance.measure should be able to produce that same view without logging to the console: https://twitter.com/igrigorik/status/690636030727159808

Show React events in the timeline when ReactPerf is active
This currently only seems to work on Chrome.

@gaearon gaearon changed the title from Show console.time() when ReactPerf is started to Show React events in the timeline when ReactPerf is active Aug 24, 2016

@ghost ghost added the CLA Signed label Aug 24, 2016

@gaearon

This comment has been minimized.

Show comment
Hide comment
@gaearon

gaearon Aug 24, 2016

Member

I tried using performance.measure() but it has an annoying issue: if events are too close, it appears to swallow some events, and they may never “finish”:

screen shot 2016-08-24 at 16 58 12

This looks like a Chrome bug to me:

screen shot 2016-08-24 at 16 56 04

Member

gaearon commented Aug 24, 2016

I tried using performance.measure() but it has an annoying issue: if events are too close, it appears to swallow some events, and they may never “finish”:

screen shot 2016-08-24 at 16 58 12

This looks like a Chrome bug to me:

screen shot 2016-08-24 at 16 56 04

@gaearon

This comment has been minimized.

Show comment
Hide comment
@gaearon

gaearon Aug 24, 2016

Member

OK, I found a workaround for Chrome issue.
Ready for a second review.

Member

gaearon commented Aug 24, 2016

OK, I found a workaround for Chrome issue.
Ready for a second review.

@@ -244,11 +301,13 @@ var ReactDebugTool = {
onBeginLifeCycleTimer(debugID, timerType) {
checkDebugID(debugID);
emitEvent('onBeginLifeCycleTimer', debugID, timerType);
markBegin(debugID, timerType);

This comment has been minimized.

@vjeux

vjeux Aug 24, 2016

Contributor

So good, I was going to ask if you could make this less verbose and repetitive :)

@vjeux

vjeux Aug 24, 2016

Contributor

So good, I was going to ask if you could make this less verbose and repetitive :)

This comment has been minimized.

@gaearon

gaearon Aug 24, 2016

Member

Yeah, I wrote this PR yesterday while waiting for the taxi so it wasn’t really clean 😄

@gaearon

gaearon Aug 24, 2016

Member

Yeah, I wrote this PR yesterday while waiting for the taxi so it wasn’t really clean 😄

typeof performance.clearMeasures === 'function';
function shouldMark(debugID) {
if (!isProfiling || !canUsePerformanceMeasure) {

This comment has been minimized.

@vjeux

vjeux Aug 24, 2016

Contributor

Probably overkill but if canUsePerformanceMeasure is not true, I would just do shouldMark = function() {}.

You could use the same technique by clearing shouldMark when you end profiling and bring it back when you start profiling. This way you don't even have to do that test.

I have no idea what are the perf implications of this but since we're talking about super hot functions, it may be worth it.

@vjeux

vjeux Aug 24, 2016

Contributor

Probably overkill but if canUsePerformanceMeasure is not true, I would just do shouldMark = function() {}.

You could use the same technique by clearing shouldMark when you end profiling and bring it back when you start profiling. This way you don't even have to do that test.

I have no idea what are the perf implications of this but since we're talking about super hot functions, it may be worth it.

This comment has been minimized.

@gaearon

gaearon Aug 24, 2016

Member

I took a profile and it was something like 0.01% of total time so I didn’t bother.

@gaearon

gaearon Aug 24, 2016

Member

I took a profile and it was something like 0.01% of total time so I didn’t bother.

This comment has been minimized.

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Is all those checks necessary? Can't we simply check 'mark' in performance or 'measure' in performance and just assume the User Timing API is supported?

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Is all those checks necessary? Can't we simply check 'mark' in performance or 'measure' in performance and just assume the User Timing API is supported?

This comment has been minimized.

@gaearon

gaearon Aug 31, 2016

Member

Is there any problem with doing them? In my experience of using standards, unless you check for everything explicitly, you risk running into bad/incomplete polyfills.

@gaearon

gaearon Aug 31, 2016

Member

Is there any problem with doing them? In my experience of using standards, unless you check for everything explicitly, you risk running into bad/incomplete polyfills.

This comment has been minimized.

@gaearon

gaearon Aug 31, 2016

Member

Also those checks run only once.

@gaearon

gaearon Aug 31, 2016

Member

Also those checks run only once.

This comment has been minimized.

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Not sure if its a overkill. But wanted to confirm if there is any weird behaviour with any browsers.

Totally agree on that point 👍

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Not sure if its a overkill. But wanted to confirm if there is any weird behaviour with any browsers.

Totally agree on that point 👍

This comment has been minimized.

@gaearon

gaearon Aug 31, 2016

Member

No weird behavior so far, just wanted to be extra safe.

@gaearon

gaearon Aug 31, 2016

Member

No weird behavior so far, just wanted to be extra safe.

This comment has been minimized.

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Cool. Sounds good.

@vigneshshanmugam

vigneshshanmugam Aug 31, 2016

Cool. Sounds good.

@vjeux

This comment has been minimized.

Show comment
Hide comment
@vjeux

vjeux Aug 24, 2016

Contributor

Yay, this is going to help so many people!

Contributor

vjeux commented Aug 24, 2016

Yay, this is going to help so many people!

@gaearon gaearon added this to the 15-next milestone Aug 24, 2016

@gaearon gaearon merged commit 0a248ee into facebook:master Aug 24, 2016

1 check passed

continuous-integration/travis-ci/pr The Travis CI build passed
Details

@gaearon gaearon deleted the gaearon:perf-timers branch Aug 24, 2016

@shaneosullivan

This comment has been minimized.

Show comment
Hide comment
@shaneosullivan

shaneosullivan Aug 24, 2016

Contributor

Is performance.measure() ideally the right way to do this? If so, can we follow up with the Chrome dev team to resolve the bug?

Contributor

shaneosullivan commented Aug 24, 2016

Is performance.measure() ideally the right way to do this? If so, can we follow up with the Chrome dev team to resolve the bug?

@vjeux

This comment has been minimized.

Show comment
Hide comment
@vjeux

vjeux Aug 24, 2016

Contributor

@shaneosullivan a bug was created and involved parties on Chrome team have cc-ed themselves https://bugs.chromium.org/p/chromium/issues/detail?id=640652

Contributor

vjeux commented Aug 24, 2016

@shaneosullivan a bug was created and involved parties on Chrome team have cc-ed themselves https://bugs.chromium.org/p/chromium/issues/detail?id=640652

@paulirish

This comment has been minimized.

Show comment
Hide comment
@paulirish

paulirish Aug 25, 2016

We have a fix landing now for the Chrome bug: https://codereview.chromium.org/2276743004
Should be in tomorrow's Canary.


Update: Fix landed.


Update (sept 8th): Just FWIW, I benchmarked the cost of performance.mark() yesterday to understand what sort of overheard it has: https://gist.github.com/paulirish/2fad3834e2617fb199bc12e17058dde4
TL;DR: it's all good.

paulirish commented Aug 25, 2016

We have a fix landing now for the Chrome bug: https://codereview.chromium.org/2276743004
Should be in tomorrow's Canary.


Update: Fix landed.


Update (sept 8th): Just FWIW, I benchmarked the cost of performance.mark() yesterday to understand what sort of overheard it has: https://gist.github.com/paulirish/2fad3834e2617fb199bc12e17058dde4
TL;DR: it's all good.

@zpao zpao modified the milestones: 15-next, 15.4.0 Oct 4, 2016

zpao added a commit that referenced this pull request Oct 4, 2016

Show React events in the timeline when ReactPerf is active (#7549)
* Show React events in the timeline when ReactPerf is active

This currently only seems to work on Chrome.

* Address Chrome issue

(cherry picked from commit 0a248ee)
@pavlelekic

This comment has been minimized.

Show comment
Hide comment
@pavlelekic

pavlelekic Dec 5, 2016

This is amazing, is there a way to run this for React Native for iOS?

This is amazing, is there a way to run this for React Native for iOS?

@gaearon

This comment has been minimized.

Show comment
Hide comment
@gaearon

gaearon Dec 5, 2016

Member

@pavlelekic I think it might just work when you use Chrome debugger? You'd need to import Perf addon from RN itself though, maybe require('react-native/lib/ReactPerf) would work. I’m not actually sure how people import it there.

Member

gaearon commented Dec 5, 2016

@pavlelekic I think it might just work when you use Chrome debugger? You'd need to import Perf addon from RN itself though, maybe require('react-native/lib/ReactPerf) would work. I’m not actually sure how people import it there.

@renovate renovate bot referenced this pull request Feb 2, 2018

Open

Update dependency react to v16 #29

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment