Community feedback on console silencing

[billyjanitsch]

Hi, I know this issue has been discussed endlessly so I apologize for bringing it up again. I hope this issue is net helpful. 🤞

Quick summary: as of #18547, React 17 silences console logs during the second rendering pass in strict mode, in dev. It's a trade-off between the confusion of logging multiple times for a single render pass and the confusion of only logging once even though the code was actually called twice.

Note that there's an outstanding PR to make it configurable (#19710) but it seems to be stalled awaiting review.

Since the change was released, I've seen a number of issues in which folks have been confused by the behavior, e.g.:

• Bug: useRef acting weird in Strict mode. #20835
• Bug: useMemo exec twice in StrictMode,But console.log only exec once,console.debug exec twice #20982
• Bug: React hijacks console functions that may cause unpredictable behavior. #20367
• In StrictMode, the useState() initializer function is called twice, but one of the results is discarded #20090
• Bug: strict mode, initial state changes, and useMemo (with dependency) doesn't seem to be recomputed #21178
• The number of console.log calls in setState is incorrect #21126
• Bug: It seems that the default value in functional React component gets updated after render. #20851
• Bug: disableLogs mutates console #20575

The response from the core team has generally been that, yes, this behavior can be confusing, but the previous behavior was equally if not more confusing. It's a trade-off without a clear answer. (Examples: 1, 2, 3.)

I totally understand this perspective and I've tried to internalize it, but, frankly, the longer it's been since the release, the more it seems to me like the new behavior is actually just significantly more confusing for most people. My signal is:

1. Anecdotally, it's a recurring source of confusion within my company, much more so than the old behavior was. It's also probably the source of the most "oh, that's weird" reactions (vs. "oh, I get it now") when explained, compared with other React nuances.
2. The change was only released 8 months ago and there are already many GitHub issues expressing confusion about it, seemingly more than there ever were for the old behavior. (There used to be more instances where people weren't aware that strict mode double-invokes components, but it's not that the new behavior makes this any more clear, it just means that fewer people are now learning this fact, which doesn't seem good?) The rate of new issues also doesn't seem to be slowing as was hypothesized.
3. The implementing PR (#18547) currently has 19 downvotes vs. 2 upvotes. Obviously people who dislike the change are more likely to downvote, but PRs are rarely this controversial and in fact this is the most downvoted non-docs PR in the whole repo.

Altogether, the change was clearly well-reasoned and well-intentioned, but now that it's had some time to settle, what I'm asking is:

1. Does my perspective on the community reaction align with your perception?
2. Have you observed a different reaction internally at FB?
3. In aggregate, does any of this change your original perspective at all?

I hope this is a fair take and a helpful set of questions to ask. Thanks for taking the time to read.

---

(FWIW, if I had to guess, I'd propose that one reason for the new behavior being more confusing is that the old behavior is only confusing until you learn that strict mode = double render, whereas the new behavior continues to be confusing after you learn it because there are subtleties. e.g., "which pass gets silenced again?", "oh, right, it's the second one, so if you log a value and render it, the console might show something different than the screen", "what about when you set state in render?", "what about refs?", etc.)

[Bessonov]

I was confused myself and asked this question. Despite it was only 3 days ago, the question got 27 upvotes.

[emileber]

The old behaviour was confusing to anyone new to React, until they learned about it.

The new behaviour is now confusing even to veteran users of React, even if they knew about StrictMode and even after learning about the new silencing.

In my opinion, it's now a trap anyone could fall into.

[gaearon]

The old behaviour was confusing to anyone new to React, until they learned about it.

The problem with the old behavior wasn't just that it was confusing — it was that it's actively interfering with product code debugging. The duplication was creating a lot of noise.

The problem with the new behavior is that it's also interfering with debugging — but specifically for double rendering issues. If you're not debugging specifically double rendering issues, I wouldn't say it's confusing. But when you are, it's confusing in a much deeper way.

So from my perspective it's a tradeoff between a medium level annoyance in a common scenario (old way) against a very high level annoyance in a relatively less common scenario (new way).

Obviously both of them are annoying and I totally understand the perspective that the tradeoff is not worth it. (There's no real need to explain why in each follow-up comment — I think we all understand what the confusing parts are.)

Personally, I don't think either of the tradeoffs are great options. I wonder if there's something in the middle that would be better. At least having a way to opt in/out of the silencing seems like it would be very useful. Regardless of the default. So this seems like a clear first step.

Maybe if this is integrated into DevTools, the default could be changed but with a message printed before any double logs warning you why they happen (and suggesting you to pick a preference in DevTools). And then if you pick a preference in either direction, it doesn't bug you again. (I'm just throwing things out there — not sure this makes sense!)

[ondrejhanslik]

Frankly, everytime developers thinks that they can improve something by changing the behavior of a system method, then they should return to school.
Javascript is a bad language, full of traps. There is no need to come and create another trap by changing the expected behavior of a method. If you have troubles with with logging, come with a custom logging system and use that instead.
Also, I think you are hugely overestimating the number of people who actually debug double-rendering issues.

[gaearon]

Let's keep this conversation polite; there is no need to tell people to "go back to school" and so on. Your point is well-understood without that.

I think you are hugely overestimating the number of people who actually debug double-rendering issues.

That to me speaks in favor of silencing because unless you're debugging double-rendering issues specifically, seeing the logs without duplication is more convenient. It's only when you're debugging double-rendering issues that this distinction starts mattering. (But I fully agree that it can be deeply confusing in that scenario.)

[billyjanitsch]

So from my perspective it's a tradeoff between a medium level annoyance in a common scenario (old way) against a very high level annoyance in a relatively less common scenario (new way).

@gaearon Thanks for explaining your perspective. I don't think my opinion has changed but this helps me understand a different way to see the trade-off. I wonder if the scale/structure of FB product eng makes the common case more common than it is elsewhere? Anecdotally, folks at my company put console logs in render to understand render cycles about as often as they do to inspect values, so in that world it feels more like a minor vs. high level of annoyance in equally common scenarios.

At least having a way to opt in/out of the silencing seems like it would be very useful. Regardless of the default. So this seems like a clear first step.

I agree that a toggle would be very helpful. At a glance, the PR I noted (#19710) seems like a complete implementation, and appears to have new code pushed since you and @bvaughn last reviewed it. Do you recall if this is a question of time/prioritization, or if there were concerns with the approach? I can offer some help if it's something like the latter and the original author isn't available.

Maybe if this is integrated into DevTools, the default could be changed but with a message printed before any double logs warning you why they happen (and suggesting you to pick a preference in DevTools). And then if you pick a preference in either direction, it doesn't bug you again.

This makes a lot of sense to me. Perhaps DevTools could also print a message on init if strict mode is enabled in any part of the app and a preference hasn't yet been chosen? Something along the lines of: "Strict mode is on; click here to read more about what this means; click here to set a preference for how to handle logging." So that it's less of a surprise when it happens later.

That to me speaks in favor of silencing

I think that @ondrejhanslik meant "underestimating". @ondrejhanslik, I agree with some of your sentiment but consider that this kind of language can make it less likely that this will be changed. React is made by humans for humans and kindness goes a long way. 🙂

[bvaughn]

At a glance, the PR I noted (#19710) seems like a complete implementation

Unfortunately, the PR you linked to wouldn't implement the functionality you're describing. The shared patching methods it override in the DevTools build are compiled into the react-dom bundle (separate copy, like everything else in packages/shared).

Implementing this functionality would require adding an additional interface between react-dom (and other renderers) and React DevTools

[billyjanitsch]

The shared patching methods it override in the DevTools build are compiled into the react-dom bundle (separate copy, like everything else in packages/shared).

@bvaughn Thanks for the context. If you have the time to dive in:

My understanding of the PR implementation was that toggling the setting in DevTools would set a global variable on the app page, which would then be read by react-dom (or other renderer) while deciding whether to patch the console on a given render. So I don't immediately see why the separate copy is a problem, or why an interface is necessary. Is the issue that the window on which __REACT_DEVTOOLS_SUPPRESS_DOUBLE_LOGGING__ is set is actually the DevTools window rather than the app window, so an interface is in fact the only way for DevTools to set a value that a renderer can read?

Implementing this functionality would require adding an additional interface between react-dom (and other renderers) and React DevTools

Assuming this is necessary, do you think it would be a reasonable self-guided task for an external contributor, or do you think it requires a core member's time? I saw the contributing guide you posted recently. Happy to take a look if you think it's within reach.

[gaearon]

Anecdotally, folks at my company put console logs in render to understand render cycles

Can you clarify a bit more what you mean about understanding render cycles? Since double rendering is "shallow" (it happens at each leaf call), it seems like it is easier to understand the actual render cycle with silencing. Since then the noise is reduced and you see the actual order in which React walks the components.

My understanding of the PR implementation was that toggling the setting in DevTools would set a global variable on the app page, which would then be read by react-dom (or other renderer) while deciding whether to patch the console on a given render.

That is also how I interpreted it! I'm probably missing something @bvaughn is seeing but I'd appreciate a clarification here too because I thought something like this should work.

[bvaughn]

My understanding of the PR implementation was that toggling the setting in DevTools would set a global variable on the app page, which would then be read by react-dom (or other renderer) while deciding whether to patch the console on a given render.

That is also how I interpreted it! I'm probably missing something @bvaughn is seeing but I'd appreciate a clarification here too because I thought something like this should work.

@billyjanitsch @gaearon My bad for not taking more time when writing my response. The PR would work kind of but not in the way I think it should.

You're right that the code in packages/shared would check for a global variable, but the check is done during module init

const {__REACT_DEVTOOLS_SUPPRESS_DOUBLE_LOGGING__: suppressLog} = canUseDOM
  ? window
  : global;

That means your setting wouldn't take place unless you changed it in DevTools and then reloaded the page. I think this is confusing because similar settings (e.g. component filters, inline errors/warnings) apply immediately.

I also don't think we should couple global DevTools variables with code in packages/shared like this. Dependencies between the two should be done via the Flow-typed injected interface (like error boundary toggles #21583 or suspense toggles #15232). That is what I meant by this comment: #19710

That code wasn't written to be turned on or off externally (by something like DevTools). It's built into React. Allowing DevTools to control it (via a new setting like the one you're proposing) would require updating React as well.

I hope this answer is clearer. Sorry for my rushed response earlier.

Implementing this functionality would require adding an additional interface between react-dom (and other renderers) and React DevTools

Assuming this is necessary, do you think it would be a reasonable self-guided task for an external contributor, or do you think it requires a core member's time? I saw the contributing guide you posted recently. Happy to take a look if you think it's within reach.

Assuming it's something the team agrees to accept/land, I think it could be a self-guided task, following the precedent of the PRs I mentioned above and the new contributing guide.

I'm not sure how I feel about this change. @gaearon: Let's bring it up during the next core sync and see how others feel? If there's consensus that it's okay, I'll shepherd it through.

[emileber]

I wonder if there's something in the middle that would be better.

For what it's worth, people commented on the SO question with the following suggestions:

[...] 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" - GACy20

[...] 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. - user56reinstatemonica8

Sorry if this was already discussed/considered! 😅

[bvaughn]

[...] 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" - GACy20

[...] 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. - user56reinstatemonica8

React double-renders components as it goes along. (It doesn't re-traverse the whole tree.) Such a message would be printed a lot of times (which would be really noisy).

[emileber]

Good point!

Maybe prefixing/suffixing duplicate renders logs would reduce the noise, coupled with an option to opt-out of logging (silencing), as discussed above, would help minimize any surprise and/or confusion? Though I'm not of fan of hijacking the console.

If the option is ever added, I feel it would be great to have it mentioned in the console log for discoverability when strict mode is used in dev.

Even a log informing the user of strict mode being used would greatly help as I've seen/closed a lot of questions on Stack Overflow about the initial duplicate logs with strict mode in the past (mostly the reason I'm commenting here).

[bvaughn]

If the option is ever added, I feel it would be great to have it mentioned in the console log for discoverability when strict mode is used in dev.

Even a log informing the user of strict mode being used would greatly help as I've seen/closed a lot of questions on Stack Overflow about the initial duplicate logs with strict mode in the past (mostly the reason I'm commenting here).

I think I understand the reason for this request, but I'm really wary of console warnings like this. Noisy consoles make developers pretty angry, and unfortunately we can't just show it once and save a cookie– because people don't keep the console open until they need it (so such a one-time-only warning would be missed in most cases).

I do understand the frustration here. It sucks to lose time investigating something weird only to find out that a framework or tool has done something clever and unexpected. I like the idea of using DevTools to improve experiences like this, but I'm not sure how we teach people to look to DevTools for this sort of thing. Hopefully our new docs (which will have a dedicated DevTools section) can help with this.

[gaearon]

I think I understand the reason for this request, but I'm really wary of console warnings like this. Noisy consoles make developers pretty angry, and unfortunately we can't just show it once and save a cookie– because people don't keep the console open until they need it (so such a one-time-only warning would be missed in most cases).

My proposal here would be that we show a message until you explicitly pick a preference in DevTools. So you can "shut up" the message by making a choice in the settings. So it's a bit noisy but it shows once per session and you can make it disappear forever by installing DevTools and choosing a preference (in either direction).

[bvaughn]

My proposal here would be that we show a message until you explicitly pick a preference in DevTools. So you can "shut up" the message by making a choice in the settings. So it's a bit noisy but it shows once per session and you can make it disappear forever by installing DevTools and choosing a preference (in either direction).

I'm concerned that this feels heavy handed. We're essentially forcing people to install a browser extension (that may have performance implications) and to leave it enabled to opt out of otherwise annoying console spam.

I love DevTools and I'd love to see more people install it and use it, but I'm concerned about this approach.

[gaearon]

We're essentially forcing people to install a browser extension (that may have performance implications) and to leave it enabled to opt out of otherwise annoying console spam.

That's already the case though. We show a console message at the start every time if you don't have DevTools installed. So it's not that different from what we already do.

[gaearon]

Oooh. Actually this got broken due to Fast Refresh. Fast Refresh integrations are being detected as DevTools hook so we're not actually showing that log anymore.

[bvaughn]

That's already the case though. We show a console message at the start every time if you don't have DevTools installed. So it's not that different from what we already do.

I forgot we did that 😂

I guess we could expand that message then? (I don't think we should log something every time we double render, regardless.)

[gaearon]

Yeah. Maybe the message could be different depending on:

1. Whether you run in StrictMode
2. Whether you have DevTools
3. Whether you picked an explicit preference in DevTools

And then there is no message if you have extension, and either are not in StrictMode, or you are in StrictMode but have picked a preference in DevTools.

[bvaughn]

Something like that seems reasonable, yeah.

[billyjanitsch]

You're right that the code in packages/shared would check for a global variable, but the check is done during module init

@bvaughn I noticed this too and agree that it's undesirable, but it seemed simple to fix (by reading the variable in disableLogs and reenableLogs instead). But...

Dependencies between the two should be done via the Flow-typed injected interface (like error boundary toggles #21583 or suspense toggles #15232).

...that totally makes sense. Thanks for linking those implementation examples. 🙂

Let's bring it up during the next core sync and see how others feel? If there's consensus that it's okay, I'll shepherd it through.

Let me know how the sync goes. Happy to help if you're willing to accept the change but don't have time to work on it.

And then there is no message if you have extension, and either are not in StrictMode, or you are in StrictMode but have picked a preference in DevTools.

@gaearon I like this approach a lot.

Thank you both for your time spent considering.

[markerikson]

Just to toss in a couple more cents:

Agreed that this is a constant source of confusion, especially at the beginner/learner level.

I think that the suggestions for altering behavior and the messages based on setup and DevTools config options sounds like an excellent idea and a very good candidate for improving this situation.

And I really appreciate the quality discussion in this thread from both sides! Good issue writeup, great explanation of tradeoffs, some brainstorming, offers of assistance, and some forming consensus. That's some nice OSS collaboration in action :)

[rhagigi]

TIL about this, and I agree it's really confusing (both before and after the silencing). The silencing here makes it really difficult to debug double-rendering issues and causes confusion when I'm trying to explain that constructors/renders run twice in StrictMode.

I think I agree that a console message that at least tells you that react has silenced a double-rendered console.log even one time would be ideal here. We'd only need to print the message if a console.log is silenced. Otherwise we don't need to console.log it at all.

React double-renders components as it goes along. (It doesn't re-traverse the whole tree.) Such a message would be printed a lot of times (which would be really noisy).

And this is why I think we should only print it once and only if a console.log() is actually silenced.

For example, right now react sets this like:

function disabledLog() {}

export function disableLogs(): void {
  if (__DEV__) {
    /* skipped some stuff for shorter comment */
    console.log = console.info = console.warn = console.error = disabledLog;
  }
}

What if instead, it set it like...

let hasWarned = false;
function disabledLog() {
  if(!hasWarned) {
    hasWarned = true;
    console.warn('React is silencing console.logs in second renders in Strict Mode. All Future Console.logs will be silenced. Follow X steps to turn off second-render console log silencing.'); 
     // but, you know, with better copy... 
     // and maybe re-console-log this *first* console.log just so they see that it did log "twice" and why - but we explain
    // that all future calls will be silenced
  }
}

export function disableLogs(): void {
  if (__DEV__) {
    /* skipped some stuff for shorter comment */
    console.log = console.info = console.warn = console.error = disabledLog;
  }
}

This would be similar to how we console.log non-fatal errors in production code at FB:

[bvaughn]

Yeah, we'd only print such a message once (per session) if we added it. (Similar to how we only print other DEV messages once to avoid clogging the console.) My comment above was more meant to point out that we really wouldn't want to print a message before every time we silenced the console.

I think we could go further still than the code example shown above, and only print the message if a component actually tried to log a message to the silenced console, e.g.

diff --git a/packages/shared/ConsolePatchingDev.js b/packages/shared/ConsolePatchingDev.js
index ed7f7f7d18..4c5618f3eb 100644
--- a/packages/shared/ConsolePatchingDev.js
+++ b/packages/shared/ConsolePatchingDev.js
@@ -21,7 +21,16 @@ let prevGroup;
 let prevGroupCollapsed;
 let prevGroupEnd;
 
-function disabledLog() {}
+let hasWarnedAboutDisabledConsoleLog = false;
+function disabledLog() {
+  if (!hasWarnedAboutDisabledConsoleLog) {
+    hasWarnedAboutDisabledConsoleLog = true;
+
+    // Print the double-render silenced console notice here.
+    // This way if no double-rendered components use the console,
+    // we won't print the message unnecessarily.
+  }
+}
 disabledLog.__reactDisabledLog = true;
 
 export function disableLogs(): void {

[rhagigi]

That is exactly what I just suggested @bvaughn... 😄

[bvaughn]

I misread your suggestion as (always) printing the notice the first time before we started double render. My bad.

[bvaughn]

See #21889 for a proposed solution for this, based on community feedback and discussion with the core team. #21890 also shook out of an earlier discussion as a follow-up item.