whatwg / console

Console Standard
https://console.spec.whatwg.org/
Other
272 stars 69 forks source link

Extending the console to improve developer experience #163

Open bvaughn opened 5 years ago

bvaughn commented 5 years ago

This issue is meant as a conversation starter around tools like React DevTools. The following GitHub issues provide some additional background context:

This issue relates to both logging and call stacks. I'll try to keep this issue mostly focused on the logging/console aspect but there will be some overlap.

Summary

At a high level, it would be nice if there were a way for frameworks or extensions to extend console methods (like console.error) without exposing themselves in the stack that the browser captures.

I'll use React and the React DevTools as an example. We recently added a feature to auto-append some additional info- referred to as "component stack" (explained below) to error logs. We do this because the call stack alone is often insufficient to identify the cause of an error. Conceptually, I think this is similar to the async call stack feature in terms of how it helps developers identify problems and debug their code.

The only mechanism we currently have to append this information is to override the built-in console method, e.g.

const originalConsoleMethod = console.error;
console.error = (...args) => {
  // Override logic...
  originalConsoleMethod(...args);
};

Unfortunately this means our override method is the top stack frame, so it's observable along with the error being logged:

Example console.error override with annotations

It would be nice if there were a way for us to tell the console to ignore, or skip over, the top most frame (our override method) like it does with its own internal methods.

It would also be nice if the appended "component stack" were an actual, clickable stack rather than just an appended string of text.

Althoguh the above example shows console.error being called from within a component (in user code). In many cases, React itself might log what logs the error, even though it's about a component.

Example console.erorr override with annotations

In this example, the relevant user code (React component) isn't even in the call stack anywhere, only in the appended "component stack". It would also be nice if there were a way for us to add it.


What are "component stacks"?

React applications are trees of components. These trees are built at runtime by "rendering" each component.

Here's an example app:

// Example.js
function Example() {
  return <List items={["one", undefined, "two"]} />;
}

// List.js
function List({ items }) {
  return (
    <ul>
      {items.map(text => (
        <ListItem key={text} text={text} />
      ))}
    </ul>
  );
}

// ListItem.js
function ListItem({ text }) {
  if (!text) {
    console.error('Required property "text" is missing');
  }
  return <li>{text}</li>;
}

The above code can be thought of as a tree:

<Example>
  <List>
    <ListItem>
    <ListItem> <- The error was here
    <ListItem>

Some things of note about this tree:

With recursive code, this sort of thing more or less "just works". However because of React's concurrent rendering mode, it processes the tree iteratively. This means that at the time our example error is logged, the JavaScript callstack doesn't provide enough information to identify where the source of the problem is:

Example of why iterative stack isn't that useful

The above call stack mostly consists of React internals. While it's helpful and meaningful to those of us working on React, it isn't all that helpful to most application developers when it comes to finding the source of their problem.

bvaughn commented 5 years ago

Related "tag stack" issues:

bvaughn commented 5 years ago

I don't want to get tangled in implementation strategies too early, but it seems worth mentioning some additional concerns related to a stack-capturing approach like mentioned in the above issues.

  1. It would probably make the most sense to "capture" these stacks in createElement, but this could be expensive- especially if we don't actually end up needing the stacks in most cases. (Since the browser is already capturing the stack though, maybe this could be made fast enough as to not be a concern.)

  2. When updating an app, React may only re-render part of the tree. (We may want to log an error from a component even though we didn't re-render it's ancestors.) We could potentially track and reuse the "captured" stacks from a previous render, but we wouldn’t want to attach the full original stack, only the top frame, because the parts above that would probably not be relevant to the update operation.

For example, React apps often update in response to user input (keyboard event or click event). The event handler schedules an update with React and React later1 decides which components in the tree need to be re-rendered, etc.

If an error is logged somewhere deep in the tree during such an update, there are two unfortunate things currently:

  1. The call stack only contains at most, one React component (as shown in the original issue above) so it may not give the user enough info to identify where the problem is coming from.
  2. The call stack likely won't contain any of the code that scheduled the update with React.

Ideally we could construct a call stack that includes at least the full component stack if not also the source of the update2. If we needed to re-use captured stacks from previous renders though, the frames above a given React component would probably not be relevant- since they would correspond to the code path that previously rendered a given component, rather than e.g. the click handler that scheduled the update.

1 I say "later" because there is often at least one tick between these two events, maybe longer. 2 React may also batch multiple updates into a single render, so connecting the source of the update to any particular warning later might just be too hard to do.

JoelEinbinder commented 5 years ago

For example, React apps often update in response to user input (keyboard event or click event). The event handler schedules an update with React and React later1 decides which components in the tree need to be re-rendered, etc.

Can you provide some code for this? I'm having trouble visualizing exactly whats going on.

bvaughn commented 5 years ago

Here's a Code Sandbox: https://codesandbox.io/s/silly-agnesi-07ro8

The console log demonstrates that the initial "mount" renders the App component once and the Button component twice (once for each usage) but the "update" that happens after a click only renders a single Button component.

Here's the warning stack that's logged during mount: Screen Shot 2019-07-18 at 9 58 46 AM

If you click on the "unknown" button, here's the warning stack that will be logged: Screen Shot 2019-07-18 at 9 59 33 AM

Couple of things this illustrates:

Regarding my note about "later" above- if I were to use the concurrent rendering mode, the update stack would also not include the event dispatch either: Screen Shot 2019-07-18 at 10 02 34 AM

dcrousso commented 5 years ago

Rather than create an entirely new console function, why not follow a similar route as function.displayName and create a Error.prototype.set displayStack or Error.prototype.set customStack (like Error.prototype.stack) that the engine can then decide to use in leu of (or in addition to) the actual JavaScript stack?

For what it's worth, Web Inspector tries to detect when a logged string looks like a stack trace, and presents it as such in the UI.

bvaughn commented 5 years ago

I'm not sure how setting a display property on Error.prototype would help with the console issues mentioned above (since there often isn't an actual error in those cases). Maybe I'm misunderstanding something?

dcrousso commented 5 years ago

@bvaughn Required property "label" missing seems like an error to me. The examples you gave in your original post even used console.error.

bvaughn commented 5 years ago

@bvaughn Required property "label" missing seems like an error to me

This is just an example. There are lots of things that are warnings in this category (e.g. "Foo has been deprecated and will be removed in the upcoming release")

In either case, there is no actual Error when you call console.error. The console shows the stack trace from where the call was made.

domenic commented 5 years ago

Let me note a connection to https://github.com/tc39/proposal-function-implementation-hiding which myself and @michaelficarra are working on. See especially https://github.com/tc39/proposal-function-implementation-hiding/issues/23 which summarizes some of the latest discussion.

One thing to keep in mind is that the console's stack trace is different from error.stack. They are probably correlated in current implementations (e.g. the stack shown by console.error() is similar to that that would be shown by console.log((new Error()).stack)). But there is no requirement on the console's output, and it's generally more helpful (e.g., interactive) than error.stack

In summary I don't think proposal-function-implementation-hiding is going to help that much, so it is best to continue pursuing this as part of the console work. But I wanted to make a note.

Finally I'll also note that the non-standard function.displayName is deprecated in favor of the standard function.name, and I've been trying to get Chrome to stop supporting it for some time without success. I don't think it's a model we should follow.

bvaughn commented 5 years ago

Thanks for the pointer @domenic!

That could be useful for the console override approach this issue outlines, making it less observable. Agreed it wouldn't be sufficient for this proposal on its own though 😄

pavelfeldman commented 5 years ago

@hashseed, @ak239 should we use this ^^ issue to explore stack tagging?

hashseed commented 5 years ago

General goal makes sense to me. But I'm uncertain how standardization would work, considering that Error.stack nor console outputis standardized.

tajo commented 5 years ago

Is there going to be a way to print out the component stack in node env? DevTools are great but it doesn't help much when the app is SSRed and dead before even hitting the browser. I was really excited about the original React.error API since it would make error messages of some of our React libs much better.

bvaughn commented 5 years ago

@tajo Discussion about React-specific APIs should probably happen in the React repo 😄 An abstract concept of something like React's component stacks is relevant to this issue, but an API that exposed component stacks to application code wouldn't really be.

tajo commented 5 years ago

Ah oops, I didn't realize this is not a React repo.

bvaughn commented 3 years ago

FWIW relevance and importance of this issue is coming up again due to a recent change on the React side: https://github.com/facebook/react/issues/22257#issuecomment-915250655

@domenic It doesn't look like there's been any movement on the tc39 proposal you linked to. Any other relevant proposals my team could throw our support behind? (Or anything else you'd suggest us doing?)