process: add 'warning' event

[jasnell]

In several places throughout the code we write directly to stderr to report warnings (deprecation, possible eventemitter memory leak). The current design of simply dumping the text to stderr is less than ideal. This PR introduces a new "Process Warnings" mechanism that emits 'warn' events on the global process object. These are invoked with a Warning object that is similar in structure to an Error in that they have a name, message and stack trace.

By default, these warnings will be printed to stderr. This can be suppressed using the --no-warnings command line flag, however the 'warn' event will still be emitted by the process, allowing applications to handle the warnings in custom ways.

The --trace-warnings command line flag will tell Node.js to print the full stack trace of warnings as part of the default handling.

The existing --no-deprecation, --throw-deprecation and --trace-deprecation flags continue to work as they currently do, but the exact output of the warning message is modified to occur on process.nextTick(). The stack trace for the warning, however, is preserved and shows the correct call site.

Test cases and documentation are included.

Refs: https://github.com/nodejs/node-eps/pull/4#issuecomment-173079195

[mscdex]

I think it might be useful to have an additional (standard) property on the error/warning object that indicates the type of warning (e.g. security warning, deprecation warning, etc.).

[ChALkeR]

I wasn't able to find uses of warning event on the process object in the npm modules, so it should be safe to add it.

[benjamingr]

https://github.com/petkaantonov/bluebird/issues/980 - but that's intentional and bluebird will align itself to whatever semantics you'll choose.

On Wed, Feb 17, 2016 at 10:49 PM, Сковорода Никита Андреевич < notifications@github.com> wrote:

I wasn't able to find uses of warning event on the process object in the npm modules, so it should be safe to add it.

— Reply to this email directly or view it on GitHub https://github.com/nodejs/node/pull/4782#issuecomment-185396820.

[ChALkeR]

@benjamingr My data is from 2016-01-28 =).

[geek]

This muddies a simple problem with a lot of unnecessary complexity. SecurityWarning is added but never even used, for example. I would even argue that the implementation of BadPracticeWarning isn't even a warning at all, its really an error on the part of the programmer, and should be output to stderr. Furthermore, if this is considered a warning, and is reasonable to ignore, changing the max listeners count is completely reasonable.

Of these, only the deprecation example makes sense as a warning. But, as pointed out, this can be easily suppressed and controlled with the --no-deprecation, --throw-deprecation and --trace-deprecation flags.

If the goal is to allow applications to handle warnings or errors in custom ways, a reasonable solution is simply to extend Error and add a property to node error objects in order to identify the type of error that they represent.

[rvagg]

Was briefly discussed this at the CTC meeting last week, not to make decisions but to make sure there was awareness. Removing the label for now, it can be added back if outstanding issues can't be resolved via the normal means. The lack of additional CTC comment suggests that there are no strong feelings about it at that level.

[benjamingr]

Great awesome news @rvagg

[geek]

@rvagg is there any interest in a simpler solution? If so, I can contribute a PR.

[jasnell]

We can iterate on this one perhaps. What are you thinking as far as simpler? On Feb 24, 2016 9:51 AM, "Wyatt Preul" notifications@github.com wrote:

@rvagg https://github.com/rvagg is there any interest in a simpler solution? If so, I can contribute a PR.

— Reply to this email directly or view it on GitHub https://github.com/nodejs/node/pull/4782#issuecomment-188378808.

[geek]

@jasnell assuming that I understand the problem and goal:

If the goal is to allow applications to handle warnings or errors in custom ways, a reasonable solution is simply to extend Error and add a property to node error objects in order to identify the type of error that they represent.

[dougwilson]

The entire Express.js code base deals with deprecations in a similar way, hooking into --*-deprecation process flags and emitting deprecations as a deprecation event on the process object to allow hooks into logging. The objects emitted are also inherited from Error, to provide not only stack traces, but integration into logging tools like Winston that already know how to serialize these types of objects. Providing a fallback to print to console with this is a little harder than Express.js has to deal with, as since Express.js is emitting the events, it can just choose to print if there are no listeners.

Express.js further provides mechanisms to suppress deprecations on a module-by-module basis, rather that only all or nothing (though you can do all-or-nothing, either by using the --no-deprecation command switch, or by telling it to ignore all modules).

Anyway, I just happened to stumble on this issue and just wanted to provide my 2c on what Express.js has been doing for almost 2 years now.

Eventually, it would be awesome if the projects under the Node.js foundation could coordinate with each other :)

[rvagg]

@geek the CTC hasn't signed off on this, it's just been discussed for the sake of raising awareness, that was done, obviously nobody felt strongly enough to drop in and add their feedback, but that doesn't imply CTC sign-off. If you have concerns then let's see if we can address them, as a collaborator you have the right to be heard on this if you feel strongly enough.

FWIW @jasnell, I'm just noticing that there isn't an LGTM in here. With the warned parameter taken care of and when the Error.call(this) calls are added this LGTM. I suspect I'm comfortable with this for similar reasons as you, having a Java background (I have no qualms making custom errors). But I think @geek might be raising a point that it's not exactly idiomatic Node or even JavaScript to be extending Error, mostly we just throw custom properties on things rather than caring about type hierarchies.

[ronkorving]

Why is it not idiomatic JavaScript to extend Error? (new TypeError()) instanceof Error yields true. And Mozilla even has a short topic about it on MDN.

[rvagg]

TypeError is part of the language and there's only a limited set of those, an even further limited set that are actually created by developers.

$ grep -ER 'new \w+Error' lib/ | awk -F'new|\\(' '{print $2}'| sort -r | uniq -c
  97  TypeError
  13  RangeError

In that respect ^ Node core is pretty typical of what happens in userland too. You rarely see people creating custom error types. That's what I mean by it not being idiomatic.

[benjamingr]

@rvagg I'd argue that Node has a very different take than browsers in terms of what's idiomatic in terms of errors. For example, I checked the "big" frameworks (Angular, Ember, React) and:

• React for example has plenty of custom errors and error types. For example its InvariantViolation
• Angular has plenty of custom errors and error types. For example its ArgumentError.
• Ember has plenty of custom errors, namely they throw EmberErrors.

At Bluebird we have some custom errors like OperationalError. Lots of libraries do this, and node is not very representative in my experience.

Now, whether or not it's a good idea is another question.

I tend to think that predicates tend to encapsulate and better match the language. Things like e.code = ... are entirely sufficient. I think that throwing and catching by type has always been really weird in languages like Java, Python and C#. I don't think popularity is an argument on my side though.

It's worth mentioning that instanceof can be made to work without subclassing (through Symbol.hasInstance).

[rvagg]

Please take a look @ #5440 folks, it's an alternative to this approach by @geek, review/comment welcome.

[jasnell]

@rvagg ... while I agree that the extending of Error here is a bit non-idiomatic, there is a point to the madness. The way the Warning() constructor is set up currently, it enables the stack trace to be modified to show the exact call site and ensures that the warning message always contains the process and pid prefix. It goes back to the consistency point I raised in @geek's alternate PR. It adds a little bit of complexity, yes, but it's hidden behind the internal module in a way that ensures that very few devs would even need to worry about it.

Also, consider that the original version of this did not extend Error at all. That was added only after feedback indicated that it may be useful. I would be quite happy just having a simple object with name, message and stack properties as I really do not want developers mistaking this for an error handling mechanism. Seeing new Error in the code whenever a warning is being issued could make it rather confusing for developers who may accidentally interpret that as a real error.

[jasnell]

@dougwilson ... I just pushed a commit that separates out a 'deprecated' event. It also switches from using DeprecationWarning to DeprecationError although I'm not overly excited by that... I don't like calling it an Error because I don't want people treating these things like they are part of a normal error handling process.

It does work a bit differently than what is in depd so please definitely take a look when you have the opportunity. It we need to make additional tweaks to this to get it nailed down then awesome. (but fyi...the only thing is that starting in about 45 minutes I'm going to be almost completely unavailable to make additional changes until Tuesday... there's no rush on getting this done tho)

[jasnell]

@geek ... pushed an update that fixes the warning check...

[dougwilson]

It also switches from using DeprecationWarning to DeprecationError although I'm not overly excited by that... I don't like calling it an Error because I don't want people treating these things like they are part of a normal error handling process.

Yea, the fact that depd called it DeprecationError was simply because it inherited from Error and everything in core ES that did that ended with Error; I don't think that particular aspect should influence your opinion between DeprecationError and DepreactionWarning here, especially for the Node.js core objects. Since even if depd wanted to use emitWarning it would have a fork, depd can always switch to DeprecationWarning to match core if that is how core goes :)

It does work a bit differently than what is in depd so please definitely take a look when you have the opportunity. It we need to make additional tweaks to this to get it nailed down then awesome.

At this point, to keep from ballooning this pull request, the only thing I bite my lip on looking at it is the removal of our source pointer from the default output, since this listener will swallow up our output (currently, can change the module, of course :)). I've been trying to think if there is a good way to middle-ground somehow, but not sure. For example, would the default message of ${warning.name}: ${warning.message} make sense to include the first line of the stack trace (the depd module will have already altered the stack down such that the first line makes sense like in https://github.com/nodejs/node/pull/5440#issuecomment-189483453)? Not sure.

[jasnell]

Ok, I'll switch it back to DeprecationWarning and will give the formatting of the message a bit more thought. When I get a bit more time I'll dig in more on the way depd does it. I appreciate the review!

[jasnell]

Looking over the way depd does this, we ought to be able to duplicate it but it does add a bit more complexity. It also feels just a bit hackish to me since it will be trivial to write out the trace or look at the warning.stack property to get that same information (that is, it feels like more work than is necessary just to get a couple bits of information moved up into the message line). I'll play with it tho when I return to this on Tuesday.

[dougwilson]

Right, it makes it more complex, but that aspect is not even something that needs to be solved at this time in core. Perhaps this may help with my concern: I am concerned, based on supporting users for over 2 years directly, that not having enough information to location the source that is causing the message in the default message is bad for users. The reason depd goes through all the trouble is such that the default message can provide all the necessary information in as few characters as possible, rather than an entire stack trace. If you are suggesting that the default message should just be a full stack trace, that is just fine with me :)

Unfortunately the default message processing here for deprecate event will severely hurt the depd module and every module it depends on, as the stack information in the default message is at the heart of the entire purpose of the module. You can see a simple example of the benefit in https://github.com/nodejs/node/pull/5440#issuecomment-189483453

[jasnell]

Yep. I'll play around with it a bit. I have a few ideas in mind. On Feb 26, 2016 2:06 PM, "Douglas Christopher Wilson" < notifications@github.com> wrote:

Right, it makes it more complex, but that aspect is not even something that needs to be solved at this time in core. Perhaps this may help with my concern: I am concerned, based on supporting users for over 2 years directly, that not having enough information to location the source that is causing the message in the default message is bad for users. The reason depd goes through all the trouble is such that the default message can provide all the necessary information in as few characters as possible, rather than an entire stack trace. If you are suggesting that the default message should just be a full stack trace, that is just fine with me :)

Unfortunately the default message processing here for deprecate event will severely hurt the depd module and every module it depends on, as the stack information in the default message is at the heart of the entire purpose of the module. You can see a simple example of the benefit in #5440 (comment) https://github.com/nodejs/node/pull/5440#issuecomment-189483453

— Reply to this email directly or view it on GitHub https://github.com/nodejs/node/pull/4782#issuecomment-189503491.

[rvagg]

I'm sorry @jasnell (mostly just feeling sorry for you) that this has become a complicated winding process to land something that shouldn't be that complex. I don't have strong enough opinions here or the headspace to get too deeply involved but let me know if we need to get some more robust critique of the different approaches happening to try and find a way forward and I'll do my best.

[benjamingr]

Well to be fair @rvagg I think that the feature is pretty complex as it defacto standardizes how modules emit warnings that are not errors. I realize it must be frustrating to land something like this but I don't think the complexity is incidental and I do think discussing different approaches to do this is important as this is something Node will live with for many years to come.

[jasnell]

I'm not that worried @rvagg. I'm sure this will get settled out shortly and I tend towards being quite patient ;) I think it's fantastic others jump in to help things evolve. On Feb 27, 2016 1:23 AM, "Rod Vagg" notifications@github.com wrote:

I'm sorry @jasnell https://github.com/jasnell (mostly just feeling sorry for you) that this has become a complicated winding process to land something that shouldn't be that complex. I don't have strong enough opinions here or the headspace to get too deeply involved but let me know if we need to get some more robust critique of the different approaches happening to try and find a way forward and I'll do my best.

— Reply to this email directly or view it on GitHub https://github.com/nodejs/node/pull/4782#issuecomment-189610180.

[jasnell]

Going through the depd stuff more, I'm finding it difficult to justify the additional complexity necessary to pull the first line of the stack trace into the commit message. --trace-deprecation and --trace-warning are simple and the .stack property is straightforward to use. As such, I think this PR is largely just about ready to go.

@geek: how are you feeling about this now? especially with the additional bits that align it with the depd/express approach?

[dougwilson]

Perhaps there was just a misunderstanding. I wasn't saying to perform all the magic that module is doing in core, only to display the first trace in the stack of the error object my module provides. Without that, depd will never use this interface to display the messages, because it will turn into the issues I have to deal with on the MySQL modules I outlined.

[dougwilson]

Or maybe call .toString() (or something similar, like how .inspect() works) on our Error object so we can choose to stringify it how we want? Would that be a fair compromise?

[jasnell]

If depd is creating the Error objects itself and simply passes those to emitWarning, then you could keep displaying the first trace in the stack as the part of the message. At that point, all you're doing is using emitWarning to do nothing but emit the event and print the message.

[dougwilson]

The stack is not part of the message property, because that is not the message, just like the name property is not part of the message property, since it is not the message.

Can you add a way for the warning object to decide hoe it wants to be stringified just like how inspect functionality works? Even a simple .toString() could be doable if you don't want to call some added method. Without this, depd will be forced to actively disable this Node.js core feature to keep the existing features of the Express ecosystem and how upgrades are done intact, and I don't want to do that. I think allowing for the warning to define a method for how it wants to be stringified is a fair compromise. I added a comment on the diff for where that would be ideally at.

[dougwilson]

Otherwise, maybe go back to not using the deprecate event and only warning so this can be evaluated separately? Listening on the deprecate event with the current stringification will cripple the upgrade process for the Express ecosystem on those versions of Node.js until Express upgrades to disable this Node.js functionality.

[dougwilson]

Anyway, that is my concern with the change landing as-is: this deprecate event listener will cripple Express's existing upgrade process that is used to go from 3.x -> 4.x and to the 5.x alpha, so a lot of work will need to happen to address that as soon as this lands so we're not bitten too hard when this releases.

My proposal for now is the following:

Can we change the console.error(${warning.name}: ${warning.message}); to something that the warning object can calculate the string to display by default by Node.js? I'm thinking perhaps literally console.error(warning.toString()) or some such? That would display exactly that same message by default and would provide the hook we can use to display a different message than the default name + message properties.

[jasnell]

Yep, I'm just thinking through any possible ramifications of that. For now, it's time to get the kids from school and make the hour and a half drive home. Will be back on later to investigate those changes.

[jasnell]

@dougwilson ... ok, done. The default Error.prototype.toString() will be used. If the object provides it's own toString and it is callable, then that will be used. If the toString is not callable, the default will be used. Also, I made it so that if the argument is not an Error, the default handling will be ignored so we shouldn't end up with any weirdness if someone passes something odd to either the 'warning' or 'deprecation' events.

[dougwilson]

Cool, the latest commit looks good for addressing any concerns I have, as it should be the best of all words, allowing for a documented centralized mechanism for these events in node.js core and providing a way for user-land modules like depd a way to hook into the default display of their generated messages, if that is desired. :+1:

[jasnell]

Awesome. @geek ... what do you think about this so far?

[geek]

@jasnell thanks for keeping this moving along.

My vote is to split this out into a couple of PRs, the first, to deal with the deprecation event, and the second, to deal with the warning event.

The issue I see is that a deprecation warning is not an actual warning, in that it only fires the deprecation event and not the warning event. It makes sense, but I don't see the need to move the deprecation logic into the warning file, when its always going to be called from util, and its not a real warning.

[jasnell]

That makes sense. The util code can simply emit the deprecation event directly. I'm not sure it needs to be a separate PR tho. Would landing them as separate commits in the same PR suffice? I need to squash and clean up the commits anyway. On Mar 3, 2016 8:08 PM, "Wyatt Preul" notifications@github.com wrote:

@jasnell https://github.com/jasnell thanks for keeping this moving along.

My vote is to split this out into a couple of PRs, the first, to deal with the deprecation event, and the second, to deal with the warning event.

The issue I see is that a deprecation warning is not an actual warning, in that it only fires the deprecation event and not the warning event. It makes sense, but I don't see the need to move the deprecation logic into the warning file, when its always going to be called from util, and its not a real warning.

— Reply to this email directly or view it on GitHub https://github.com/nodejs/node/pull/4782#issuecomment-192090191.

[geek]

@jasnell absolutely, was thinking of ways to make them land easier. Another benefit is it will boost your commit count :)

[jasnell]

@geek... I made a number of additional changes and simplifications and squashed the commits down to one for now (it was a bit easier this way). PTAL. If after looking at it you feel there is still value in separating out the deprecation stuff into a separate commit, I will reswizzle it a bit more and separate those out. Just let me know.

[jasnell]

@geek ... nits addressed, rebased and updated.

[geek]

@jasnell LGTM, nice work.

[Fishrock123]

I'd like to do a final (not just me) review on this, which PR is the "main/mergeable" one?

[jasnell]

@Fishrock123 ... this one I believe. I've incorporated most of @geek's feedback into this one. (and he signed off here in https://github.com/nodejs/node/pull/4782#issuecomment-193494538)

[jasnell]

@Fishrock123 ... ping ... I'd like to get this one landed soon.

[Fishrock123]

Ok I'll review later today

[jasnell]

@Fishrock123 ... updated! I just went ahead and removed the BadPracticeWarning and made it simply a Warning. Also, added clarification to the doc about emitting custom deprecation events and fixed the one nit in the test case. PTAL

[Fishrock123]

To be clear: I do think there is a place for BadPracticeWarning, just not there. :)