javascript - Why is `Promise.then` called twice in a React component but not the console.log?

Question

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.

Answer 1

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 an asynchronous callback. But it does so when it is called from render. More details about this are in the answer by @trincot.

Answer 2

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 
export default function App() {
  i++;
  myconsolelog("render " + i); // 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.