try-runtime follow-chain seems broken

[liamaharon]

Is there an existing issue?

• I have searched the existing issues

Experiencing problems? Have you tried our Stack Exchange first?

• This is not a support question.

Description of bug

As reported in this SO post follow-chain logs a curious error when used according to instructions.

Waiting for @kianenigma to double check that this is not user error. If confirmed a bug and time permits I'm interested in taking the issue.

Steps to reproduce

1. git clone https://github.com/substrate-developer-hub/substrate-node-template.git
2. cargo build -r
3. cp ./target/release/node-template .
4. cargo build -r --features=try-runtime
5. cp ./target/release/node-template ./node-template-try-runtime
6. cp ./target/release/wbuild/node-template-runtime/node_template_runtime.wasm ./runtime-try-runtime.wasm
7. ./node-template --dev
8. (in a different terminal)

./node-template-try-runtime \
    try-runtime \
    --runtime runtime-try-runtime.wasm \ 
    -lruntime=debug \
    follow-chain \
    --uri ws://localhost:9944

Output:

$ ./node-template-try-runtime try-runtime -lruntime=debug --runtime runtime-try-runtime.wasm follow-chain --uri ws://localhost:9944

2023-03-23 18:57:16.935  INFO main try-runtime::cli: subscribing to "chain_subscribeFinalizedHeads" / "chain_unsubscribeFinalizedHeads"
2023-03-23 18:57:16.938  INFO main remote-ext: since no prefix is filtered, the data for all pallets will be downloaded
2023-03-23 18:57:16.939  INFO main remote-ext: scraping key-pairs from remote at block height 0x983dd9c8956066e16614931e2ced38ce00545663426bfc60ccdc41256447323c
2023-03-23 18:57:16.939  INFO main remote-ext: adding data for hashed prefix: 3a6368696c645f73746f726167653a64656661756c743a, took 0s
2023-03-23 18:57:16.939  INFO main remote-ext: Querying a total of 36 keys from prefix , splitting among 8 threads, 5 keys per thread
2023-03-23 18:57:16.944  INFO main remote-ext: adding data for hashed prefix: , took 0s
2023-03-23 18:57:16.944  INFO main remote-ext: adding data for hashed key: 3a636f6465
2023-03-23 18:57:16.947  INFO main remote-ext: adding data for hashed key: 26aa394eea5630e07c48ae0c9558cef7f9cce9c888469bb1a0dceaa129672ef8
2023-03-23 18:57:16.947  INFO main remote-ext: adding data for hashed key: 26aa394eea5630e07c48ae0c9558cef702a5c1b19ab7a04f536c519aca4983ac
2023-03-23 18:57:16.947  INFO main remote-ext: initialized state externalities with storage root 0x46b1c5672777f6ade7e0642446079ff3a170e0723b36cdf7bc5e0279f9396620 and state_version V1
2023-03-23 18:57:16.958  INFO main try-runtime::cli: original spec: RuntimeString::Owned("node-template")-100, code hash: 8958348fee00241d329b5ae60038f81327919277c9689a99efb391c1bde2939d
2023-03-23 18:57:16.964  INFO main try-runtime::cli: new spec: RuntimeString::Owned("node-template")-100, code hash: 2ba5db522fe028e0c2733c7d1a173383371bb514cf3c34475c7510b874aabc7c
2023-03-23 18:57:16.984 ERROR main runtime: panicked at 'Bad input data provided to execute_block: Codec error', /Users/liamaharon/grimoire/substrate-node-template/runtime/src/lib.rs:352:1
2023-03-23 18:57:16.985 ERROR main try-runtime::cli: failed to execute block 3 due to Input("failed to execute TryRuntime_execute_block: Execution aborted due to trap: unreachable")
2023-03-23 18:57:19.093 ERROR main runtime: panicked at 'Bad input data provided to execute_block: Codec error', /Users/liamaharon/grimoire/substrate-node-template/runtime/src/lib.rs:352:1
2023-03-23 18:57:19.093 ERROR main try-runtime::cli: failed to execute block 4 due to Input("failed to execute TryRuntime_execute_block: Execution aborted due to trap: unreachable")

[liamaharon]

Error originates here:

substrate/primitives/state-machine/src/lib.rs

Lines 408 to 415 in 4bf67fb

	let (result, was_native) = self.exec.call(
	&mut ext,
	self.runtime_code,
	self.method,
	self.call_data,
	use_native,
	self.context,
	);

Result:

Err(
    AbortedDueToTrap(
        MessageWithBacktrace {
            message: "unreachable",
            backtrace: None,
        },
    ),
)

Going to traverse the commit history to see where the bug was introduced.

[liamaharon]

Panics with a different error starting polkadot-v0.9.35:

Thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: ParseError(Error("unknown field `block`, expected `header` or `extrinsics`", line: 0, column: 0))', /Users/liamaharon/grimoire/substrate/utils/frame/try-runtime/cli/src/commands/follow_chain.rs:110

[liamaharon]

Latest version I can get this working is polkadot-v0.9.30

[liamaharon]

I've made a little progress debugging (on polkadot-v0.9.40).

The error is emitted at the injected decode_params step that is injected immediately before the execute_block runtime api is executed.

Error:

2023-03-23 18:57:16.984 ERROR main runtime: panicked at 'Bad input data provided to execute_block: Codec error'

Code:

substrate/primitives/api/proc-macro/src/impl_runtime_apis.rs

Lines 101 to 110 in 4bf67fb

	quote!(
	#let_binding =
	match #c::DecodeLimit::decode_all_with_depth_limit(
	#c::MAX_EXTRINSIC_DEPTH,
	&mut #input,
	) {
	Ok(res) => res,
	Err(e) => panic!("Bad input data provided to {}: {}", #fn_name_str, e),
	};
	)

So, what's the bad input data being provided? I modified the panic! to log the input:

Err(e) => {
	panic!("Bad input data provided to {}: {}. MAX_EXTRINSIC_DEPTH: {}, input: {:?}", #fn_name_str, e, #c::MAX_EXTRINSIC_DEPTH, #input);
},

and it turns out that the input provided is empty:

main runtime: panicked at 'Bad input data provided to execute_block: Codec error. MAX_EXTRINSIC_DEPTH: 256, input: []'

An empty input for execute_block didn't seem right, I checked the Ok arm on branch polkadot-v0.9.30 but strangely it's also empty there.

main runtime: panicked at 'Good input data provided to execute_block: MAX_EXTRINSIC_DEPTH: 256, input: []'

Kian thinks the empty input is likely a red herring, and that next debugging step should be to check if the input is malformed when it's passed to state_machine_call_with_proof.

[liamaharon]

@kianenigma spotted the issue: a true for signature_check is missing here

substrate/utils/frame/try-runtime/cli/src/commands/follow_chain.rs

Line 151 in 75dee3c

(block, command.state_root_check, command.try_state.clone()).encode().as_ref(),