wasm_bindgen_interpreter_workarounds.md

rustwasm/wasm-bindgen#3782 adds coverage output but requires a workaround in wasm-bindgen-interpreter which should be possible to avoid.

In this issue, I want to show where these problems occurs and how I've (unsuccessfully) attempted to solve them so that someone else can maybe pick up where I left off.

Exploring the Issue

cargo new wasm-cov-test

Let's add a simple test to our project:

// src/main.rs

fn bool_to_str(b: bool) -> &'static str {
    if b {
        "true"
    } else {
        "false"
    }
}

#[cfg(test)]
mod test {
    use super::*;

    #[wasm_bindgen_test::wasm_bindgen_test]
    fn  test_bool_to_str() {
        assert_eq!(bool_to_str(true), "true");
    }
}

Make sure you comment out the workarounds in the interpreter and then simply run:

RUSTFLAGS="-Cinstrument-coverage -Zno-profiler-runtime" wasm-pack test --node

which will give us:

thread 'main' panicked at crates/wasm-interpreter/src/lib.rs:222:18:
can only call locally defined functions

I changed the debug message showing which function was called in the interpreter (fn call) to an error for clearer visibility to see the call stack:

[2024-01-16T09:06:05Z ERROR wasm_bindgen_wasm_interpreter] starting a call of Id { idx: 2668 } Some("__wbindgen_describe___wbg_log_066807e304e5b079.command_export")
[2024-01-16T09:06:05Z ERROR wasm_bindgen_wasm_interpreter] starting a call of Id { idx: 48 } Some("__wasm_call_ctors")
[2024-01-16T09:06:05Z ERROR wasm_bindgen_wasm_interpreter] starting a call of Id { idx: 53 } Some("__llvm_profile_init")
[2024-01-16T09:06:05Z ERROR wasm_bindgen_wasm_interpreter] starting a call of Id { idx: 52 } Some("__llvm_profile_register_functions")
[2024-01-16T09:06:05Z ERROR wasm_bindgen_wasm_interpreter] starting a call of Id { idx: 0 } Some("__llvm_profile_register_function")

As a reminder, the only purpose of this interpreter is to process the __wbindgen_describe blocks. So the first call is fine.

The last three calls are clearly calls to the profiler which will obviously lead to issues in the minimalistic interpreter.

wasm2wat target/debug/deps/wasm_cov_test*.wasm > cov_test.wat

We can now search for __wasm_call_ctors:

(func $__wasm_call_ctors (type 1)
    call $__llvm_profile_init
    call $__llvm_profile_init.1
    call $__llvm_profile_init.2
    call $__llvm_profile_init.3
    call $__llvm_profile_init.4
    call $__llvm_profile_init.5
    call $__llvm_profile_init.6
    call $__llvm_profile_init.7
    call $__llvm_profile_init.8
    call $__llvm_profile_init.9
    call $__llvm_profile_init.10
    call $__llvm_profile_init.11
    call $__llvm_profile_init.12
    call $__llvm_profile_init.13
    call $__llvm_profile_init.14
    call $__llvm_profile_init.15
    call $__llvm_profile_init.16
    call $__llvm_profile_init.17
    call $__llvm_profile_init.18
    call $__llvm_profile_init.19
    call $__llvm_profile_init.20
    call $__llvm_profile_init.21
    call $__llvm_profile_init.22
    call $__llvm_profile_init.23)

So there is nothing happening other than some profiling initialization stuff in this function. I assume that this is why this function isn't even generated in the build without profiling. In fact, there are no function calls relevant exclusively to the profiler that don't originate from __wasm_call_ctors.

The problem isn't that this function exists, the problem is that it's being called. We need it to exist because it's important for getting the profiling information later when running the actual tests. We don't need profiling in the generated describe blocks since they're generated. Let's look for how this function is called in the functions that interest us. Our output earlier said that __wbindgen_describe___wbg_log_066807e304e5b079.command_export was calling it.

(func $__wbindgen_describe___wbg_log_066807e304e5b079.command_export (type 1)
    call $__wasm_call_ctors
    call $__wbindgen_describe___wbg_log_066807e304e5b079)

This is just a proxy function that initializes the profiler before calling the function we're actually interested in. Once again, this function isn't generated when we turn off profiling information. The actual function - without the trailing .command_export, however is.

You might think that it would be enough to simply skip the call to __wasm_call_ctors in order to find the proper function. It is indeed a step in the right direction (which is why it's part of the workaround found in the interpreter) but it isn't sufficient. We can see why when looking at the code for __wbindgen_describe___wbg_log_066807e304e5b079.

(func $__wbindgen_describe___wbg_log_066807e304e5b079 (type 1)
    (local i32 i32 i32 i32 i64 ...)
    global.get $__stack_pointer
    local.set 0
    i32.const 16
    local.set 1
    local.get 0
    local.get 1
    i32.sub
    local.set 2
    local.get 2
    global.set $__stack_pointer
    i32.const 0
    local.set 3
    local.get 3
    i64.load offset=1287056
    local.set 4
    i64.const 1
    local.set 5
    local.get 4
    local.get 5
    i64.add
    local.set 6
    i32.const 0
    local.set 7
    local.get 7
    local.get 6
    i64.store offset=1287056
    ...)

For comparison, here's a different excerpt of the version without profiling infomation:

(func $__wbindgen_describe___wbg_log_066807e304e5b079 (type 1)
    (local i32 i32 i32 i32 i32 i32 i32 i32 i32 i32 i32)
    global.get $__stack_pointer
    local.set 0
    i32.const 16
    local.set 1
    local.get 0
    local.get 1
    i32.sub
    local.set 2
    local.get 2
    global.set $__stack_pointer
    ...)

There are five places where the interpreter runs into trouble:

• declare i64
• const i64
• add i64
• load i64
• store i64

All of these are related to the profiler setting which lines/functions were hit. This explains why __wasm_call_ctors was called. The profiling information is initialized before the function is called and is then set while the function is running.

It wouldn't be hard to simply allow the interpreter to handle the first three cases but the last one is the one that causes big issues.

i64.store offset=1287056

This is simply a much too large of an offset. The interpreter is currently configured to use a stack size of 1KiB. Not to mention that having the interpreter - that runs before the actual tests - handle profiling is a complete waste of everyone's time.

In theory, removing coverage from all __wbindgen_describe blocks, should fix:

• __wasm_call_ctors won't be called
• i64 instructions won't be generated, so we won't have to work around them
• the interpreter would probably also be a lot faster when handling code created with profiling info

Fixing This

There is support for skipping the generation of profiling information with the unstable feature #[coverage(off)]. You can use a nightly compiler and cherry-pick this commit to enable the feature and see my attempt.

You would have to find all places where a __wbindgen_describe_* function is created and mark it as #[coverage(off)].

I attempted to add it to every fn describe() in the repo (as you can see in the commit above) but this didn't appear to change anything.

I think the whole recompiling Rust with stable coverage_attribute can be circumvented by hiding it behind a crate feature which requires nightly.

You can then use the following to allow using unstable features inside proc-macros:
In the proc-macro crate:

#![cfg_attr(
    feature = "unstable-coverage",
    feature(allow_internal_unstable),
    allow(internal_features)
)]

On the proc-macro definition itself:

#[cfg_attr(feature = "unstable-coverage", allow_internal_unstable(coverage_attribute))]

I added a note 👍