Fix stack trace #4428

GeoffreyBooth · 2017-01-21T10:44:20Z

So in #4399 we removed CoffeeScript’s patched Error.prepareStackTrace, because it was poorly implemented and threw exceptions when it shouldn’t. However, removing that patch is a major inconvenience (triggering #4418) as errors thrown by the runtime have incorrect line numbers. Just working with failing tests in the CoffeeScript codebase itself is a major pain in the ass, since the line numbers are meaningless for tests that throw errors.

So we need this patch back, but we should fix it so that it doesn’t cause the errors described in the other tickets. As I looked into it, it appears that Error.prepareStackTrace‘s original implementation went like this:

Start with the filename of the file where the exception is being thrown.
Reopen that file (per getSourceMap calling exports._compileFile calling fs.readFileSync).
Recompile the file, generating a source map that gets cached in memory.
Use that source map to patch the stack trace.

The “reopen the file” part is hugely problematic, because the file might not still be available by the time the exception is thrown and this stack trace is requested; that’s what #3890 complains about. It also makes this code completely unusable in a browser, where fs doesn’t exist.

In #4399 @jashkenas complained that a file is compiled a second time just to generate a source map. Upon closer inspection, though, it seems to me that what’s happening is that a file gets recompiled to generate a source map only when a stack trace is needed, which presumably should be a rare occurrence. I think this is the desired behavior; since the default compilation mode has source map generation off, we shouldn’t generate source maps all the time just so that we have them cached for stack traces. Recompiling only in the event of a stack trace should be faster than generating source maps all the time, whether they were requested or not. (I can see people disagreeing with me on this though; @jashkenas, what do you think?)

What we should cache, then, is the code of the file we compiled. That way when a stack trace needs to recompile it to get the source map, it’s already in memory; it doesn’t need to open a file. This lets us remove the fs.readFileSync and its associated exceptions, which fixes #3890.

Perhaps unrelated, I patched Jison’s output to not assume that since require and exports are defined, require(‘fs’) must be as well. This closes #4391, and fixes edge cases in the browser compiler. I also submitted zaach/jison#339 to try to push the fix upstream.

…a CommonJS/Node environment, not a browser environment that may happen to have globals named `require` and `exports` (as would be the case if require.js is being used). Fixes jashkenas#4391.

… stack trace for a file that has been deleted since compilation; fixes jashkenas#3890, but not well. A better solution would not try to recompile the file when trying to retrieve its stack trace.

…eeScript project folder

…not throw IO-related exceptions; source maps are either retrieved from memory, or the related source code is retrieved from memory to generate a new source map. Fixes jashkenas#3890 the proper way.

Closes jashkenas#4418.

…ecting a CommonJS environment generally, just check for `fs` before trying to use it

lydell · 2017-01-21T11:53:35Z

src/coffee-script.coffee

+
+  frames = for frame in stack
+    break if frame.getFunction() is exports.run
+    "  at #{formatSourcePosition frame, getSourceMapping}"


While were improving all of this anyway, I think we should take the opportunity to indent the "at" lines just like Node.js does. That is, 4 spaces instead of 2.

Ugh, really? I hate 4-space indentation . . .

I also prefer 2-space indentation in general, but I thought it might be a good idea to match the standard error formatting as closely as possible?

lydell · 2017-01-21T12:13:43Z

test.coffee:

test = ->
  console.log a if true

do test

Let's try it out!

~/forks/coffeescript GeoffreyBooth-fix-stack-trace 
❯ ./bin/coffee test.coffee 
ReferenceError: a is not defined
  at test (/home/lydell/forks/coffeescript/test.coffee:6:26)
  ...

~/forks/coffeescript GeoffreyBooth-fix-stack-trace 
❯ coffee -c test.coffee 

~/forks/coffeescript GeoffreyBooth-fix-stack-trace % 
❯ node test.js
/home/lydell/forks/coffeescript/test.js:7
      return console.log(a);
                         ^

ReferenceError: a is not defined
    at test (/home/lydell/forks/coffeescript/test.js:7:26)
    ...

Observations:

The source-mapped line and column numbers don't seem to be correct? (deletions = actual, additions = expected)
```
-at test (/home/lydell/forks/coffeescript/test.coffee:6:26)
+at test (/home/lydell/forks/coffeescript/test.coffee:2:15)
```
Am I missing something?

When running node test.js, I got this too:

/home/lydell/forks/coffeescript/test.js:7
      return console.log(a);
                         ^

I wonder why that doesn't show up in the coffee test.coffee call. It would be awesome if we could output this:

/home/lydell/forks/coffeescript/test.coffee:2
  console.log a if true
              ^

If I change test.coffee to this: (note process.nextTick)

test = ->
  console.log a if true

process.nextTick test

... I do get that output, although the compiled JS version:

~/forks/coffeescript GeoffreyBooth-fix-stack-trace % 
❯ coffee test.coffee 
/home/lydell/forks/coffeescript/test.coffee:6
      return console.log(a);
                         ^

ReferenceError: a is not defined
    at test (/home/lydell/forks/coffeescript/test.coffee:6:26)
    ...

I think the approach of this PR is very good. 👍 The added code is mostly restored from the old version, with a few tweaks, right?

GeoffreyBooth · 2017-01-21T19:14:37Z

@lydell Error.prepareStackTrace is unchanged from when we removed it in aee27fb. So if you’re seeing line/column number errors, those should’ve been happening back in 1.11 too. I would treat that as a separate issue/PR.

I added new tests to cover #3890 (file deleted between initial compilation and stack trace) and #4418 (wrong line numbers). The latter test seems to be okay to me. Technically I feel like the reported line number should be 1338 (if the first line is 1) or 1337 (if the first line is 0) but 1339 seems close enough. In my experience the line numbers in Coffee stack traces have never been overly precise, more like setting breakpoints on source maps in a browser, but they’ve been close enough to quickly find the relevant code.

lydell · 2017-01-21T19:27:21Z

@lydell Error.prepareStackTrace is unchanged from when we removed it in commit aee27fb. So if you’re seeing line/column number errors, those should’ve been happening back in 1.11 too.

They were correct before:

~/forks/coffeescript GeoffreyBooth-fix-stack-trace % 
❯ git checkout 1.12.1
Note: checking out '1.12.1'.
...

~/forks/coffeescript 1.12.1^0 % 
❯ ./bin/coffee test.coffee 
ReferenceError: a is not defined
  at test (/home/lydell/forks/coffeescript/test.coffee:2:15)

…tack-trace

GeoffreyBooth · 2017-01-21T19:42:21Z

That’s perverse. Here’s the diff between the 1.12.1 coffee-script.coffee and the version in this PR. I don’t see why the line numbers would be affected by these changes.

…y correct line numbers in stack traces

GeoffreyBooth · 2017-01-22T10:38:27Z

@lydell you were right, the caching wasn’t working properly. I’ve made it much more robust. Stack traces should now be processing source maps correctly both for compiled files (your test) and filename-less strings compiled via CoffeeScript.run.

lydell · 2017-01-22T10:52:07Z

Nice! All looks good to me now. 👍

Regarding the "prelude":

/home/lydell/forks/coffeescript/test.js:7
      return console.log(a);
                         ^

I have no idea where that comes from, and if it is possible to do anything about it. Anyways, this PR is about restoring what was removed, so that's out of scope. But it'd be nice if we could figure out how to CoffeeScript-ify it in the future! :)

GeoffreyBooth · 2017-01-22T12:19:12Z

@lydell It’s probably not a good idea to try to Coffeeify the “prelude.” The error that’s being thrown is a JavaScript runtime error, so the user should probably see the offending JavaScript. The original CoffeeScript might mask what the issue is, especially if the user isn’t a CoffeeScript expert and the Coffee isn’t compiling into what the user is expecting. That said, I would love to include the runtime “prelude” with our output somehow if there was a way to retrieve it.

@murrayju do you have a minute to try this branch with your project that originally led to us removing our patched Error.prepareStackTrace? I’d love to get some verification that this replacement doesn’t cause you any issues. I updated your Plunker project with the new browser compiler, and it seems to me like it’s working as expected.

GeoffreyBooth · 2017-01-22T12:21:02Z

src/coffee-script.coffee

@@ -146,13 +163,13 @@ exports.run = (code, options = {}) ->

  # Set the filename.
  mainModule.filename = process.argv[1] =
-    if options.filename then fs.realpathSync(options.filename) else '.'
+    if options.filename then fs.realpathSync(options.filename) else '<anonymous>'


@lydell I changed this so that we have consistent “filenames” when compiling from run or eval or other non-file sources, which is important for looking up cached sources and source maps later. Do you see any issue with this? Was there anything special about a filename of . before?

I can't see any obvious issue, but on the other hand I have no idea if there was anything special about the . before either.

Okay. I just ran the browser tests and test.html and ran into (and fixed) some issues, which is what led me to change this. We never had a stack trace line number test that ran in the browser before, so I’m not sure our previous stack traces ever worked in the browser (I suspect they didn’t). I hope there aren’t any other edge cases I’m not thinking of.

GeoffreyBooth · 2017-01-22T12:22:16Z

src/coffee-script.coffee

+  # of `<anonymous>`, but the browser may request the stack trace with the
+  # filename of the script file.
+  else if sourceMaps['<anonymous>']?
+    sourceMaps['<anonymous>']


…work to do to test this branch

murrayju · 2017-01-22T13:55:30Z

👍 Gave it a quick run through my build/tests, and it all worked fine!

GeoffreyBooth · 2017-01-22T21:20:04Z

Thanks @murrayju!

@lydell, I guess I’ll merge this, and I guess we should do another release?

lydell · 2017-01-22T21:31:32Z

I guess we should do another release?

Ok, I’ll try to do that tomorrow. Remind me if I forget.

mrmowgli · 2017-01-22T21:35:50Z

@GeoffreyBooth THIS pull request officially makes you MY hero!! This has been broken for a while ;)

jashkenas · 2017-01-24T15:48:51Z

Heroic of you to tackle this — nice work!

Conceptually, it feels like the right thing to do would be (while running live via coffee) to keep the source maps for each file cached in memory, use them when needed ... and never go back and recompile a file a second time.

That said, this works too.

GeoffreyBooth · 2017-01-24T16:19:35Z

I haven't tested it, but I think that's what this code does. The issue is that source maps are not created by default, so we don't want to always create them regardless of whether they were requested, even if they're not returned. If they're created, whether in the first place or as part of a stack trace, they're cached.

cf jashkenas/coffeescript#4428

GeoffreyBooth added 7 commits January 20, 2017 23:13

Revert aee27fb

0b0323b

Patch Jison’s output so that it requires fs only if we’re truly in …

c70541b

…a CommonJS/Node environment, not a browser environment that may happen to have globals named `require` and `exports` (as would be the case if require.js is being used). Fixes jashkenas#4391.

Temporary fix for exceptions getting thrown when trying to generate a…

e2ac4b9

… stack trace for a file that has been deleted since compilation; fixes jashkenas#3890, but not well. A better solution would not try to recompile the file when trying to retrieve its stack trace.

Save the test REPL history in the system temp folder, not in the Coff…

96a8776

…eeScript project folder

Rewrite getSourceMap to never read a file from disk, and therefore …

86e7d56

…not throw IO-related exceptions; source maps are either retrieved from memory, or the related source code is retrieved from memory to generate a new source map. Fixes jashkenas#3890 the proper way.

Add test to verify that stack traces reference the correct line number.

c83410b

Closes jashkenas#4418.

Get the parser working in the browser compiler again; rather than det…

51097cd

…ecting a CommonJS environment generally, just check for `fs` before trying to use it

GeoffreyBooth requested review from jashkenas and lydell January 21, 2017 10:44

GeoffreyBooth added the fixed label Jan 21, 2017

lydell reviewed Jan 21, 2017

View reviewed changes

Follow Node’s standard of 4-space indentation of stack trace data

316a9f3

Merge branch 'master' of github.com:jashkenas/coffeescript into fix-s…

e117647

…tack-trace

GeoffreyBooth added 2 commits January 21, 2017 22:55

Better .gitignore

14876e4

Fix caching of compiled code and source maps; add more tests to verif…

23e9fc7

…y correct line numbers in stack traces

GeoffreyBooth added 2 commits January 22, 2017 02:52

Better fallback value for the parser source

6f03c8a

Fix the stack traces and tests when running in a browser

27c2833

GeoffreyBooth commented Jan 22, 2017

View reviewed changes

Update the browser compiler so that @murrayju doesn’t have any extra …

f6a2384

…work to do to test this branch

GeoffreyBooth merged commit 3108244 into jashkenas:master Jan 22, 2017

GeoffreyBooth deleted the fix-stack-trace branch January 22, 2017 21:20

GeoffreyBooth mentioned this pull request Jan 22, 2017

1.12.3 #4429

Merged

GeoffreyBooth mentioned this pull request Jan 23, 2017

Forced patch of Error.prepareStackTrace conflicts with other libraries #4258

Closed

maxlath added a commit to inventaire/inventaire that referenced this pull request Jan 26, 2017

reverting coffee-script version: fix stack line regression

335e0c2

cf jashkenas/coffeescript#4428

GeoffreyBooth mentioned this pull request Apr 18, 2017

Syntax error script type="text/coffeescript" does not tell in which file #2368

Closed

BrownBear2 mentioned this pull request Jun 6, 2017

CLI: Line numbers shown as NaN in stack trace when compiling CoffeeScript inside CoffeeScript #4558

Closed

GeoffreyBooth mentioned this pull request Aug 23, 2017

Fix #4558: Stack trace line numbers for scripts that compile CoffeeScript #4645

Merged

GeoffreyBooth mentioned this pull request Oct 5, 2021

Bug: Requiring "coffeescript" breaks Node.js built-in source map support globally #5382

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix stack trace #4428

Fix stack trace #4428

GeoffreyBooth commented Jan 21, 2017

lydell Jan 21, 2017

GeoffreyBooth Jan 21, 2017

lydell Jan 21, 2017

lydell commented Jan 21, 2017

GeoffreyBooth commented Jan 21, 2017

lydell commented Jan 21, 2017

GeoffreyBooth commented Jan 21, 2017

GeoffreyBooth commented Jan 22, 2017

lydell commented Jan 22, 2017

GeoffreyBooth commented Jan 22, 2017

GeoffreyBooth Jan 22, 2017

lydell Jan 22, 2017

GeoffreyBooth Jan 22, 2017

GeoffreyBooth Jan 22, 2017

murrayju commented Jan 22, 2017

GeoffreyBooth commented Jan 22, 2017

lydell commented Jan 22, 2017

mrmowgli commented Jan 22, 2017

jashkenas commented Jan 24, 2017

GeoffreyBooth commented Jan 24, 2017

Fix stack trace #4428

Fix stack trace #4428

Conversation

GeoffreyBooth commented Jan 21, 2017

lydell Jan 21, 2017

Choose a reason for hiding this comment

GeoffreyBooth Jan 21, 2017

Choose a reason for hiding this comment

lydell Jan 21, 2017

Choose a reason for hiding this comment

lydell commented Jan 21, 2017

GeoffreyBooth commented Jan 21, 2017

lydell commented Jan 21, 2017

GeoffreyBooth commented Jan 21, 2017

GeoffreyBooth commented Jan 22, 2017

lydell commented Jan 22, 2017

GeoffreyBooth commented Jan 22, 2017

GeoffreyBooth Jan 22, 2017

Choose a reason for hiding this comment

lydell Jan 22, 2017

Choose a reason for hiding this comment

GeoffreyBooth Jan 22, 2017

Choose a reason for hiding this comment

GeoffreyBooth Jan 22, 2017

Choose a reason for hiding this comment

murrayju commented Jan 22, 2017

GeoffreyBooth commented Jan 22, 2017

lydell commented Jan 22, 2017

mrmowgli commented Jan 22, 2017

jashkenas commented Jan 24, 2017

GeoffreyBooth commented Jan 24, 2017