Ic_cdk v0.18.3 - test 'Panicked at 'Call already trapped'

Developers Rust
1

I’m migrating Juno’s codebase to ic_cdk 0.18.3, and while doing so, a few tests are failing for the following reasons:

2021-05-06 19:17:10.000000213 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] [ic-cdk-timers] canister_global_timer: CallRejected(CallRejected { raw_reject_code: 5, reject_message: “IC0503: Error from Canister lxzze-o7777-77777-aaaaa-cai: Canister called ic0.trap with message: ‘Panicked at ‘Call already trapped’, /cargo/registry/src/index.crates.io-1949cf8c6b5b557f/ic-cdk-executor-1.0.0/src/lib.rs:80:13’.\nConsider gracefully handling failures from this canister or altering the canister to handle exceptions. See documentation: https://internetcomputer.org/docs/current/references/execution-errors#trapped-explicitly” })

What breaking changes could have caused this error? Or is there a bug?

I’ve upgraded the dependencies and adapted the usage of ic_cdk::futures::spawn, but aside from that, I haven’t made any other changes.

PR and CI: https://github.com/junobuild/juno/pull/1557

2

Could you point me to the failing tests? Also, it might be worthwile to look into spawn ordering changes and custom macros section in the migration guide as they might be related.

3

I had a look at the spawn ordering. As far I can tell after double checking, I think, I actually never “depend on the code in the spawned future running before the code below”, as mentioned in the CHANGELOG, so I assume it should be fine.

As for custom macros, I don’t even know how they work, so we can safely assume I don’t use them.

git clone https://github.com/junobuild/juno
cd juno
git checkout build/ic-cdk-18
npm ci
mkdir -p target/deploy # side note: I should fix this

# Install required tools:
# see HACKING.md
# https://github.com/junobuild/juno/blob/main/HACKING.md#required-tools
# might also be able to just run the script ./docker/bootstrap

npm run build:test-sputnik

npm run test src/tests/specs/sputnik/sputnik.sdk.get-doc-store.spec.ts

Link to the test source code: https://github.com/junobuild/juno/blob/main/src/tests/specs/sputnik/sputnik.sdk.get-doc-store.spec.ts

That said, it’s definitely not a starter repo - there are many layers involved.

Side note: the test suite obviously passes successfully on main with ic_cdk 0.1.17.

4

That said, it’s definitely not a starter repo - there are many layers involved.

You weren’t kidding :sweat_smile:.

On first glance, I don’t see anything obviously wrong.

wrt to custom macros and spawn, two possible things can go wrong that could trap

  1. Calling spawn without an outer in_executor_context or in_query_context
  2. Calling in_executor_context inside another in_executor_context.

Outside of this, another possible issue would be incompatibility with rquickjs Runtime. I would let @AdamS comment on that.

1 Like
5

Thanks for the feedback. Interesting, it seems that tests using rquickjs in a synchronous context pass, but those that require futures do not.

6

Could it be related to a trap occurring within the spawn?

#[no_mangle]
pub extern "Rust" fn juno_on_set_doc(context: OnSetDocContext) {
    spawn(async move {
        let execute_context = AsyncJsFnContext { context };

        if let Err(e) = execute_async_js(execute_context).await {
            trap(&e.to_string());
        }
    });
}

Update: actually trap is not used in the tests that fail.

7

Juno appears to use many custom macros from the crate at path libs/macros, which has not been updated to the new boilerplate described in the migration guide.

8

I’m confused, which section of the migration guide precisely?

9

The ‘custom exports’ section at the bottom. Unless I am misinterpreting how these macros work.

1 Like
10

Gotcha, when @vsekar mentionned it earlier, I assumed it was about “Custom Decoders/Encoders in Macros” and not “Custom Exports (advanced)”. The term “Macros” in the first title was the confusion, mislead it, my bad.

Let me check…

11

So, the good news, is that migrating as following resolve the original error message of the thread:

#[no_mangle]
pub extern "Rust" fn juno_on_set_doc(context: OnSetDocContext) {
    in_executor_context(|| {
        spawn(async move {
            let execute_context = AsyncJsFnContext { context };

            if let Err(e) = execute_async_js(execute_context).await {
                trap(&e.to_string());
            }
        });
    });
}

But, I’m now getting this other error message:

2021-05-06 19:17:10.000000213 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] Panicked at ‘in_*_context called within an existing async context’, /cargo/registry/src/index.crates.io-1949cf8c6b5b557f/ic-cdk-executor-1.0.0/src/lib.rs:152:13
2021-05-06 19:17:10.000000213 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] [ic-cdk-timers] canister_global_timer: CallRejected(CallRejected { raw_reject_code: 5, reject_message: “IC0503: Error from Canister lxzze-o7777-77777-aaaaa-cai: Canister called ic0.trap with message: ‘Panicked at ‘in_*_context called within an existing async context’, /cargo/registry/src/index.crates.io-1949cf8c6b5b557f/ic-cdk-executor-1.0.0/src/lib.rs:152:13’.\nConsider gracefully handling failures from this canister or altering the canister to handle exceptions. See documentation: https://internetcomputer.org/docs/current/references/execution-errors#trapped-explicitly” })

12

This indicates both of the above are not the issue.

13

So I should revert this commit - i.e. I should not add in_executor_context to my code base, right? Which means the issue is something else?

14

Okay, so I did misinterpret and you’re backending to the CDK macros somewhere. By exported functions, to be clear, I just mean the ones that start with canister_ - non-entrypoints don’t count. So you don’t need to insert any new calls (you would spot those as #[export_name = "canister_update myfunction"]).

Further testing indicates that you are, in fact, running afoul of spawn ordering, though I couldn’t tell you where. If I patch your crate to use this hack, the test passes. We intend this function to ship in the next release.

15

Ok. Reverted my commit.

Me neither.

#[update]
pub fn set_doc(collection: CollectionKey, key: Key, doc: SetDoc) -> Doc {
    ...
    
    match result {
        Ok(doc) => {
            invoke_on_set_doc(&caller, &doc); // <--- enters here

            doc.data.after // <----- this is maybe the issue?
        }
        Err(error) => trap(&error),
    }
}

#[allow(unused_variables)]
pub fn invoke_on_set_doc(caller: &UserId, doc: &DocContext<DocUpsert>) {
    #[cfg(feature = "on_set_doc")]
    {
        ...

        unsafe {
            let collections = juno_on_set_doc_collections();

            if should_invoke_doc_hook(collections, &context) {
                set_timer(Duration::ZERO, || { 
                    juno_on_set_doc(context); // <--- calls extern
                });
            }
        }
    }
}

#[no_mangle]
pub extern "Rust" fn juno_on_set_doc(context: OnSetDocContext) {
    spawn(async move {
        let execute_context = AsyncJsFnContext { context };

        if let Err(e) = execute_async_js(execute_context).await {
            trap(&e.to_string());
        }
    });
}

Thanks! :+1:

Will it be a minor update, and do you already have a schedule?

16

Yes, 0.18.4.

Immediately. spawn_017_compat in ic_cdk::futures - Rust

1 Like
17

Awesome, thanks! Migrating all spawn functions to spawn_017_compat resolves two of the three tests that were failing but, there is one that ends in error.

npm run test src/tests/specs/sputnik/sputnik.ic-cdk-call.spec.ts

2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] Panicked at ‘Call already trapped’, /cargo/registry/src/index.crates.io-1949cf8c6b5b557f/ic-cdk-executor-1.0.0/src/lib.rs:80:13

It happens when I perform a raw call in a spawned async context - i.e. when I use the following:

#[rquickjs::function]
async fn ic_cdk_call_raw<'js>(
    ctx: Ctx<'js>,
    canister_id: JsRawPrincipal<'js>,
    method: String<'js>,
    args: JsCallRawArgs<'js>,
) -> JsResult<JsCallRawResult<'js>> {
    let id = canister_id.to_principal()?;

    let args_raw = args.to_bytes()?;

    let result = call_raw(id, &method.to_string()?, args_raw, 0).await;

    match result {
        Err(err) => Err(throw_js_exception(
            &ctx,
            JUNO_SPUTNIK_ERROR_IC_CDK_CALL_RAW,
            format!("{}: {}", err.0 as i32, &err.1),
        )),
        Ok(bytes) => JsCallRawResult::from_bytes(&ctx, &bytes),
    }
}

Do you have an idea?

18

Mmmh everything seems expected.

#[no_mangle]
pub extern "Rust" fn juno_on_set_doc(context: OnSetDocContext) {
    
    ic_cdk::println!("----------> 0");
    
    spawn_017_compat(async move {
        let execute_context = AsyncJsFnContext { context };

            ic_cdk::println!("----------> 1");

        if let Err(e) = execute_async_js(execute_context).await {
                ic_cdk::println!("----------> 2");
            
            trap(&e.to_string());
        }

            ic_cdk::println!("----------> 3");
     });
        
     ic_cdk::println!("----------> 4");
}

// Around the raw call ...

    ic_cdk::println!("---------> call___________0");

    let result = call_raw(id, &method.to_string()?, args_raw, 0).await;

    ic_cdk::println!("---------------------> call___________1");

And I get

2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> 0
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> 1
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> call___________0
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> 4
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> call___________1
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] --------------------> 3
2021-05-06 19:17:10.000000219 UTC: [Canister lxzze-o7777-77777-aaaaa-cai] Panicked at ‘Call already trapped’, /cargo/registry/src/index.crates.io-1949cf8c6b5b557f/ic-cdk-executor-1.0.0/src/lib.rs:80:13