React DevTools recording commit without any component re-render

[kentcdodds]

I'm struggling to make an isolated example of this, but the app where I found this is pretty simple so hopefully it's not too challenging to track down.

So I was profiling https://the-react-bookshelf.netlify.com (locally) and got this when I clicked on the "login" button:

The fact that there was no profile data for a commit is interesting. Each commit should be associated to a state update somewhere in the tree, and wherever that happened should trigger at least one component to re-render, but that didn't appear to happen here.

I also verified that I don't have any components filtered out:

And I didn't filter any commits either:

Here's the exported profile data:

https://gist.github.com/kentcdodds/dbff66043653333cd22cb9261a08550b

And here's the repo where you can pull it down and reproduce yourself: https://github.com/kentcdodds/bookshelf. The component we're looking at is here: https://github.com/kentcdodds/bookshelf/blob/master/src/unauthenticated-app.js

Sorry I can't give a more direct reproduction.

[kentcdodds]

Made a smaller reproduction. I'm thinking that it has something to do with @reach/dialog: https://github.com/kentcdodds/devtools-renderless-profile

That has a profile in it as well. Basically the same thing, just a lot less code :)

[marvinhagemeister]

Noticed a similar thing past week in a project at work with react-dnd. There the ghosting element that follows the cursor while dragging renders on each dragover event. But because nothing has changed (or maybe everything is memoized, haven't looked in depth) the devtools gray out all components.

[kentcdodds]

I just noticed this same behavior in the redux Todo app example: https://codesandbox.io/s/github/reduxjs/redux/tree/master/examples/todos

[bvaughn]

I think the reason the linked sandbox shows a cascading commit is that discrete DOM events (like "submit") flush updates in two passes. I was mistaken. See this comment instead.

It just so happens that one of these passes bails out without doing any actual work, but React still calls the DevTools hook and the Profiler isn't "smart" enough to ignore the no-work one. Maybe it should be?

[kentcdodds]

Thanks for digging into that Brian!

Maybe it should be?

I think that it should, for a few reasons:

1. It's confusing
2. It could cause people to try to optimize something that may not need optimizing.
3. It's extra noise and isn't very useful because it's not actionable.

I think that it should exclude those kinds of commits. Maybe making it configurable would work, though I'm not sure I can think of a situation where seeing a commit was bailed would be helpful.

[bvaughn]

I think that it should exclude those kinds of commits. Maybe making it configurable would work, though I'm not sure I can think of a situation where seeing a commit was bailed would be helpful.

It is already configurable, FWIW, and maybe I should lean on this a little harder with a default configuration (would need more thought). Profiler lets you hide commits below a certain threshold:

In general, let me think about this a little more. I'm not really familiar with Redux / react-redux, and I think it's doing something here to trigger this issue. (It wouldn't happen from a "vanilla" React form+state.)

[kentcdodds]

I've noticed it come up in smaller examples in my workshops. Next time I come across it, I'll try to make an even smaller repro. Thanks!

[bvaughn]

That would be helpful, thanks.

[bvaughn]

I may have misspoke earlier by saying that the "submit" event was the cause of this. Looking again, it looks like the second update is being triggered by another event type (e.g. "blur", "focus", "keydown" - whatever happens to dispatch next after the "submit")

Not sure why this is. Nothing seems to be listening for that event type in this project, so it's maybe something React DOM is doing itself?

cc @trueadm @necolas since you two have a lot more insight into the event system than I do 😄

[trueadm]

Looking into this and it seems this might be occurring because ReactDOM's event plugins, that provide functionality to things like onChange, over-register (intentionally) to events such as blur, focus and keydown even if you don't use those events directly in your code.

Furthermore, these events are all "discrete" events, which means they flush any prior work – likely causing multiple updates here:

https://github.com/facebook/react/blob/master/packages/react-dom/src/events/ReactDOMEventListener.js#L288-L291

However, we do have a slightly altered change with the React Flare flag enabled, specifically flushing doesn't occur for multiple discrete events of the same timeStamp:

https://github.com/facebook/react/blob/master/packages/legacy-events/ReactGenericBatching.js#L106-L127

@bvaughn this might fix this issue – please could you test with a build with the React Flare enabled?

If you don't use onChange, or onBeforeInput then maybe the event replaying logic might be responsible here? cc @sebmarkbage

[bvaughn]

However, we do have a slightly altered change with the React Flare flag enabled, specifically flushing doesn't occur for multiple discrete events of the same timeStamp:

I don't think that would apply since it's always the next event (e.g. "blur", "focus", "keydown") rather than the one that scheduled work originally ("submit"). So I think the timestamps wouldn't match.

If you don't use onChange, or onBeforeInput then maybe the event replaying logic might be responsible here?

FWIW the repro project I'm looking at is only using onSubmit:
https://codesandbox.io/s/xenodochial-worker-sh0ou

[trueadm]

@bvaughn > So I think the timestamps wouldn't match.

You'd be surprised. Most events all trigger at the same time for interactions, for example, when you click something there's about 10 events that fire – all with the same timeStamp. In this case, as it's a submit, they are likely to be different though. Worth trying out still?

[bvaughn]

I added a log of the event timeStamp and they are different, fwiw.

[bvaughn]

So in this case, after the "submit" event handler, the next time flushPendingDiscreteUpdates is called,rootsWithPendingDiscreteUpdates has a root which has an expiration time of the previous update scheduled from the "submit" handler.

The rootsWithPendingDiscreteUpdates entry is being added by scheduleUpdateOnFiber as part of the update scheduled by the "submit" handler:

react/packages/react-reconciler/src/ReactFiberWorkLoop.js

Lines 425 to 442 in a1ff9fd

	if (
	(executionContext & DiscreteEventContext) !== NoContext &&
	// Only updates at user-blocking priority or greater are considered
	// discrete, even inside a discrete event.
	(priorityLevel === UserBlockingPriority ||
	priorityLevel === ImmediatePriority)
	) {
	// This is the result of a discrete event. Track the lowest priority
	// discrete update per root so we can flush them early, if needed.
	if (rootsWithPendingDiscreteUpdates === null) {
	rootsWithPendingDiscreteUpdates = new Map([[root, expirationTime]]);
	} else {
	const lastDiscreteTime = rootsWithPendingDiscreteUpdates.get(root);
	if (lastDiscreteTime === undefined || lastDiscreteTime > expirationTime) {
	rootsWithPendingDiscreteUpdates.set(root, expirationTime);
	}
	}
	}

[kentcdodds]

Just in case it's helpful. I reproduced this with:

https://codesandbox.io/s/input-with-strange-render-13tu0

It's literally just:

import React from 'react'
import ReactDOM from 'react-dom'

function App() {
  const [name, setName] = React.useState('')
  return <input value={name} onChange={e => setName(e.target.value)} />
}

ReactDOM.render(<App />, document.getElementById('root'))

[bvaughn]

Ah, thanks!

I had been trying to reproduce with an onClick but I think now, looking at the event stuff, you need a special meta event like "change" in order for React to add some related (non-App-code-specific) event handlers.

[bvaughn]

Also worth pointing out that this "bug" does not happen when using the root API, only legacy/sync mode.

[bvaughn]

I think this bug could be seen as the fault of the synthetic event system (for scheduling the work unnecessarily) or the reconciler (for "committing" the no-op work). I don't think it's the fault of DevTools or the Profiler though, and my thoughts so far on possible ways to detect and filter it have all shown false positives.

Edit: I've submitted a PR that improves this experience by skipping the empty commits: #17253

[bvaughn]

The following test case demonstrates the current failing behavior in the smaller repro case:

packages/react-devtools-shared/src/__tests__/profilerStore-test.js

it("should filter empty commits", () => {
  const inputRef = React.createRef();
  const ControlledInput = () => {
    const [name, setName] = React.useState("foo");
    const handleChange = event => setName(event.target.value);
    return <input ref={inputRef} value={name} onChange={handleChange} />;
  };

  const container = document.createElement("div");

  // This element has to be in the <body> for the event system to work.
  document.body.appendChild(container);

  // It's important that this test uses legacy sync mode.
  // The root API does not trigger this particular failing case.
  ReactDOM.render(<ControlledInput />, container);

  utils.act(() => store.profilerStore.startProfiling());

  // Sets a value in a way that React doesn't see,
  // so that a subsequent "change" event will trigger the event handler.
  const setUntrackedValue = Object.getOwnPropertyDescriptor(
    HTMLInputElement.prototype,
    "value"
  ).set;

  const target = inputRef.current;
  setUntrackedValue.call(target, "bar");
  target.dispatchEvent(new Event("input", { bubbles: true, cancelable: true }));
  expect(target.value).toBe("bar");

  utils.act(() => store.profilerStore.stopProfiling());

  // Only one commit should have been recorded (in response to the "change" event).
  const root = store.roots[0];
  const data = store.profilerStore.getDataForRoot(root);
  expect(data.commitData).toHaveLength(1);
});

[bvaughn]

DevTools Profiler experience will be improved as of the next extension release. Will follow up with a fix to the underlying React/event issue soonish.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contribution.

[bvaughn]

I think the overall experience here has been improved, but the issue is still pending a decision on #17267.

[stale]

This issue has been automatically marked as stale. If this issue is still affecting you, please leave any comment (for example, "bump"), and we'll keep it open. We are sorry that we haven't been able to prioritize it yet. If you have any new additional information, please include it with your comment!

[kentcdodds]

Just verified this is still an issue in the current DevTools.

[bvaughn]

Yup, #17267 was never reviewed or merged.

[stale]

This issue has been automatically marked as stale. If this issue is still affecting you, please leave any comment (for example, "bump"), and we'll keep it open. We are sorry that we haven't been able to prioritize it yet. If you have any new additional information, please include it with your comment!

[kentcdodds]

bump

[RohovDmytro]

The issue happens to me, still.

[bvaughn]

That's because (as mentioned a couple of comments above yours) the fix in #17267 was never reviewed or landed.

[tavoyne]

@bvaughn Are we sure it's caused by the Profiler?

Take this code:

const App = () => {
  const [, setTouched] = useState(false);

  const handleBlur = () => {
    setTouched(true);
  };

  console.log('Rendered');

  return <input onBlur={handleBlur} />;
};

If you click in and out the input twice, you'll notice 'Rendered' gets printed twice to the console, and not only once as we might expect. Opening the Profiler, you'll see two commits, the first one is normal (and expected), the other one is ghosty as above. Weirdly enough, it's just the second blur that causes the extra print and commit, i.e. if you repeat the operation one or more times, nothing will happen.

Doesn't the fact that the App element actually ran (even without causing a re-render) show that the Profiler is not faulty here, and that maybe the event system is? I may be missing something, forgive me if I am!

Sandbox link.

[bvaughn]

@theoavoyne Thanks for sharing this repro.

This is a good example of the issue being described in the thread. Indeed, React renders twice– but bails out after the second rendering of App because there are no changes. (You can see this by adding an log inside of an effect and verifying that it never gets printed the second time.)

Ideally React would not call the DevTools hook at all in this case, which is what my PR #17267 was about.

[tavoyne]

Thank you, Brian.

Yes I tried that already and noticed exactly what you said. But why is React rendering on the second blur anyway? From my understanding, it shouldn't. And why is it rendering on the second blur but not on subsequent ones? What happens with the subsequent ones (i.e. no rendering at all) is what I expect should happen with the second one.

EDIT: this behaviour is observable with events other than blur, so I guess I'm mistaking on what should happen. I just don't get why it renders that second time (even with bailing out).

[bvaughn]

Honestly, I forget the reason why React is sometimes able to detect a bailout case earlier (eagerly) and when it sometimes has to do some light work (e.g. rendering a component) before being able to detect bailout. Maybe it has to do with the state/update queue. Regardless, this type of bailout isn't general observable (unless you're specifically looking for it with logs like this) and shouldn't matter much except for cases like this where it causes confusion.

I'm going to rebase #17267 and try to get some eyes on it.

[bvaughn]

The following test case demonstrates the most recently reported failing behavior:

packages/react-devtools-shared/src/__tests__/profilerStore-test.js

it('should filter empty commits', () => {
  let commitCount = 0;

  const inputRef = React.createRef();
  const Example = () => {
    const [, setTouched] = React.useState(false);

    const handleBlur = () => {
      setTouched(true);
    };

    React.useLayoutEffect(() => {
      commitCount++;
    });

    return <input ref={inputRef} onBlur={handleBlur} />;
  };

  const container = document.createElement('div');

  // This element has to be in the <body> for the event system to work.
  document.body.appendChild(container);

  // It's important that this test uses legacy sync mode.
  // The root API does not trigger this particular failing case.
  legacyRender(<Example />, container);

  expect(commitCount).toBe(1);
  commitCount = 0;

  utils.act(() => store.profilerStore.startProfiling());

  // Focus and blur.
  const target = inputRef.current;
  target.focus();
  target.blur();
  target.focus();
  target.blur();
  expect(commitCount).toBe(1);

  utils.act(() => store.profilerStore.stopProfiling());

  // Only one commit should have been recorded (in response to the "change" event).
  const root = store.roots[0];
  const data = store.profilerStore.getDataForRoot(root);
  expect(data.commitData).toHaveLength(1);
  expect(data.operations).toHaveLength(1);
});

[tavoyne]

And don't you think that the problem may lie here, e.g. that React renders when it shouldn't?

I use console.log on rendering quite a lot for debugging purposes, and I've never encountered a situation where it was fired unexpectedly.

I agree that the Profiler should be showing commits only when they happened, so your PR is much needed. But maybe this is pointing to another problem as well? Maybe the event system (since it happens only with event handlers) is messing up at some point?

[bvaughn]

And don't you think that the problem may lie here, e.g. that React renders when it shouldn't?

Again, I forget the exact scenario when React can't safely detect an eager bailout case without shallowly rendering the tree, but I think this may be related to that. I'm not sure. I'm looking into it. If you'd like to look into it also, I'd be happy to have another set of eyes digging in.

I don't think my initial change (#17267) is still relevant after the expiration time to lanes refactor, as we already bail out early if there is no work scheduled on the root:

react/packages/react-reconciler/src/ReactFiberWorkLoop.new.js

Lines 645 to 653 in e0aa5e2

	if (nextLanes === NoLanes) {
	// Special case: There's nothing to work on.
	if (existingCallbackNode !== null) {
	cancelCallback(existingCallbackNode);
	}
	root.callbackNode = null;
	root.callbackPriority = NoLane;
	return;
	}

Need to dig more.

[bvaughn]

I think the equivalent fix now would be to not call the DevTools commit hook if both rootHasEffect and subtreeHasEffects are false. Unforunately, such a change would break e.g. component inspection if a change in props didn't result in any effects.

If a subtree renders without generating any effects– should Profiler still care about this? I can see arguments both ways. On the one hand, it's confusing to see an empty tree. On the other, even cheap renders aren't free and these bailouts have cost, so maybe we should report them.

I don't think there's any way for DevTools to detect this type of bailout though, since memoizedProps, memoizedState, and ref will all be equal in this case– and the PerformedWork flag will be false, since React bailed out. (React doesn't consider the bailout render "work" in this case.)

Maybe DevTools could avoid showing an empty commit by "detecting" this case based on whether there are no Fibers passed the PerformedWork check. This be an improvement since we'd avoid showing an apparently empty commit.

[tavoyne]

Such a change would break e.g. component inspection if a change in props didn't result in any effects.

That's pretty bad I think. It will make the Profiler less predictable.

Even cheap renders aren't free and these bailouts have cost, so maybe we should report them.

Totally agree.

In the end, I'm not 100% sure that the Profiler is doing anything wrong here. If the extra render caused by the second call to setState wasn't happening, its output would be what's expected and we would never (or maybe it happens in other scenarios? I'm not sure) encounter such an empty tree.

BTW, this issue was discussed here. Unfortunately, it wasn't clearly answered.

PS: I'm not super familiar with the codebase, so I may not be of great assistance here. Still, I'm digging into it.

[bvaughn]

This latest reported issue should be fixed by #22745