Bug?: No stacktraces during `include`

[Justin Rosenstein]

Hey Ondřej,

It looks like stacktraces are unavailable for exceptions that occur during include.  (See below for what I mean.)  Is this a known bug?  Are there plans to fix it?

thanks!,

Justin (Asana)

test.js

try {

  include('/tmp/included.js');

} catch (e) {

  system.stdout("Stacktrace for call to `f` during `include`: "

      + e.stack + "\n");

}

try {

  f();

} catch (e) {

  system.stdout("Stacktrace for call to `f` in this file: "

      + e.stack + "\n");

}

included.js

global.f = function() {

  throw new Error('testing');

};

f();  // throws exception

$ ./v8cgi /tmp/a.js

Stacktrace for call to `f` during `include`: undefined

Stacktrace for call to `f` in this file: Error: testing

    at /private/tmp/included.js:2:9

    at Object.<anonymous> (/private/tmp/test.js:9:3)

[Ondřej Žára]

Hi Justin,

I am unable to reproduce this - the sample code you provided works as expected, both exceptions have the .stack property.

1) What version of v8cgi are you using? Can you try the latest SVN revision?

2) What version of V8 do you have?



Sincerely,
Ondrej Zara

2010/4/7 Justin Rosenstein <jus...@gmail.com>

[Justin Rosenstein]

Not the latest :-).  Will up everything and let you know on the off chance the problem doesn't go away.  Sorry 'bout that.

2010/4/7 Ondřej Žára <ondre...@gmail.com>

[Justin Rosenstein]

We upgraded lastest v8 (looks like version 2.2.2?) and v8cgi (0.8.1dev), and are still seeing the problem.  Any guesses?  Thanks again, Ondřej.

2010/4/7 Justin Rosenstein <jus...@gmail.com>

--
You received this message because you are subscribed to the Google Groups "v8cgi" group.
To post to this group, send email to v8...@googlegroups.com.
To unsubscribe from this group, send email to v8cgi+un...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/v8cgi?hl=en.

[Ondřej Žára]

Hi Justin,

hmm, this is strange. I *exactly* copied your example and tried to reproduce on my system; this is my result:

ondras@kapitan:~/svn/v8cgi-trunk$ ./v8cgi test.js
Stacktrace for call to `f` during `include`: Error: /tmp/included.js:2: Error: testing
    at Object.<anonymous> (/home/ondras/svn/v8cgi-trunk/test.js:4:3)

Stacktrace for call to `f` in this file: Error: testing

    at /tmp/included.js:2:9
    at Object.<anonymous> (/home/ondras/svn/v8cgi-trunk/test.js:11:13)


which is correct - and different from your observations.

1) can you please show your v8cgi configuration file?

2) is this problem visible also when using require() ? I plan on actually *removing* the include() function (in favor of require)...

3) in your initial example (first post in this thread), you execute /tmp/a.js, which is not defined in the example. Is this just a typo, instead of "test.js" ?

Sincerely,
Ondrej

2010/5/7 Justin Rosenstein <jus...@gmail.com>

[Malcolm Handley]

Hey Ondřej.

We now get the same stack traces as you but I think that a closer look shows that they are still missing some frames. To make the situation clearer I have updated versions of the files:

$ cat /tmp/test.js 

try {

  include('/tmp/included.js');

} catch (e) {

  system.stderr("Stacktrace for call to `f` during `include`: "

      + e.stack + "\n");

}

try {

  f();

} catch (e) {

  system.stderr("Stacktrace for call to `f` in this file: "

      + e.stack + "\n");

}

$ cat /tmp/included.js 

var g = function() {

  throw new Error('testing');

};

global.f = function() {

  g();

};

f();  // throws exception

$ ./v8cgi /tmp/test.js 

Stacktrace for call to `f` during `include`: Error: /private/tmp/included.js:2: Error: testing

    at Object.<anonymous> (/private/tmp/test.js:2:3)

Stacktrace for call to `f` in this file: Error: testing

    at /private/tmp/included.js:2:9

    at /private/tmp/included.js:6:3

    at Object.<anonymous> (/private/tmp/test.js:9:3)

I think that we were confused before because we saw the reference to "included.js:2" before the stack trace for the first exception. As far as I can tell the exception still correctly reports the line that it came from but is missing stack frames after the call to include.

Here's /etc/v8cgi.conf:

// This file has been modified from the original to include a reference to /Users/malcolm/Projects/outergit/asana

var Config = {};

exports.Config = Config;

// put default .js and .so files here

// NOTE: this was called "Config.libraryPath" in older versions of v8cgi

require.paths.push("/Users/malcolm/Projects/outergit/asana/3rdparty/v8js/v8cgi/lib");

// these will get loaded automatically

Config["libraryAutoload"] = ["js", "util", "html", "http"];

// name of session cookie

Config["sessionCookie"] = "V8SID";

// directory for session storage

Config["sessionPath"] = "/tmp";

// session lifetime - in seconds

Config["sessionTime"] = 60*60;

// session domain

Config["sessionDomain"] = "/";

// address for sending emails

Config["smtpHost"] = "127.0.0.1";

// port for sending emails

Config["smtpPort"] = 25;

// default From: header

Config["smtpFrom"] = "";

// explicit HTTP request handler. Will get obsoleted in future versions.

Config["httpHandler"] = null;

// Uncaught exceptions go to stdout (true) or stderr (false)

Config["showErrors"] = true;

I'm sorry about the mention to a.js in the earlier email. I hope that everything in this message makes sense.

As for require versus include, we prefer to use include because it more closely matches what happens when the browser loads multiple JS files. That said, I will try require if you would find that helpful.

2010/5/7 Ondřej Žára <ondre...@gmail.com>

[Ondřej Žára]

Hi Malcom,
 

I'm sorry about the mention to a.js in the earlier email. I hope that everything in this message makes sense.

thanks for the clarification; our examples seem to be in sync now.

However, I am afraid that there is very little I can do now: the exception caused by evaluating the code in "included.js" already contains all the information it can have. To understand why there is no mention of stack starting from "test.js", let me show you what happens when you execute some JS code and use the include/require function:

1) your code (test.js) is passed to V8
2) V8 starts evaluating your code (by calling its Run() method), properly keeping track of scopes etc
3) V8 detects the call of include/require, which is a function defined outside of V8 by C++ means
4) therefore, the control is passed to C++ (v8cgi)
5) v8cgi analyzes arguments of the relevant include/require call and locates the proper file (included.js)
6) v8cgi (recursively) calls V8's Run() with the contents of included file. At this point, the Run() method has no information about what happened before; it only knows at what line of the previous source code a stop occured. This is - in my opinion - the reason why an exception thrown when evaluating a module contains no information about a stack trace. I also believe that I have no means of improving the situation.

Also note that this problem should be common for both include and require, as they behave identically on this level. The reason for *not* using include() is that this function might get eventually removed from future releases. Note that other CommonJS implementations are completely missing this "php-like" (or browser-like) variant of require(), as it encourages sloppy programming.

Sticking with require() can also minimize the number of exceptions being thrown during require() call: typically, a module only contains definitions, functions and classes. It is up to the caller to use (instantialize, call) them.


I hope my explanations are 1) correct, 2) understandable :)

Yours,
Ondrej


 

[Ondřej Žára]

Hi Kris,

v8cgi checks for compilation errors in load_js method (app.cc), after the script is created with v8::Script::New() (cache.cc).

After double-checking the (incorrect) output from your sample:

Stacktrace for call to `f` during `include`:

  Error: /private/tmp/included.js:2:
  Error: testing

    at Object.<anonymous> (/private/tmp/test.js:2:3)

What information exactly are you missing here? Can you please show node's output for comparison?


Thanks,
Ondrej

2010/6/4 Kris Rasmussen <kr...@asana.com>

Hi Ondrej,

Thanks for taking the time to help us better understand this. I did the same experiment with node.js and found that they do show a stack starting from "test.js" with the proper line numbers.

When node.js is processing a require it uses the v8::Script::Compile method to acquire a v8::Script object and then checks a TryCatch instance for any errors and reports them. If that goes well, then it will call script->Run().

In v8cgi, it looks like you are using v8::Script::new and not checking any TryCatch to see if exceptions were caught.

I thought this observation might be related but I have VERY limited knowledge of the v8 source so I apologize if this isn't helpful.

Thanks,

Kris

2010/6/3 Ondřej Žára <ondre...@gmail.com>

[Ondřej Žára]

Kris,

after looking into v8cgi's code once more, I possibly discovered the weak spot. Please stay tuned, I will try to commit a fix soon so you can re-test with your sample code.



O.

2010/6/4 Kris Rasmussen <kr...@asana.com>

Hi Ondrej,

Thanks for taking the time to help us better understand this. I did the same experiment with node.js and found that they do show a stack starting from "test.js" with the proper line numbers.

When node.js is processing a require it uses the v8::Script::Compile method to acquire a v8::Script object and then checks a TryCatch instance for any errors and reports them. If that goes well, then it will call script->Run().

In v8cgi, it looks like you are using v8::Script::new and not checking any TryCatch to see if exceptions were caught.

I thought this observation might be related but I have VERY limited knowledge of the v8 source so I apologize if this isn't helpful.

Thanks,

Kris

2010/6/3 Ondřej Žára <ondre...@gmail.com>

[Ondřej Žára]

Kris,

please update to revision 807 and try again. I refactored the whole exception handling part of v8cgi and I believe it should behave more properly now.

Let me know about your further observations.


Sincerely,
Ondrej Zara

2010/6/4 Kris Rasmussen <kr...@asana.com>

Hi Ondrej,

Thanks for taking the time to help us better understand this. I did the same experiment with node.js and found that they do show a stack starting from "test.js" with the proper line numbers.

When node.js is processing a require it uses the v8::Script::Compile method to acquire a v8::Script object and then checks a TryCatch instance for any errors and reports them. If that goes well, then it will call script->Run().

In v8cgi, it looks like you are using v8::Script::new and not checking any TryCatch to see if exceptions were caught.

I thought this observation might be related but I have VERY limited knowledge of the v8 source so I apologize if this isn't helpful.

Thanks,

Kris

2010/6/3 Ondřej Žára <ondre...@gmail.com>

[Malcolm Handley]

That does indeed fix the problem, Ondřej. Thank you so much!

On Sat, Jun 5, 2010 at 3:14 PM, Kris Rasmussen <kr...@asana.com> wrote:

That's great news Ondřej! We will try this out when we get back in the office and confirm that the exception handling improvements work as expected. Thank you for resolving this so quickly.

Best,

Kris

2010/6/5 Ondřej Žára <ondre...@gmail.com>