Improve error messages from jsifier

[RReverser]

Got a bit tired of opaque error messages coming from JS library processing when I accidentally introduce a syntax error, so here's a simple but effective improvement made possible by replacing eval with vm.runScriptInContext.

I'm actually not sure why Node.js doesn't just use the same error output for eval as well, but at least this helps 🤷‍♂️

While at it, also added filenames to load functions used by compiler.js itself, so the stacktrace contains actual filenames instead of nested evals and did few other minor cleanups to avoid error message duplication.

Example post-processed JS error message before:

error: failure to execute js library "library_pthread.js":
error: use -sVERBOSE to see more details
Internal compiler error in src/compiler.js!
Please create a bug report at https://github.com/emscripten-core/emscripten/issues/
with a log of the build and the input files used to run. Exception message: "SyntaxError: Unexpected token 'function'" | SyntaxError: Unexpected token 'function'
    at Object.load (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8), <anonymous>:215:14)
    at runJSify (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8), <anonymous>:78:18)
    ...

After:

error: failure to execute js library "library_pthread.js":
error: use -sVERBOSE to see more details
Internal compiler error in src/compiler.js!
Please create a bug report at https://github.com/emscripten-core/emscripten/issues/
with a log of the build and the input files used to run. Exception message: "library_pthread.preprocessed.js:330
  $spawnThread function(threadParams) {
               ^^^^^^^^

SyntaxError: Unexpected token 'function'
    at new Script (vm.js:102:7)
    at createScript (vm.js:262:10)
    at Object.runInThisContext (vm.js:310:10)
    at Object.load (C:\Users\me\Documents\emscripten\src\modules.js:215:12)
    at runJSify (C:\Users\me\Documents\emscripten\src\jsifier.js:78:18)
    ...

Example preprocessor error message before:

parseTools.js preprocessor error in shell_minimal.js:126: "#if MIN_CHROME_VERSION < 45 || MINEDGE_VERSION < 12 || MIN_FIREFOX_VERSION < 34 || MIN_IE_VERSION != TARGET_NOT_SUPPORTED || MIN_SAFARI_VERSION < 90000"!
Internal compiler error in src/compiler.js!
Please create a bug report at https://github.com/emscripten-core/emscripten/issues/
with a log of the build and the input files used to run. Exception message: "ReferenceError: MINEDGE_VERSION is not defined" | ReferenceError: MINEDGE_VERSION is not defined
    at eval (eval at preprocess (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8)), <anonymous>:1:29)        
    at preprocess (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8), <anonymous>:97:32)
    at finalCombiner (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8), <anonymous>:475:25)
    at runJSify (eval at load (C:\Users\me\Documents\emscripten\src\compiler.js:39:8), <anonymous>:543:3)
    ...

After:

Internal compiler error in src/compiler.js!
Please create a bug report at https://github.com/emscripten-core/emscripten/issues/
with a log of the build and the input files used to run. Exception message: "shell_minimal.js:126
 MIN_CHROME_VERSION < 45 || MINEDGE_VERSION < 12 || MIN_FIREFOX_VERSION < 34 || MIN_IE_VERSION != TARGET_NOT_SUPPORTED || MIN_SAFARI_VERSION < 90000
                            ^

ReferenceError: MINEDGE_VERSION is not defined
    at shell_minimal.js:126:32
    at Script.runInThisContext (vm.js:134:12)
    at Object.runInThisContext (vm.js:310:38)
    at preprocess (C:\Users\me\Documents\emscripten\src\parseTools.js:96:33)
    at finalCombiner (C:\Users\me\Documents\emscripten\src\jsifier.js:475:25)
    at runJSify (C:\Users\me\Documents\emscripten\src\jsifier.js:543:3)
    ...

[sbc100]

I love this! Thanks for working on it.

It does kind of seems like 3 seperate changes that all help make the error messages more clear:

1. Improve eval calls by adding sourceURL
2. Use vm.runInThisContext rather than eval for library file
3. Fairly major re-write of the pre-processor.

I wonder if you could maybe split this up. In particular (3) seems like a much larger change that could be better off being reviewed on it own. WDYT?

[RReverser]

Fairly major re-write of the pre-processor.

Hm, are you viewing with whitespace changes enabled by any chance? The big change is mostly indentation.

[sbc100]

Fairly major re-write of the pre-processor.

Hm, are you viewing with whitespace changes enabled by any chance? The big change is mostly indentation.

Doh! Thanks for pointing that out. Let me look again.

[sbc100]

lgtm!

I do wonder if we should have more test coverage here, but I won't block the landing of this change on that.

[RReverser]

Huh, this is an interesting one. Looking...

test_minimal_runtime_memorygrowth (test_core.core0) ... Internal compiler error in src/compiler.js!
Please create a bug report at https://github.com/emscripten-core/emscripten/issues/
with a log of the build and the input files used to run. Exception message: "preamble_minimal.js:92
 SHARED_MEMORY || !ALLOW_MEMORY_GROWTH || MAXIMUM_MEMORY != FOUR_GB
                                                            ^

ReferenceError: FOUR_GB is not defined
    at preamble_minimal.js:92:64
    at Script.runInThisContext (vm.js:134:12)
    at Object.runInThisContext (vm.js:310:38)
    at preprocess (C:\Users\me\Documents\emscripten\src\parseTools.js:96:33)
    at finalCombiner (C:\Users\me\Documents\emscripten\src\jsifier.js:478:27)
    at runJSify (C:\Users\me\Documents\emscripten\src\jsifier.js:543:3)
    at Object.<anonymous> (C:\Users\me\Documents\emscripten\src\compiler.js:85:3)
    at Module._compile (internal/modules/cjs/loader.js:1085:14)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1114:10)
    at Module.load (internal/modules/cjs/loader.js:950:32)
emcc: error: 'C:/Users/me/Documents/emsdk/node/14.18.2_64bit/bin/node.exe C:\Users\me\Documents\emscripten\src\compiler.js C:\Users\me\AppData\Local\Temp\tmpfcze19l4.json' failed (returned 1)
None
None
FAIL

======================================================================
FAIL: test_minimal_runtime_memorygrowth (test_core.core0)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\Users\me\Documents\emscripten\test\common.py", line 1017, in run_process
    return shared.run_process(cmd, check=check, **args)
  File "C:\Users\me\Documents\emscripten\tools\shared.py", line 110, in run_process
    ret = subprocess.run(cmd, check=check, input=input, *args, **kw)
  File "C:\Python38\lib\subprocess.py", line 512, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['C:\\Users\\me\\Documents\\emscripten\\emcc.bat', '-sNO_DEFAULT_TO_CXX', 'C:\\Users\\me\\Documents\\emscripten\\test\\core\\test_memorygrowth.c', '-o', 'test_memorygrowth.js', '-sMINIMAL_RUNTIME', '-sALLOW_MEMORY_GROWTH', '-Wclosure', '-Werror', '-Wno-limited-postlink-optimizations', '-O0']' returned non-zero exit status 1.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\me\Documents\emscripten\test\test_core.py", line 2307, in test_minimal_runtime_memorygrowth
    self.do_runf(src, '*pre: hello,4.955*\n*hello,4.955*\n*hello,4.955*')
  File "C:\Users\me\Documents\emscripten\test\common.py", line 1196, in do_runf
    return self._build_and_run(filename, expected_output, **kwargs)
  File "C:\Users\me\Documents\emscripten\test\common.py", line 1230, in _build_and_run
    js_file = self.build(filename, libraries=libraries, includes=includes,
  File "C:\Users\me\Documents\emscripten\test\common.py", line 689, in build
    self.run_process(cmd, stderr=self.stderr_redirect if not DEBUG else None)
  File "C:\Users\me\Documents\emscripten\test\common.py", line 1022, in run_process
    self.fail(f'subprocess exited with non-zero return code({e.returncode}): `{shared.shlex_join(cmd)}`')
AssertionError: subprocess exited with non-zero return code(1): `C:\Users\me\Documents\emscripten\emcc.bat -sNO_DEFAULT_TO_CXX C:\Users\me\Documents\emscripten\test\core\test_memorygrowth.c -o test_memorygrowth.js -sMINIMAL_RUNTIME -sALLOW_MEMORY_GROWTH -Wclosure -Werror -Wno-limited-postlink-optimizations -O0`

[sbc100]

Perhaps we should look at why this change was needed? Presumably it means that some things that were previously available in preprocessor statements might no longer be? I wonder how many such cases there are?

[RReverser]

The only things that should / would become unavailable now are local variables in scope, since now I'm using the safer global eval, as every other place except the preprocessor, already used. All the settings and helper functions are already assigned to the global object so continue working as expected.

This file declared two "global" constants - FOUR_GB and FLOAT_TYPES - and, from my quick grep, only FOUR_GB is actualy used in libraries. It worked before because it happened to be in the same scope as eval, but instead, like other settings, it should be set on the global object to be consistently available everywhere else. Which is what I did here.

In theory it's possible that someone used local variables from preprocessor function too (e.g. i or line or filenameHint) but that would be extremely fragile and I really hope nobody did that...

At least the tests pass now, but with share-everything eval it used before, you can never be sure what external users relied on 🤷‍♂️ Mandatory https://xkcd.com/1172/ as always applies.

[sbc100]

Makes sense. lgtm

[sbc100]

BTW, its great to see you back contributing to emscripten! Yours insights and improvements are most welcome.

[RReverser]

BTW, its great to see you back contributing to emscripten! Yours insights and improvements are most welcome.

Thanks! I've recently started contracting and currently working on a project that allows (in fact, encourages) me to make improvements upstream where possible, so that certainly helps :)