PocketIC - IncompleteMessage when running multiple integration tests

I’m doing some integration testing in rust with pocket-ic. When i run my tests one by one, they all pass correctly. When I run them all together, i get about 6 out of the total that fail all with the same message

failures:

---- tests::test_reward_token_types::test_set_reward_token_types_with_bad_token_symbol stdout ----
thread 'tests::test_reward_token_types::test_set_reward_token_types_with_bad_token_symbol' panicked at /Users/freddie/.cargo/registry/src/index.crates.io-6f17d22bba15001f/pocket-ic-2.2.0/src/lib.rs:773:14:
HTTP failure: reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(61265), path: "/instances/17/update/add_cycles", query: None, fragment: None }, source: hyper::Error(IncompleteMessage) }

---- tests::test_reward_token_types::test_set_reward_token_validate stdout ----
thread 'tests::test_reward_token_types::test_set_reward_token_validate' panicked at /Users/freddie/.cargo/registry/src/index.crates.io-6f17d22bba15001f/pocket-ic-2.2.0/src/lib.rs:773:14:
HTTP failure: reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(61265), path: "/instances/18/update/add_cycles", query: None, fragment: None }, source: hyper::Error(IncompleteMessage) }

---- tests::test_reward_token_types::test_set_reward_token_validate_when_not_governance_canister stdout ----
thread 'tests::test_reward_token_types::test_set_reward_token_validate_when_not_governance_canister' panicked at /Users/freddie/.cargo/registry/src/index.crates.io-6f17d22bba15001f/pocket-ic-2.2.0/src/lib.rs:773:14:
HTTP failure: reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(61265), path: "/instances/19/update/add_cycles", query: None, fragment: None }, source: hyper::Error(IncompleteMessage) }
note: panic did not contain expected string
      panic message: `"HTTP failure: reqwest::Error { kind: Request, url: Url { scheme: \"http\", cannot_be_a_base: false, username: \"\", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(61265), path: \"/instances/19/update/add_cycles\", query: None, fragment: None }, source: hyper::Error(IncompleteMessage) }"`,
 expected substring: `"FATAL ERROR: Caller is not a governance principal"`
---- tests::test_synchronise_neurons::test_synchronise_neurons_happy_path stdout ----
thread 'tests::test_synchronise_neurons::test_synchronise_neurons_happy_path' panicked at /Users/freddie/.cargo/registry/src/index.crates.io-6f17d22bba15001f/pocket-ic-2.2.0/src/lib.rs:773:14:
HTTP failure: reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(61265), path: "/instances/20/update/add_cycles", query: None, fragment: None }, source: hyper::Error(IncompleteMessage) }


failures:
    tests::test_reward_token_types::test_set_reward_token_types_with_bad_token_symbol
    tests::test_reward_token_types::test_set_reward_token_validate
    tests::test_reward_token_types::test_set_reward_token_validate_when_not_governance_canister
    tests::test_synchronise_neurons::test_synchronise_neurons_happy_path

test result: FAILED. 17 passed; 4 failed; 0 ignored; 0 measured; 0 filtered out; finished in 88.18s

Any potential leads on what this could be? Looks like it’s related to adding cycles. There are various points that i reinstall a canister wasm but I do that in other tests as well and those don’t fail.

In parallel or in serie? If the latest, not a solution but, maybe you can try to wait a bit before between those with pic.tick();.

I think this ensure that all previous instructions have been processed or something. I generally have to do so when I upgrade a canister to wait that some debts of instruction is proceeded. Again don’t know exactly, just sharing if it case it could potentialy quickly help.

I was running in series. weirdly in parallel i get less test failures. it must be related to the tick thing. Just not sure where exactly I need to put it. appreciate the reply though :slight_smile:

1 Like

I see more specific errors

each one of the 4 that fail give me this.

Apr 21 12:27:31.821 CRIT s:/n:/ic_state_manager/ic_state_manager Failed to make a checkpoint @23: IoError { path: "/var/folders/d5/4y9bwwld72z5rqmz2nnjhrn80000gn/T/.tmp5LxqFe/tip", message: "Could not sync and mark readonly scratchpad for checkpoint 23", io_err: "Too many open files (os error 24)" }
thread 'tokio-runtime-worker' panicked at rs/state_manager/src/lib.rs:2393:25:
Failed to make a checkpoint @23: IoError { path: "/var/folders/d5/4y9bwwld72z5rqmz2nnjhrn80000gn/T/.tmp5LxqFe/tip", message: "Could not sync and mark readonly scratchpad for checkpoint 23", io_err: "Too many open files (os error 24)" }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread 'tokio-runtime-worker' panicked at rs/pocket_ic_server/src/state_api/state.rs:495:45:
join failed!: JoinError::Panic(Id(1982), ...)

Too many open files (os error 24) sounds like my favorite error but, I face it with dfx and local replica, not pocketic

Recently Stefan suggested a solution which I did not tried yet, maybe it can help?

you just need to increase the resources for the shell ulimit -n 10240

1 Like

When a checkpoint is created, then a bunch of files are created for every canister. This means that if your tests create a lot of canisters in total, then a lot of files will be created upon checkpoints (and also upon creating those canisters although you don’t report that specific error). This is why you need to tweak ulimit -n to make your system not complain about too many open files at the same time.