Error: Debug Messages are Printed Twice

[maxrobot]

Description: when trying to debug my contracts I noticed that some debug messages would be printed twice.

I have even created an integration test here

Which simply instantiates a contract with a debug message:

#[cfg(not(tarpaulin_include))]
#[cfg_attr(not(feature = "library"), entry_point)]
pub fn instantiate(
    deps: DepsMut,
    _env: Env,
    _info: MessageInfo,
    _msg: InstantiateMsg,
) -> StdResult<Response> {
    deps.api.debug(&format!("\nInstantiate Mock Query"));
    Ok(Response::default())
}

When I execute the linked test in the test-tube repo as follows:

user@machine:test-tube$ cargo test wasm_integration
    Finished test [unoptimized + debuginfo] target(s) in 0.12s
     Running unittests src/lib.rs (target/debug/deps/osmosis_test_tube-cb3dd881bea82e8e)

running 1 test

Instantiate Mock Query

Instantiate Mock Query
test module::wasm::tests::wasm_integration ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 17 filtered out; finished in 0.12s

     Running unittests src/lib.rs (target/debug/deps/test_tube-4170a80f535dabc4)

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 3 filtered out; finished in 0.00s

As shown above Instantiate Mock Query is printed twice, further investigation printing the block info shows also that these transaction are executed at different block heights.

I am very confused why this would be happening and would be grateful for any pointers how to stop/solve this from happening.

[iboss-ptk]

It is not being executed twice but it's because fee setting is auto by default, which calls estimate_fee which calls Simulate to get consumed gas for simulation. In which it does invoke wasm-vm entrypoint, thus deps.api.debug is being called.

For block height, after some investigation, it seems to be how Simulate and DeliverTx behaves differently. Both calls runTx under the hood but with different mode. Even calling Simulate and DeliverTx in this sequence on the same tx:

Simuate(tx)  -> DeliverTx(tx)  -> Simulate(tx)

We get:

h -> h + 1 -> h

Where h is the previous block height.

[maxrobot]

Ah that's very interesting actually I will need to take a look myself.

Do you think it might be possible to silence them somehow? Reason being that when debugging contracts it's useful to print some debug messages, however it is more difficult to do so if we have duplicated outputs?

Thanks for the great response :)

[iboss-ptk]

I haven't yet find a clean solution to prevent this, at first I thought switching wasmOptson the fly might help, since the reason why deps.api.debug works is due to this option but it's set on instantiating keeper and I haven't yet find way to replace them nicely.

Another option is to just redirect all stdout altogether in Simulate function (example), this is kind of hacky since then all other potentially useful stdout will be gone.

We could make that an optional config to allow Simulate stdout. What do you think @maxrobot ?

[maxrobot]

Maybe this is super stupid thought but why do we need to have Simulate for the fee setting, could we not just turn that to optional for test-tube?

[maxrobot]

Happy for this to be closed as it's not an issue from my PoV anymore :)