74

I'm very confused about the output of the following component:

import { StrictMode } from "react"
import ReactDOM from "react-dom"

function Test(): React.ReactElement {
    console.log('render')
    Promise.resolve()
        .then(() => console.log('then ' + Math.random()))
    return <></>
}

ReactDOM.render(
  <StrictMode>
    <Test />
  </StrictMode>,
  document.getElementById("root")
)

It produces the following output at least in Chrome and Firefox:

00:46:30.264 render
00:46:30.267 then 0.5430663800781927
00:46:30.267 then 0.9667426372511254

I would rather expect to see the same count of messages. What am I missing?

Repro: https://codesandbox.io/s/elegant-frost-dmcsl

EDIT: I know that strict mode leads to extra rendering, but as stated, I would then expect the same count of messages.

EDIT 2: Both answers below are great. I would like to cite comment of @user56reinstatemonica8 here:

Relevant: Community feedback on console silencing

2
  • 1
    Please add all of the code to reproduce this issue, not just a link to the sandbox. The <StrictMode> is actually key to your issue.
    – zero298
    Jul 7, 2021 at 19:26
  • 3
    Yeah, but why render is printed only once? Jul 7, 2021 at 19:28

3 Answers 3

85

In React strict mode react may run render multiple times, which could partly explain what you see.

But you correctly wondered if that was the case and render was called multiple times, why was render not printed twice too?

React modifies the console methods like console.log() to silence the logs in some cases. Here is a quote:

Starting with React 17, React automatically modifies the console methods like console.log() to silence the logs in the second call to lifecycle functions. However, it may cause undesired behavior in certain cases where a workaround can be used.

Apparently, it doesn't do so when the console.log is called from Promise callback. But it does so when it is called from render. More details about this are in the answer by @trincot.

2
  • 4
    …and that's also why you shouldn't schedule asynchronous callbacks (or worse, start asynchronous work) from inside the render method, but only from effects - an effect would run only once.
    – Bergi
    Jul 8, 2021 at 13:20
  • 31
    @Bergi That's actually the reason why a random framework shouldn't touch system function (which are commonly used for debugging) to do unexpected things.
    – Sulthan
    Jul 12, 2021 at 22:17
44

There is a second run of your render function when strict mode is enabled (only in development mode), but as discussed here, React will monkey patch console methods (calling disableLogs();) for the duration of that second (synchronous) run, so that it does not output.

The changelog shows this code was inserted in packages/react-reconciler/src/ReactFiberBeginWork.js in order to temporarily suppress logs (insertions marked with comment):

  if (__DEV__) {
    ReactCurrentOwner.current = workInProgress;
    setIsRendering(true);
    nextChildren = renderWithHooks(
      current,
      workInProgress,
      render,
      nextProps,
      ref,
      renderExpirationTime,
    );
    if (
      debugRenderPhaseSideEffectsForStrictMode &&
      workInProgress.mode & StrictMode
    ) {
      disableLogs();       // <--
      try {                // <--
        nextChildren = renderWithHooks(
          current,
          workInProgress,
          render,
          nextProps,
          ref,
          renderExpirationTime,
        );
      } finally {          // <--
        reenableLogs();    // <--
      }                    // <--

Here is a version of your code that demonstrates it really runs twice:

var i = 0;
var myconsolelog = console.log; // Work around React's monkeypatching 

function Test(): React.ReactElement {
    i++;
    myconsolelog(i + ". render"); // will output twice now!
    Promise.resolve(i)
        .then((i) => console.log(i + ". then " + Math.random()));
    return <></>;
}

In my opinion, this log-suppression is a really bad design choice.

6
  • 2
    Yes, see in this changelog, and see the pair disableLogs and reenableLogs around the call of renderWithHooks. Info added to answer.
    – trincot
    Jul 7, 2021 at 19:41
  • 13
    Yeah... no idea why they felt the need to monkeypatch console methods. I understand that this second render may be a surprise... but IMHO it would have been better to write a debug message saying "Starting second rendering of component X, see https://blah for why this happens in development mode", i.e. they should have added their explanation of why the logs repeated instead of silencing them... Given that there are any number of other ways in which the user can detect the double render it doesn't really make sense to hide it...
    – GACy20
    Jul 8, 2021 at 7:09
  • 3
    Yeah, or to reduce noise, at the start of the second render cycle, they could do something like console.groupCollapsed('Starting dev-only second render, see [link] for info'), run console.groupEnd at the end, and capture all second-render log messages in a collapsed accordion. Minimal noise, no hidden surprises, clear what's happening. Jul 9, 2021 at 9:43
  • 6
  • 1
    I agree, this monkeypatch is a bad choice. Maybe, their devs use console.log quite often? ;)
    – Newlukai
    Jul 15, 2021 at 10:13
2

In case it might help anyone, you can monkey-patch Object.defineProperties to ignore any changes made to the console object, effectively preventing ReactDOM from monkey-patching console.log.

const defineProperties = Object.defineProperties;
Object.defineProperties = function (o, props) {
  return o === console ? o : defineProperties(o, props);
};

Make sure to put this in development mode only (e.g. in create-react-app when process.env.NODE_ENV === 'development'), so that it doesn't end up in the production build.

4
  • Wouldn't it be better to freeze console instead of patching things further? Feb 23, 2022 at 23:11
  • If you freeze console, then React's attempt to patch console will throw an error, effectively blowing up the whole app.
    – xemlock
    Feb 24, 2022 at 11:48
  • Is it confirmed that defineProperties is used by React to patch? From what I see, it's regular assignment, which won't cause an error for frozen properties. Feb 24, 2022 at 13:34
  • 1
    Yes, console is patched with Object.defineProperties, as can be seen here: github.com/facebook/react/blob/v17.0.2/packages/shared/… (most recent version of React, as of Feb 2022). This results in errors like "TypeError: Cannot redefine property: info" being thrown from react-dom internals, if the console has been frozen.
    – xemlock
    Feb 25, 2022 at 14:36

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.