Add context to multitest execution errors #597

uint · 2021-12-22T20:48:50Z

Closes #575

uint · 2021-12-22T21:03:06Z

packages/multi-test/src/contracts.rs

+        let address = env.contract.address.clone();
+        (self.execute_fn)(deps, env, info.clone(), msg.clone())
+            .map_err(|err| anyhow!("{}", err))
+            .context(format!(


@ueco-jb This stuff takes the ContractError you'd normally return in a contract entrypoint, makes an anyhow::Error out of it, and then wraps that in another anyhow::Error, now with extra info (address, sender, etc). So we're not getting extra stdout logs, it's just the error now has more info.

If you look at the failing test, it refers to places like this in code: https://github.com/CosmWasm/cw-plus/blob/main/contracts/cw3-flex-multisig/src/contract.rs#L1089. Basically it looks like downcast stopped working with the added context, and I'm not sure why yet.

If you're happy with the direction though, I'll investigate when I'm back.

Adding context to the error does seem like a very nice way of handling it.

I assume this context is print out when we do res.unwrap() on the Err variant. If so, this seems like a very nice addition.

Question: if this is nested - execute calls execute in submsg, 2nd contract errors - this will show context for both contracts, right?

A test showing the error message in such a case would be great to evaluate it. (I know... super hard to do CI there, maybe just something marked "#[skip]" that I can modify that line and run locally to evaluate

Question: if this is nested - execute calls execute in submsg, 2nd contract errors - this will show context for both contracts, right?

Yes, although I haven't tested it with more levels of nesting I think. A test would be nice for that. I'll look at that.

Okay, the nested thing didn't quite work, but I fixed it. There are tests showing it works. There's a way to take a peek what the display looks like now: https://github.com/CosmWasm/cw-plus/pull/597/files#r778142632

ethanfrey

Added a comment for more details, but if it works as I think it does, I like the direction

ethanfrey · 2021-12-28T11:41:57Z

packages/multi-test/src/contracts.rs

+        let address = env.contract.address.clone();
+        (self.execute_fn)(deps, env, info.clone(), msg.clone())
+            .map_err(|err| anyhow!("{}", err))
+            .context(format!(


Adding context to the error does seem like a very nice way of handling it.

I assume this context is print out when we do res.unwrap() on the Err variant. If so, this seems like a very nice addition.

Question: if this is nested - execute calls execute in submsg, 2nd contract errors - this will show context for both contracts, right?

A test showing the error message in such a case would be great to evaluate it. (I know... super hard to do CI there, maybe just something marked "#[skip]" that I can modify that line and run locally to evaluate

uint · 2022-01-04T14:53:43Z

packages/multi-test/src/app.rs

+                .unwrap_err();
+
+            // uncomment to have the test fail and see how the error stringifies
+            // panic!("{:?}", err);


A dirty way to take a peek at the debug formatted error with two levels of nesting.

I get:

---- app::test::errors::double_nested_call stdout ---- thread 'app::test::errors::double_nested_call' panicked at 'error executing WasmMsg: sender: random Execute { contract_addr: "Contract #0", msg: Binary([123, 34, 101, 120, 101, 99, 117, 116, 101, 34, 58, 123, 34, 99, 111, 110, 116, 114, 97, 99, 116, 95, 97, 100, 100, 114, 34, 58, 34, 67, 111, 110, 116, 114, 97, 99, 116, 32, 35, 49, 34, 44, 34, 109, 115, 103, 34, 58, 34, 101, 121, 74, 108, 101, 71, 86, 106, 100, 88, 82, 108, 73, 106, 112, 55, 73, 109, 78, 118, 98, 110, 82, 121, 89, 87, 78, 48, 88, 50, 70, 107, 90, 72, 73, 105, 79, 105, 74, 68, 98, 50, 53, 48, 99, 109, 70, 106, 100, 67, 65, 106, 77, 105, 73, 115, 73, 109, 49, 122, 90, 121, 73, 54, 73, 109, 85, 122, 77, 68, 48, 105, 76, 67, 74, 109, 100, 87, 53, 107, 99, 121, 73, 54, 87, 49, 49, 57, 102, 81, 61, 61, 34, 44, 34, 102, 117, 110, 100, 115, 34, 58, 91, 93, 125, 125]), funds: [] } Caused by: 0: error executing WasmMsg: sender: Contract #0 Execute { contract_addr: "Contract #1", msg: Binary([123, 34, 101, 120, 101, 99, 117, 116, 101, 34, 58, 123, 34, 99, 111, 110, 116, 114, 97, 99, 116, 95, 97, 100, 100, 114, 34, 58, 34, 67, 111, 110, 116, 114, 97, 99, 116, 32, 35, 50, 34, 44, 34, 109, 115, 103, 34, 58, 34, 101, 51, 48, 61, 34, 44, 34, 102, 117, 110, 100, 115, 34, 58, 91, 93, 125, 125]), funds: [] } 1: error executing WasmMsg: sender: Contract #1 Execute { contract_addr: "Contract #2", msg: Binary([123, 125]), funds: [] } 2: Contract returned an error on execute msg: EmptyMsg 3: Generic error: Handle failed', packages/multi-test/src/app.rs:2693:13 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

This is a great output.
I just also realise we need a better debug encoding for Binary.

Added CosmWasm/cosmwasm#1199 which could be an interesting follow-up sometime.

Sounds good! It's probably not super important that the binary stuff is readable here - it's usually going to be something predictable like WasmMsg::Execute, and then the contract execute msg itself will be shown in its deserialized form. Like 2: in your output.

ethanfrey

Great stuff.

A few items for follow-up (pretty sure they were on your plate, but double-checking) but a great improvement.

ethanfrey · 2022-01-04T17:04:20Z

packages/multi-test/src/app.rs

+                .instantiate_contract(error_code_id, owner, &msg, &[], "error", None)
+                .unwrap();
+
+            // caller1 calls caller2, caller2 calls error


ethanfrey · 2022-01-04T17:08:37Z

packages/multi-test/src/app.rs

+                .unwrap_err();
+
+            // uncomment to have the test fail and see how the error stringifies
+            // panic!("{:?}", err);


I get:

---- app::test::errors::double_nested_call stdout ---- thread 'app::test::errors::double_nested_call' panicked at 'error executing WasmMsg: sender: random Execute { contract_addr: "Contract #0", msg: Binary([123, 34, 101, 120, 101, 99, 117, 116, 101, 34, 58, 123, 34, 99, 111, 110, 116, 114, 97, 99, 116, 95, 97, 100, 100, 114, 34, 58, 34, 67, 111, 110, 116, 114, 97, 99, 116, 32, 35, 49, 34, 44, 34, 109, 115, 103, 34, 58, 34, 101, 121, 74, 108, 101, 71, 86, 106, 100, 88, 82, 108, 73, 106, 112, 55, 73, 109, 78, 118, 98, 110, 82, 121, 89, 87, 78, 48, 88, 50, 70, 107, 90, 72, 73, 105, 79, 105, 74, 68, 98, 50, 53, 48, 99, 109, 70, 106, 100, 67, 65, 106, 77, 105, 73, 115, 73, 109, 49, 122, 90, 121, 73, 54, 73, 109, 85, 122, 77, 68, 48, 105, 76, 67, 74, 109, 100, 87, 53, 107, 99, 121, 73, 54, 87, 49, 49, 57, 102, 81, 61, 61, 34, 44, 34, 102, 117, 110, 100, 115, 34, 58, 91, 93, 125, 125]), funds: [] } Caused by: 0: error executing WasmMsg: sender: Contract #0 Execute { contract_addr: "Contract #1", msg: Binary([123, 34, 101, 120, 101, 99, 117, 116, 101, 34, 58, 123, 34, 99, 111, 110, 116, 114, 97, 99, 116, 95, 97, 100, 100, 114, 34, 58, 34, 67, 111, 110, 116, 114, 97, 99, 116, 32, 35, 50, 34, 44, 34, 109, 115, 103, 34, 58, 34, 101, 51, 48, 61, 34, 44, 34, 102, 117, 110, 100, 115, 34, 58, 91, 93, 125, 125]), funds: [] } 1: error executing WasmMsg: sender: Contract #1 Execute { contract_addr: "Contract #2", msg: Binary([123, 125]), funds: [] } 2: Contract returned an error on execute msg: EmptyMsg 3: Generic error: Handle failed', packages/multi-test/src/app.rs:2693:13 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

ethanfrey · 2022-01-04T17:12:31Z

packages/multi-test/src/app.rs

+                .unwrap_err();
+
+            // uncomment to have the test fail and see how the error stringifies
+            // panic!("{:?}", err);


This is a great output.
I just also realise we need a better debug encoding for Binary.

Added CosmWasm/cosmwasm#1199 which could be an interesting follow-up sometime.

ethanfrey · 2022-01-04T17:13:59Z

packages/multi-test/src/executor.rs

-            msg,
+        let binary_msg = to_binary(msg)?;
+        let wrapped_msg = WasmMsg::Execute {
+            contract_addr: contract_addr.to_string(),


to_string is more explicit, but does require a clone.
into_string?

(Note: this is pedantic to even worry about performance here... this is test code after all... just my usual review bugs chipped in)

Good catch.

ethanfrey · 2022-01-04T17:14:35Z

packages/multi-test/src/test_helpers/contracts/caller.rs

+    Ok(Response::default())
+}
+
+fn execute(


This is an even simpler form of reflect. Great example

ethanfrey · 2022-01-04T17:16:03Z

packages/multi-test/src/contracts.rs

+            .context(format!(
+                "Contract returned an error on execute msg:\n{:?}",
+                msg,
+            ))
    }

    fn instantiate(


We should do the same map error here and for query, right?

I assume that will be a follow-up PR, but just want to double check

Ah yeah, I guess I shouldn't close the issue until those are implemented.

ethanfrey · 2022-01-05T10:56:06Z

packages/multi-test/src/contracts.rs

-        let msg = from_slice(&msg)?;
-        (self.instantiate_fn)(deps, env, info, msg).map_err(|err| anyhow!(err))
+        let msg: T2 = from_slice(&msg)?;
+        (self.instantiate_fn)(deps, env, info, msg.clone())


Just a thought, we could remove the Clone bound if you did the following, right?

let ctx = format!("Contract returned an error on instantiate msg:\n{:?}", msg); (self.instantiate_fn)(deps, env, info, msg).map_err(anyhow::Error::from).context(ctx)

Nothing really important, just like reducing required bounds and removing clones when possible.

Huh, yeah, that looks much better. Will do 👍

ethanfrey · 2022-01-05T10:56:24Z

packages/multi-test/src/contracts.rs

@@ -319,13 +319,13 @@ impl<T1, T2, T3, E1, E2, E3, C, T4, E4, E5, T6, E6> Contract<C>
    for ContractWrapper<T1, T2, T3, E1, E2, E3, C, T4, E4, E5, T6, E6>
 where
    T1: DeserializeOwned + Debug + Clone,
-    T2: DeserializeOwned,
-    T3: DeserializeOwned,
+    T2: DeserializeOwned + Debug + Clone,


Would remove Clone from T1, T2, T3

ethanfrey · 2022-01-05T10:56:40Z

packages/multi-test/src/contracts.rs

    }

    fn query(&self, deps: Deps, env: Env, msg: Vec<u8>) -> AnyResult<Binary> {
-        let msg = from_slice(&msg)?;
-        (self.query_fn)(deps, env, msg).map_err(|err| anyhow!(err))
+        let msg: T3 = from_slice(&msg)?;


Thanks to add these two and the simple test. Looks good to me

add context to multitest execution errors

b4e8e67

uint mentioned this pull request Dec 22, 2021

Add more debug output from multi-test #575

Closed

uint commented Dec 22, 2021

View reviewed changes

ethanfrey reviewed Dec 28, 2021

View reviewed changes

uint added 3 commits January 3, 2022 19:13

multitest: add a contract that tests WasmMsg calls

582e47e

multitest: add tests for contract errors

0291e82

multitest: handle nested error contexts properly

2c90217

uint force-pushed the 575-multitest-debug branch from 18b97c8 to 2c90217 Compare January 4, 2022 14:38

clippy

05cf444

uint force-pushed the 575-multitest-debug branch from c8addae to 05cf444 Compare January 4, 2022 14:47

uint added 2 commits January 4, 2022 15:50

multitest: test comments

3eb5e2d

Merge branch 'main' into 575-multitest-debug

ad155f5

uint marked this pull request as ready for review January 4, 2022 14:51

uint commented Jan 4, 2022

View reviewed changes

uint requested review from ethanfrey, hashedone, maurolacy and ueco-jb January 4, 2022 14:54

ethanfrey approved these changes Jan 4, 2022

View reviewed changes

uint added 3 commits January 4, 2022 21:02

multitest: style

708e572

multitest: context for queries and instantiations

ef50e4b

cw1-whitelist: missing InstantiateMsg derives

ede69a5

uint merged commit 11e9585 into main Jan 4, 2022

uint deleted the 575-multitest-debug branch January 4, 2022 20:41

ethanfrey reviewed Jan 5, 2022

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add context to multitest execution errors #597

Add context to multitest execution errors #597

uint commented Dec 22, 2021 •

edited

Loading

uint Dec 22, 2021

ethanfrey Dec 28, 2021

uint Jan 3, 2022

uint Jan 4, 2022

ethanfrey left a comment

ethanfrey Dec 28, 2021

uint Jan 4, 2022

ethanfrey Jan 4, 2022

ethanfrey Jan 4, 2022

uint Jan 4, 2022

ethanfrey left a comment

ethanfrey Jan 4, 2022

ethanfrey Jan 4, 2022

ethanfrey Jan 4, 2022

ethanfrey Jan 4, 2022

uint Jan 4, 2022

ethanfrey Jan 4, 2022

ethanfrey Jan 4, 2022

uint Jan 4, 2022

ethanfrey Jan 5, 2022

uint Jan 5, 2022

ethanfrey Jan 5, 2022

ethanfrey Jan 5, 2022

Add context to multitest execution errors #597

Add context to multitest execution errors #597

Conversation

uint commented Dec 22, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ethanfrey left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ethanfrey left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

uint commented Dec 22, 2021 •

edited

Loading