Wasm runtime tracing

[deuszex]

Hey!

Right now I am looking for tracking the opcode execution inside the runtime. The closest I managed to find was the Trap backtrace in the upcoming 1.0.0-alpha5 version. But in my case I want to track not just in the case of error, but even in the case of correct execution. Adding the tracing into the wasm code itself is not an option.

Am I just missing to find it, or it is actually not an feature? Is it planned? Any suggestions?

[syrusakbary]

We just recently added support for middleware in #1839.

You could use it to inject function calls before each opcode, for example :)

[deuszex]

Thanks for the answer @syrusakbary!
I've been testing the advice you offered since then, and I got to the conclusion that I am lost...

As far as I gathered:
-In Metering wasmer sets a GlobalInitializer with the initial_limit, and sets a GlobalIndex to it (in this case the index is 3).
-The number I get with a mutex counter in the cost_function is the same every time with the same wasm (with my example wasm this is 1226118 ), so I presume it is run only once at 'compile' time, as there are also Function.call()s that exceed this by a huge margin(hundreds of millions of point).

    let import_object = imports! {};
    let mut crane = Cranelift::default();
    let initial_balance : u64 = 1226118;
    let middleware = Arc::new(Metering::new(initial_balance, cost_function)) as Arc<dyn ModuleMiddleware>;
    crane.push_middleware(middleware);
    let store = Store::new(&JIT::new(&crane).engine());
    let module = match Module::new(&store, wasm){
        Ok(m)=>m,
        Err(e)=> panic!(format!("Module cannot be constructed: {}", e))
    };

I cannot seem to find/retrieve the actual remaining_points from module, instance, or store. What I think could be it is is Instance.globals: BoxedSlice<LocalGlobalIndex, Arc<Global>> but it is protected, and might not even have the data I'm looking for.
There is for sure counting in the background, because if set the initial_limit below the "expected" operator count it fails with Unreachable until i set the limit above it.

For one, I am looking for the actual counter (that I presume is on the Instance) that changes as I call the different functions on the Instance.exports functions.

I am also looking for a runtime attachable for actual operation tracing on calls.

Are these possible?

[syrusakbary]

We just merged the metering example, which I think fixes the issue you commented #1867

Let me know if that resolves the issue!

[deuszex]

Yes! It solves the problem with the metric numbers! Great work.

For anyone stumbling upon this issue:
Right now this needs the cargo.toml to have all wasmer dependencies with { git = "https://github.com/wasmerio/wasmer", rev = "2e16b00" }, referencing the latest commit as it's not in the tagged versions yet.
Also need to remove as Arc<dyn ModuleMiddleware> from Metering declaration to work.

My other problem still stands, that is appending another function to the operators. While I can get the remaining point now and it shows a value of 8751485 or 46682 being used (or whatever called function and parameters result), the mutex that I introduced as a counter into the cost_function stays at a value of 314474. In my earlier comment this was the number 1226118 I changed the cost function to always give 1 (with the original function it is still 1226118).

I should probably implement a custom middleware for that I presume?

edit: changed problems to numbers in the first line.

[Hywan]

Is this issue solved?

[deuszex]

One half of it is, the other part is not a concern right now. Closing Issue.