ComponentizeJS Better error for `performance` access at Wizer time

I still get the same error with jco 1.7.1 that uses 0.13.1 of this project. #150 does not set timeOrigin. The change from https://github.com/bytecodealliance/ComponentizeJS/pull/146/commits/cb4d73af4fbbd75fb4bafc79b04a7d500180bd96#diff-882dd8ad95be11b373fd2693a697c12144f8b51d4605a35cd678a0d2e5b4a09dR354 makes it work for me locally.

~/ms/StarlingMonkey15/cowsay> npx jco componentize cowsay.js --wit src/cowsay.wit -o cowsay.wasm
Redirecting call to abort() to mozalloc_abort

Error: the `componentize.wizer` function trapped

Caused by:
    0: error while executing at wasm backtrace:
           0: 0x25f20 - <unknown>!<wasm function 206>
           1: 0x25f29 - <unknown>!<wasm function 207>
           2: 0xa921 - <unknown>!<wasm function 87>
           3: 0x42119 - <unknown>!<wasm function 348>
           4: 0x25431f - <unknown>!<wasm function 5279>
           5: 0x254f50 - <unknown>!<wasm function 5282>
           6: 0x25576e - <unknown>!<wasm function 5285>
           7: 0x35a029 - <unknown>!<wasm function 7091>
           8: 0x258ee8 - <unknown>!<wasm function 5313>
           9: 0x24bbcc - <unknown>!<wasm function 5278>
          10: 0x245b22 - <unknown>!<wasm function 5276>
          11: 0x255aeb - <unknown>!<wasm function 5288>
          12: 0x29a0a9 - <unknown>!<wasm function 5791>
          13: 0x34e9db - <unknown>!<wasm function 7049>
          14: 0x34e72d - <unknown>!<wasm function 7049>
          15: 0x20286 - <unknown>!<wasm function 105>
          16: 0x1f50e - <unknown>!<wasm function 104>
          17: 0xa882 - <unknown>!<wasm function 86>
          18: 0x22580f - <unknown>!<wasm function 5012>
    1: wasm trap: wasm `unreachable` instruction executed
(jco componentize) Error: Failed to initialize the compiled Wasm binary with Wizer:
Wizering failed to complete
    at componentize (file:///Users/cataggar/ms/StarlingMonkey15/node_modules/@bytecodealliance/componentize-js/src/componentize.js:271:13)
    at async componentize (file:///Users/cataggar/ms/StarlingMonkey15/node_modules/@bytecodealliance/jco/src/cmd/componentize.js:11:25)
    at async file:///Users/cataggar/ms/StarlingMonkey15/node_modules/@bytecodealliance/jco/src/jco.js:200:9

Oct 30 '24 23:10 cataggar

Check that you're definitely using the latest ComponentizeJS in your node_modules folder verifying the version.

Oct 30 '24 23:10 guybedford

That was the first thing I checked. Here is a debug build which prints debug info. I build it with npm run build:debug and then set const DEBUG_BUILD = true; to use it.

~/ms/ComponentizeJS> git log -1
commit 25065612c2121b685e0e0c801e0bfa86de99727c (HEAD -> main, tag: 0.13.1, origin/main, cataggar/main)
Author: Guy Bedford <[email protected]>
Date:   Tue Oct 29 18:15:14 2024 -0700

    0.13.1

~/ms/StarlingMonkey15/cowsay> npx jco componentize cowsay.js --wit src/cowsay.wit -o cowsay.wasm 
Redirecting call to abort() to mozalloc_abort

Error: the `componentize.wizer` function trapped

Caused by:
    0: error while executing at wasm backtrace:
           0: 0x1683f - <unknown>!mozalloc_abort
           1: 0x16848 - <unknown>!abort
           2: 0xdec9 - <unknown>!std::__2::__throw_bad_optional_access[abi:v160000]()
           3: 0x33a82 - <unknown>!builtins::web::performance::Performance::timeOrigin_get(JSContext*, unsigned int, JS::Value*)
           4: 0x267ad1 - <unknown>!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason)
           5: 0x26850f - <unknown>!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason)
           6: 0x268c20 - <unknown>!js::CallGetter(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>)
           7: 0x395be9 - <unknown>!js::NativeGetProperty(JSContext*, JS::Handle<js::NativeObject*>, JS::Handle<JS::Value>, JS::Handle<JS::PropertyKey>, JS::MutableHandle<JS::Value>)
           8: 0x26bb81 - <unknown>!js::GetProperty(JSContext*, JS::Handle<JS::Value>, JS::Handle<js::PropertyName*>, JS::MutableHandle<JS::Value>)
           9: 0x260432 - <unknown>!js::Interpret(JSContext*, js::RunState&)
          10: 0x25ace4 - <unknown>!js::RunScript(JSContext*, js::RunState&)
          11: 0x268fc0 - <unknown>!js::Execute(JSContext*, JS::Handle<JSScript*>, JS::Handle<JSObject*>, JS::MutableHandle<JS::Value>)
          12: 0x2b3990 - <unknown>!js::ModuleObject::execute(JSContext*, JS::Handle<js::ModuleObject*>)
          13: 0x38a990 - <unknown>!InnerModuleEvaluation(JSContext*, JS::Handle<js::ModuleObject*>, JS::MutableHandle<JS::GCVector<js::ModuleObject*, 0ul, js::SystemAllocPolicy>>, unsigned long, unsigned long*)
          14: 0x38a83f - <unknown>!InnerModuleEvaluation(JSContext*, JS::Handle<js::ModuleObject*>, JS::MutableHandle<JS::GCVector<js::ModuleObject*, 0ul, js::SystemAllocPolicy>>, unsigned long, unsigned long*)
          15: 0x38a458 - <unknown>!JS::ModuleEvaluate(JSContext*, JS::Handle<JSObject*>, JS::MutableHandle<JS::Value>)
          16: 0x1138b - <unknown>!ScriptLoader::eval_top_level_script(char const*, JS::SourceText<mozilla::Utf8Unit>&, JS::MutableHandle<JS::Value>, JS::MutableHandle<JS::Value>)
          17: 0xdcd6 - <unknown>!api::Engine::eval_toplevel(JS::SourceText<mozilla::Utf8Unit>&, char const*, JS::MutableHandle<JS::Value>)
          18: 0xda41 - <unknown>!api::Engine::Engine(std::__2::unique_ptr<api::EngineConfig, std::__2::default_delete<api::EngineConfig>>)
          19: 0xc07f - <unknown>!wizen()
          20: 0xc222 - <unknown>!__wizer_initialize()
          21: 0x2350dd - <unknown>!componentize_initialize
       note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable may show more debugging information
    1: wasm trap: wasm `unreachable` instruction executed
(jco componentize) Error: Failed to initialize the compiled Wasm binary with Wizer:
Wizering failed to complete
    at componentize (file:///Users/cataggar/ms/ComponentizeJS/src/componentize.js:271:13)
    at async componentize (file:///Users/cataggar/ms/jco/src/cmd/componentize.js:11:25)
    at async file:///Users/cataggar/ms/jco/src/jco.js:200:9

Oct 30 '24 23:10 cataggar

Are you trying to use performance.now() in the JS initialization outside of a component exported function? Wizer-time use of the performance global is not permitted.

Oct 30 '24 23:10 guybedford

i.e. compile time is not the time to do timing stuff.

Oct 30 '24 23:10 guybedford

I have no customization like that. Happy to share my screen.

Oct 30 '24 23:10 cataggar

You're writing something like this:

// this is a wizer time use of the performance global - NOT ALLOWED
const start = performance.now();
export const run = {
  run () {
    console.log(performance.now() - start);
  }
};

when you should be writing this:

export const run = {
  run () {
    const start = performance.now();
    console.log(performance.now() - start);
  }
};

Oct 31 '24 00:10 guybedford

Here are the steps to reproduce.

git clone [email protected]:cataggar/StarlingMonkey15.git --no-checkout
cd StarlingMonkey15
git checkout 4d130a9cab15563cc38a4619a3c6a8c129d1be85
cd cowsay
bun install
bun run build.ts
bunx jco componentize cowsay.js --wit src/cowsay.wit -o cowsay.wasm

Following those steps:

~/tmp/StarlingMonkey15/cowsay> bun install
bun install v1.1.33 (247456b6)

Checked 108 installs across 130 packages (no changes) [117.00ms]
~/tmp/StarlingMonkey15/cowsay> bun run build.ts
~/tmp/StarlingMonkey15/cowsay> bunx jco componentize cowsay.js --wit src/cowsay.wit -o cowsay.wasm
Redirecting call to abort() to mozalloc_abort

Error: the `componentize.wizer` function trapped

Caused by:
    0: error while executing at wasm backtrace:
           0: 0x25f20 - <unknown>!<wasm function 206>
           1: 0x25f29 - <unknown>!<wasm function 207>
           2: 0xa921 - <unknown>!<wasm function 87>
           3: 0x42119 - <unknown>!<wasm function 348>
           4: 0x25431f - <unknown>!<wasm function 5279>
           5: 0x254f50 - <unknown>!<wasm function 5282>
           6: 0x25576e - <unknown>!<wasm function 5285>
           7: 0x35a029 - <unknown>!<wasm function 7091>
           8: 0x258ee8 - <unknown>!<wasm function 5313>
           9: 0x24bbcc - <unknown>!<wasm function 5278>
          10: 0x245b22 - <unknown>!<wasm function 5276>
          11: 0x255aeb - <unknown>!<wasm function 5288>
          12: 0x29a0a9 - <unknown>!<wasm function 5791>
          13: 0x34e9db - <unknown>!<wasm function 7049>
          14: 0x34e72d - <unknown>!<wasm function 7049>
          15: 0x20286 - <unknown>!<wasm function 105>
          16: 0x1f50e - <unknown>!<wasm function 104>
          17: 0xa882 - <unknown>!<wasm function 86>
          18: 0x22580f - <unknown>!<wasm function 5012>
    1: wasm trap: wasm `unreachable` instruction executed
(jco componentize) Error: Failed to initialize the compiled Wasm binary with Wizer:
Wizering failed to complete
    at componentize (file:///Users/cataggar/tmp/StarlingMonkey15/node_modules/@bytecodealliance/componentize-js/src/componentize.js:271:13)
    at async componentize (file:///Users/cataggar/tmp/StarlingMonkey15/node_modules/@bytecodealliance/jco/src/cmd/componentize.js:11:25)
    at async file:///Users/cataggar/tmp/StarlingMonkey15/node_modules/@bytecodealliance/jco/src/jco.js:200:9

Oct 31 '24 00:10 cataggar

So looking at your JS code, enable() accesses performance.timeOrigin and enable() is called at Wizer time during the initialization of the application.

The bug here is that we don't throw a better error - the error should be:

Error: Cannot access `performance` properties at pre-initialization time.

The fix is to wrap all these enable() callers in a function which is only called on usage of the component, so that you aren't capturing a timeOrigin from the Wizer initialization time.

Hope that helps.

Oct 31 '24 00:10 guybedford

It did! I'm able to disable tryGetPerformanceHooks to avoid accessing performance. I'm able to use yesterday's releases now.

Oct 31 '24 01:10 cataggar

Great to hear, we should definitely improve the error though.

Oct 31 '24 18:10 guybedford