Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

Improve Exception reporting #3238

Closed
wants to merge 2 commits into from

5 participants

@felixge

2 patches that improve / fix the output of the throw call sites for errors triggered inside process.nextTick callbacks as well as during module loading.

@felixge felixge Fix process.nextTick throw call sites
This patch now reports the proper throw call site for exceptions
triggered within process.nextTick. So instead of this:

node.js:201
        throw e; // process.nextTick error, or 'error' event on first tick
              ^

You will now see:

mydir/myscript.js:15
  throw new Error('My Error');
          ^

From my testing this patch causes no performance regressions, but does
greatly simplify processing the nextTickQueue.
77def43
@felixge felixge Fix exception output for module load exceptions
So instead of:

node.js:201
        throw e; // process.nextTick error, or 'error' event on first tick
              ^

You will now see:

path/to/foo.js:1
throw new Error('bar');
      ^

This is a sub-set of isaacs patch here:

joyent#3235

The difference is that this patch purely adresses the exception output,
but does not try to make any behavior changes / improvements.
13afa9f
@domenic

I am so excited to see this land.

@shigeki
Collaborator

"Cannot find module" error looks like below. I'm in favor of hiding process.nextTick() in the error but user would be surprised at seeing the request variable in it.

$ ./node foo.js

module.js:337
    throw new Error("Cannot find module '" + request + "'");
          ^
Error: Cannot find module '/home/ohtsu/tmp/github/node/foo.js'
    at Function._resolveFilename (module.js:337:11)
    at Function._load (module.js:279:25)
    at Array.0 (module.js:484:10)
    at EventEmitter._tickCallback (node.js:190:38)
@felixge

@shigeki you mean if foo.js does not exist? Yeah, that's what the new output will look like. IMO it's better than the previous:

node.js:201
        throw e; // process.nextTick error, or 'error' event on first tick
              ^
Error: Cannot find module '/Users/Felix/code/node/foo.js'
    at Function._resolveFilename (module.js:332:11)
    at Function._load (module.js:279:25)
    at Array.0 (module.js:479:10)
    at EventEmitter._tickCallback (node.js:192:40)

That being said, we could rename the request variable inside of Module._resolveFilename to something like location. Do you think that would help?

@shigeki
Collaborator

@felixge I totally agree that it is much better than the previous.
I meant that most of users do not care and understand the source code of native modules and its variable names.
For example of this error case, I've made a quick patch in 09f9771 as

> ./node foo.js
Error: Cannot find module '/home/ohtsu/tmp/github/node/foo.js'
    at Function._resolveFilename (module.js:337:13)
    at Function._load (module.js:279:25)
    at Array.0 (module.js:486:10)
    at EventEmitter._tickCallback (node.js:190:38

I think that all errors that throws in native/build-in modules need not to show its source code to user.

@felixge

@shigeki I like the result of 09f9771, but consider this:

try{
  require('some-module');
} catch (err) {
  throw err;
}

In this (arguably theoretic) case you would still hide the throw call site even so it is now in user land, which is bad.

IMO hiding the throw call site under certain circumstance would bring more complexity than it would help people. So -1 from me.

@shigeki
Collaborator

@felixge If you agree not to dispose source of all native modules in error, I've just made a patch in 267c31f as

> ./node foo.js
Error: Cannot find module '/home/ohtsu/tmp/github/node/foo.js'
    at Function._resolveFilename (module_native:337:11)
    at Function._load (module_native:279:25)
    at Array.0 (module_native:484:10)
    at EventEmitter._tickCallback (node.js:190:38)
> cat mod.js
try {
 require('no_exist');
} catch (e) {
  throw e;
}
> ./node mod.js

/home/ohtsu/tmp/github/node/mod.js:4
  throw e;
        ^
Error: Cannot find module 'no_exist'
    at Function._resolveFilename (module_native:337:11)
    at Function._load (module_native:279:25)
    at Module.require (module_native:359:17)
    at require (module_native:375:17)
    at Object.<anonymous> (/home/ohtsu/tmp/github/node/mod.js:2:2)
    at Module._compile (module_native:446:26)
    at Object..js (module_native:464:10)
    at Module.load (module_native:353:31)
    at Function._load (module_native:311:12)
    at Array.0 (module_native:484:10)

With this patch, "_native" is the reserved string to identify native modules but they are also used in node_native.h and would not cause any problems. I think it does not bring more complexity. How about that?

@isaacs

Landed in v0.6.

@isaacs isaacs closed this
@isaacs

@felixge There's another case that we overlooked: setTImeout. Currently, that reports timers.js. We wrap the callback in a try/catch so that other timers in that same timeout value can also get fired after emitting the 'uncaughtException' event.

Also, I'm having a bit of a weird issue porting it to master. The line number in the stack_overflow case is showing up as 0, so the printed out error line is wrong. It's still a net improvement over what we have, but I think it'd be a lot better if we could get the accurate call site.

https://github.com/isaacs/node/tree/v0.6-merge has the merge in progress. There's a failing test right now, so we ought to decide whether it's possible/worthwhile to fix it, otherwise make it pass the sloppy way.

@felixge

@isaacs I can look into both of these tomorrow.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on May 8, 2012
  1. @felixge

    Fix process.nextTick throw call sites

    felixge authored
    This patch now reports the proper throw call site for exceptions
    triggered within process.nextTick. So instead of this:
    
    node.js:201
            throw e; // process.nextTick error, or 'error' event on first tick
                  ^
    
    You will now see:
    
    mydir/myscript.js:15
      throw new Error('My Error');
              ^
    
    From my testing this patch causes no performance regressions, but does
    greatly simplify processing the nextTickQueue.
  2. @felixge

    Fix exception output for module load exceptions

    felixge authored
    So instead of:
    
    node.js:201
            throw e; // process.nextTick error, or 'error' event on first tick
                  ^
    
    You will now see:
    
    path/to/foo.js:1
    throw new Error('bar');
          ^
    
    This is a sub-set of isaacs patch here:
    
    joyent#3235
    
    The difference is that this patch purely adresses the exception output,
    but does not try to make any behavior changes / improvements.
This page is out of date. Refresh to see the latest.
View
11 lib/module.js
@@ -304,11 +304,16 @@ Module._load = function(request, parent, isMain) {
}
Module._cache[filename] = module;
+
+ var hadException = true;
+
try {
module.load(filename);
- } catch (err) {
- delete Module._cache[filename];
- throw err;
+ hadException = false;
+ } finally {
+ if (hadException) {
+ delete Module._cache[filename];
+ }
}
return module.exports;
View
12 src/node.cc
@@ -255,9 +255,7 @@ static void Spin(uv_idle_t* handle, int status) {
Tick();
}
-
-static Handle<Value> NeedTickCallback(const Arguments& args) {
- HandleScope scope;
+static void StartTickSpinner() {
need_tick_cb = true;
// TODO: this tick_spinner shouldn't be necessary. An ev_prepare should be
// sufficent, the problem is only in the case of the very last "tick" -
@@ -268,9 +266,12 @@ static Handle<Value> NeedTickCallback(const Arguments& args) {
uv_idle_start(&tick_spinner, Spin);
uv_ref(uv_default_loop());
}
- return Undefined();
}
+static Handle<Value> NeedTickCallback(const Arguments& args) {
+ StartTickSpinner();
+ return Undefined();
+}
static void PrepareTick(uv_prepare_t* handle, int status) {
assert(handle == &prepare_tick_watcher);
@@ -1694,6 +1695,9 @@ void FatalException(TryCatch &try_catch) {
emit->Call(process, 2, event_argv);
// Decrement so we know if the next exception is a recursion or not
uncaught_exception_counter--;
+
+ // This makes sure uncaught exceptions don't interfere with process.nextTick
+ StartTickSpinner();
}
View
24 src/node.js
@@ -180,26 +180,18 @@
startup.processNextTick = function() {
var nextTickQueue = [];
+ var nextTickIndex = 0;
process._tickCallback = function() {
- var l = nextTickQueue.length;
- if (l === 0) return;
+ var nextTickLength = nextTickQueue.length;
+ if (nextTickLength === 0) return;
- var q = nextTickQueue;
- nextTickQueue = [];
-
- try {
- for (var i = 0; i < l; i++) q[i]();
- }
- catch (e) {
- if (i + 1 < l) {
- nextTickQueue = q.slice(i + 1).concat(nextTickQueue);
- }
- if (nextTickQueue.length) {
- process._needTickCallback();
- }
- throw e; // process.nextTick error, or 'error' event on first tick
+ while (nextTickIndex < nextTickLength) {
+ nextTickQueue[nextTickIndex++]();
}
+
+ nextTickQueue.splice(0, nextTickIndex);
+ nextTickIndex = 0;
};
process.nextTick = function(callback) {
View
6 test/message/stack_overflow.out
@@ -1,6 +1,6 @@
before
-node.js:*
- throw e; // process.nextTick error, or 'error' event on first tick
- ^
+*test*message*stack_overflow.js:31
+function stackOverflow() {
+ ^
RangeError: Maximum call stack size exceeded
View
6 test/message/throw_custom_error.out
@@ -1,6 +1,6 @@
before
-node.js:*
- throw e; // process.nextTick error, or 'error' event on first tick
- ^
+*test*message*throw_custom_error.js:31
+throw { name: 'MyCustomError', message: 'This is a custom message' };
+^
MyCustomError: This is a custom message
View
6 test/message/throw_non_error.out
@@ -1,6 +1,6 @@
before
-node.js:*
- throw e; // process.nextTick error, or 'error' event on first tick
- ^
+*/test/message/throw_non_error.js:31
+throw { foo: 'bar' };
+^
[object Object]
View
6 test/message/undefined_reference_in_new_context.out
@@ -1,8 +1,8 @@
before
-node.js:*
- throw e; // process.nextTick error, or 'error' event on first tick
- ^
+*test*message*undefined_reference_in_new_context.js:34
+script.runInNewContext();
+ ^
ReferenceError: foo is not defined
at evalmachine.<anonymous>:*
at Object.<anonymous> (*test*message*undefined_reference_in_new_context.js:*)
Something went wrong with that request. Please try again.