Skip to content

Instantly share code, notes, and snippets.

Embed
What would you like to do?
Interaction tracing with React

Interaction tracing with React

React recently introduced an experimental profiler API. After discussing this API with several teams at Facebook, one common piece of feedback was that the performance information would be more useful if it could be associated with the events that caused the application to render (e.g. button click, XHR response). Tracing these events (or "interactions") would enable more powerful tooling to be built around the timing information, capable of answering questions like "What caused this really slow commit?" or "How long does it typically take for this interaction to update the DOM?".

With version 16.4.3, React added experimental support for this tracing by way of a new NPM package, scheduler. However the public API for this package is not yet finalized and will likely change with upcoming minor releases, so it should be used with caution.

This Gist provides some high-level documentation for anyone looking to experiment with the API.

WARNING: "unstable_" APIs may change in any version without respecting semver

React has always respected semantic versioning for its public API. However, sometimes we want to share an early preview of something that is likely to change in the future. This is one of those cases. If you care about semantic versioning guarantees, don't use "unstable_" APIs because they are subject to change in any patch release. If you use them, you agree that things will break between releases, and that you use a lockfile to avoid that.

Note that if you're using a version of react/react-dom that's less than 16.6, you should refer to this earlier revision of the documentation instead.

Note that if you're using the schedule package v0.3.0-v0.4.0 you should refer to this earlier revision of the documentation instead.

Overview

An interaction is a descriptive string (e.g. "login button clicked") and a timestamp. When you declare an interaction, you also provide a callback in which to do some work related to that interaction. Interactions are similar to "zones" in that any work done within the "zone" is attributed to the interaction.

For example, you can trace a React render like so:

import { unstable_Profiler as Profiler } from "react";
import { render } from "react-dom";
import { unstable_trace as trace } from "scheduler/tracing";

trace("initial render", performance.now(), () =>
  render(
    <Profiler id="Application" onRender={onRender}>
      <Application />
    </Profiler>,
    domElement
  )
);

In the above example, the profiler's onRender prop will be called after the application renders and mounts. Among other things, it will receive a parameter that specifies the Set of interactions that were part of that render (i.e. the "initial render" interaction).

The interaction will also appear in the React DevTools profiler plug-in.

API

The following methods are a subset of the interaction tracing API.

unstable_trace

unstable_trace(
  name: string,
  timestamp: number,
  callback: () => T
) => T

Traces a new interaction (by appending to the existing set of interactions). The callback function will be executed and its return value will be returned to the caller. Any code run within that callback will be attributed to that interaction. Calls to unstable_wrap() will schedule async work within the same zone.

unstable_wrap

unstable_wrap(callback: Function) => Function

Wrap a function for later execution within the current interaction "zone". When this function is later run, interactions that were active when it was "wrapped" will be reactivated.

The wrapped function returned also defines a cancel() property which can be used to notify any traceed interactions that the async work has been cancelled.

Examples

Tracing initial render

import { unstable_trace as trace } from "scheduler/tracing";

trace("initial render", performance.now(), () => render(<Application />));

Tracing state updates

import { unstable_trace as trace } from "scheduler/tracing";

class MyComponent extends Component {
  handleLoginButtonClick = event => {
    trace("Login button click", performance.now(), () => {
      this.setState({ isLoggingIn: true });
    });
  };

  // render ...
}

Tracing async work

import {
  unstable_trace as trace,
  unstable_wrap as wrap
} from "scheduler/tracing";

trace("Some event", performance.now(), () => {
  setTimeout(
    wrap(() => {
      // Do some async work
    })
  );
});
@alexgvozden

This comment has been minimized.

Copy link

alexgvozden commented Sep 7, 2018

this is just amazing... simple but powerful API, thanks!

@adeelibr

This comment has been minimized.

Copy link

adeelibr commented Sep 17, 2018

this is awesome.

@adeelibr

This comment has been minimized.

Copy link

adeelibr commented Sep 17, 2018

@bvaughn just a question, out of curiosity. Does the Profiler used in devtools use this internally as well? 😅

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Sep 18, 2018

@adeelibr The profiler in DevTools reads information that's tracked using this API, but it does not use it itself.

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Oct 24, 2018

This gist has been updated for 16.6

@hiyangguo

This comment has been minimized.

Copy link

hiyangguo commented Nov 8, 2018

You should install scheduler with command:

npm i scheduler --save-dev
@MJingv

This comment has been minimized.

Copy link

MJingv commented Dec 10, 2018

"scheduler": "^0.11.3",
"react-dom": "16.6.0",
"react": "16.6.3",

Can't resolve 'schedule/tracing'

@lippyDesign

This comment has been minimized.

Copy link

lippyDesign commented Dec 15, 2018

Can someone explain to me how wrap works with async calls? I'm trying to measure how long it takes to make api request and render:
`
import React, { unstable_Profiler as Profiler } from 'react';
import { unstable_trace as trace, unstable_wrap as wrap } from "scheduler/tracing";
import axios from 'axios';

import List from './List';

class App extends React.Component {
state = {
count: 0,
data: null
};

componentDidMount() {
this.fetchData();
}

logProfile = (id, phase, actualTime, baseTime, startTime, commitTime, interactions) => {
console.log('--------- logProfile fired -----------')
console.log(${id}'s ${phase.toUpperCase()} phase:);
console.log(Actual time: ${actualTime} ms);
console.log(Base time: ${baseTime} ms);
console.log(Start time (since component mounted): ${startTime} ms);
console.log(Commit time (since component mounted): ${commitTime} ms);
console.log(interactions);
};

go = direction => () => this.setState(({ count }) => ({
count: direction === "up" ? count + 1 : count - 1
}));

fetchData = () => {
trace("Fetch todos", performance.now(), () => {
this.setState({ data: null });
wrap(async () => {
try {
const { data } = await axios.get('https://jsonplaceholder.typicode.com/todos/');
this.setState({ data });
} catch (e) {
console.log(e);
}
})()
});
}

render() {
return (

<button onClick={this.go("up")}>up
The count is {this.state.count}

<button onClick={this.go("down")}>down

<button onClick={() => this.fetchData()}>refetch

);
}
}
export default App;
`

@eps1lon

This comment has been minimized.

Copy link

eps1lon commented Apr 16, 2019

Be sure to use the same scheduler that react is using i.e. use the same version. If you create a library that uses the scheduler package scheduler has to be listed as peerDependency. If you use e.g. unstable_trace from a different version of scheduler then the interaction won't be listed in onRender in Profiler.

@abhinavsinghvi

This comment has been minimized.

Copy link

abhinavsinghvi commented Jun 26, 2019

Does Profiler give time without react dev overhead so I mean to say that there is significant difference between react dev vs react prod, does Profiler component make sure that it will give number same as taken by react in prod environment?

@ali-sao

This comment has been minimized.

Copy link

ali-sao commented Jul 23, 2019

يلعن سماواتك يا أبهيناف في كندرتي

@vinodhinisekar

This comment has been minimized.

Copy link

vinodhinisekar commented Aug 29, 2019

Does Profiler track the child component detail also by using javascript?

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Aug 29, 2019

Does Profiler give time without react dev overhead so I mean to say that there is significant difference between react dev vs react prod, does Profiler component make sure that it will give number same as taken by react in prod environment?

Profiling bundle is much closer to production bundle. There is a small amount of extra overhead but it's minimal.

Does Profiler track the child component detail also by using javascript?

Sorry. I don't understand the question.

@arunstan

This comment has been minimized.

Copy link

arunstan commented Oct 17, 2019

unstable_Profiler is renamed to Profiler as of react v16.10

@kentcdodds

This comment has been minimized.

Copy link

kentcdodds commented Apr 21, 2020

Here's how you'd add wrap to some async stuff:

function handleGetWidgetsClick() {
  getWidgets().then(
    widgets => dispatch({type: 'success', widgets}),
    error => dispatch({type: 'error', error}),
  )
}
function handleGetWidgetsClick() {
  trace('clicked "get widgets" button', performance.now(), () => {
    getWidgets().then(
      wrap(widgets => dispatch({type: 'success', widgets})),
      wrap(error => dispatch({type: 'error', error})),
    )
  })
}

Let me know if I got that wrong, but it's working for me. Here's a screenshot of the devtools when you've got something like this set up properly:

image

And the React.Profiler component sends the interactions as expected as well :)

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Apr 21, 2020

Looks right, yes

@raphaelbs

This comment has been minimized.

Copy link

raphaelbs commented Apr 24, 2020

I'm planning to use the Profiler to collect render metrics for critical flows in the application, to both improve the ones with a lot of re-renderings and also to have some health metrics in the pipeline. I have some questions, hopefully you guys can shed light into them:

  1. The difference between actualDuration and the baseDuration can be used as a metric of how poor performance the component has? Is it reliable enough?
  2. Is there a way to detect when React finishes rendering? I’m considering using the idle-until-urgent but it includes tasks other than React's.
  3. DevTools > Performance > Timings displays the error Lifecycle hook scheduled a cascading update. Is this related to the commit counts and re-renderings that the React’s Profiler tab shows? (attachment 1).
  4. Summing the actualDuration of the update phases for a given component (attachment 3) gives a different value when comparing with the React Profiler tab (attachment 2). What does this difference mean? Are they different metrics?
Attachments

Attachment 1,
image

Attachment 2, reported rendering duration 217 + 149 + 5 + 29 = ~400ms:
image

Attachment 3, totalTime reporting ~600ms for the same profile run as the attachment 2:
image

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Apr 24, 2020

  1. The difference between actualDuration and the baseDuration can be used as a metric of how poor performance the component has? Is it reliable enough?

actualDuration is probably your best metric for how well or poor a component "performs" in terms of rendering time. The delta between actualDuration and baseDuration is an indicator of how much better it performs on an update rather than a mount (aka much time is saved by memoization).

  1. Is there a way to detect when React finishes rendering? I’m considering using the idle-until-urgent but it includes tasks other than React's.

Finishes rendering as in...commits what it has to the DOM? That's what the React.Profiler API does (and also what the DevTools Profiler shows). Each commit is a finished render. If you mean "has no more scheduled work pending" then the experimental interaction tracing API could be used to do this but for your purposes, it's probably overkill. In hindsight you could just look at the last commit and when it took place vs the current time.

  1. DevTools > Performance > Timings displays the error Lifecycle hook scheduled a cascading update. Is this related to the commit counts and re-renderings that the React’s Profiler tab shows? (attachment 1).

A "cascading update" means something in the commit phase (componentDidMount, componentDidUpdate, useEffect, or useLayoutEffect) scheduled another render right after React just finished the current one. So yes it does relate to the number of commits. This is something we warn about because in most of those cases, the cascading update has to be flushed synchronously (b'c of e.g. positioning tooltips, sizing modals, etc- intermediate states that shouldn't be visible to the user) so it delays paint. (You can find lots of other things written about this on the React docs and GItHub issues.)

  1. Summing the actualDuration of the update phases for a given component (attachment 3) gives a different value when comparing with the React Profiler tab (attachment 2). What does this difference mean? Are they different metrics?

Simple answer: Yes, some differences are expected. Profiler's actualDuration only includes time spent in your React component. Browser profiler also includes time spent in React internals. Profiler also sums durations within the render. Browser tools might show them separately (at least in the case of concurrent rendering).

@kentcdodds

This comment has been minimized.

Copy link

kentcdodds commented Apr 24, 2020

The delta between actualDuration and baseDuration is an indicator of how much better it performs on an update rather than a mount

Does this mean that on an update, the actualDuration is how long the update took (specifically how long it took to run the function itself) and the baseDuration was the actualDuration of the mount? Or am I misunderstanding this?

Thanks a bunch for this gist and answering questions @bvaughn! It's been very insightful. I'm excited for this to become stable. Oh, on that note, my expectation is that when this is stable we won't be importing from the scheduler directly. Do you think that we will be importing from the scheduler, or will we import these things from React (which may just re-export things from the scheduler)? It's my impression that the React team wants to consider the scheduler an implementation detail. Thoughts?

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Apr 25, 2020

The docs define actualDuration and baseDuration as:

  • actualDuration: number - Time spent rendering the Profiler and its descendants for the current update. This indicates how well the subtree makes use of memoization (e.g. React.memo, useMemo, shouldComponentUpdate). Ideally this value should decrease significantly after the initial mount as many of the descendants will only need to re-render if their specific props change.
  • baseDuration: number - Duration of the most recent render time for each individual component within the Profiler tree. This value estimates a worst-case cost of rendering (e.g. the initial mount or a tree with no memoization).

Put another way, actualDuration is probably what you want to think about in most cases. It's the most intuitive measure. (How long did this render take?)

baseDuration is more of a concept. The whole subtree probably takes about this long to mount (if it were to mount). The delta between the two then could be used to indicate how well you're memoizing things.

Do you think that we will be importing from the scheduler, or will we import these things from React (which may just re-export things from the scheduler)? It's my impression that the React team wants to consider the scheduler an implementation detail. Thoughts?

I'm not sure yet what the final API for tracing will be like, since we'll be using a native scheduler (perhaps with a smaller API) for scheduling things.

@raphaelbs

This comment has been minimized.

Copy link

raphaelbs commented Apr 25, 2020

@bvaughn thanks for the comprehensive response!

If you mean "has no more scheduled work pending"

I did, yeah!

In hindsight you could just look at the last commit and when it took place vs the current time

The PoC I’m working on is exactly that! But I wonder if user inputs will affect this e.g. if the user interacts right away, its interactions would account as part of the “initial mounting” tracing bucket.

then the experimental interaction tracing API could be used to do this but for your purposes

In this scenario I would trace individual points of the application to be used as “stop profiling” flags?

A "cascading update" means something in the commit phase (componentDidMount, componentDidUpdate, useEffect, or useLayoutEffect) scheduled another render right after React just finished the current one.

What qualifies the right after? Is it a fixed timestamp?
In React’s point of view, there’s a difference between an user triggered render vs a cascading updated one?

@octopitus

This comment has been minimized.

Copy link

octopitus commented Apr 26, 2020

CMIIW but I think the example of "tracing async work" must be something like this:

import {
  unstable_trace as trace,
  unstable_wrap as wrap
} from "scheduler/tracing";

trace("Some event", performance.now(), () => {
  const wrapped = wrap(() => {
    // Do some async work
  })

  setTimeout(() => wrapped());
});

wrap must be called within the same "zone" of trace. The wrapped function also need to be called.

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Apr 26, 2020

@octopitus That's not really different from what the current example shows, since wrap is invoked synchrously.

@octopitus

This comment has been minimized.

Copy link

octopitus commented Apr 27, 2020

I have an demo follow your example but it doesn't work. Turns out the thing wrapped in setTimeout never get call.

@bvaughn

This comment has been minimized.

Copy link
Owner Author

bvaughn commented Apr 27, 2020

@octopitus Your demo has a mistake:

trace("api", performance.now(), () => {
  setTimeout(() => { // This wrapper function is the mistake
    wrap(() => {
      setMount(true);
    });
  });
});

Compare to the example above:

trace("Some event", performance.now(), () => {
  setTimeout( // There's no wrapper function
    wrap(() => {
      // Do some async work
    })
  );
});
@octopitus

This comment has been minimized.

Copy link

octopitus commented Apr 27, 2020

Oh, right, my bad. Thanks for pointing out.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.