Better error for `performance` access at Wizer time

[cataggar]

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 cb4d73a#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

[guybedford]

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

[cataggar]

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 <gbedford@fastly.com>
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

[guybedford]

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.

[guybedford]

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

[cataggar]

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

[guybedford]

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);
  }
};

[cataggar]

Here are the steps to reproduce.

git clone git@github.com: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

[guybedford]

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.

[cataggar]

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

[guybedford]

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