Skip to content

Better error for performance access at Wizer time #153

Open
Open
Better error for performance access at Wizer time#153

Description

@cataggar
cataggar
opened on Oct 30, 2024

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

Activity

  1. guybedford commented on Oct 30, 2024

    @guybedford
    guybedford
    on Oct 30, 2024

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

  2. cataggar commented on Oct 30, 2024

    @cataggar
    cataggar
    on Oct 30, 2024
    ContributorAuthor

    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

  3. guybedford commented on Oct 30, 2024

    @guybedford
    guybedford
    on Oct 30, 2024

    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.

  4. guybedford commented on Oct 30, 2024

    @guybedford
    guybedford
    on Oct 30, 2024

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

  5. cataggar commented on Oct 30, 2024

    @cataggar
    cataggar
    on Oct 30, 2024
    ContributorAuthor

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

  6. guybedford commented on Oct 31, 2024

    @guybedford
    guybedford
    on Oct 31, 2024

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

  7. cataggar commented on Oct 31, 2024

    @cataggar
    cataggar
    on Oct 31, 2024
    ContributorAuthor

    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

  8. guybedford commented on Oct 31, 2024

    @guybedford
    guybedford
    on Oct 31, 2024

    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.

  9. guybedford
    changed the title [-]timeOrigin still not set[/-] [+]Better error for `performance` access at Wizer time[/+] on Oct 31, 2024
  10. cataggar
    added a commit that references this issue on Oct 31, 2024

    Cannot access performance properties at pre-initialization time.

    79cc63b

  11. cataggar commented on Oct 31, 2024

    @cataggar
    cataggar
    on Oct 31, 2024
    ContributorAuthor

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

  12. guybedford commented on Oct 31, 2024

    @guybedford
    guybedford
    on Oct 31, 2024

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions