2

We have the weird case that extrinsics in general work, but there is a specific extrinsic that stalls the parachain. See https://github.com/integritee-network/parachain/issues/222. This extrinsic sends a UMP-message to the relay chain requesting a slot swap.

Here are the logs with

  • -lparachain::collation-generation=trace
  • -lparachain::approval-distribution=trace
  • -lparachain::collator-protocol=trace
  • -lbasic-authorship=trace -ltxpool=trace

https://gist.github.com/clangenb/134b993a11e14f24f54893e08c86d959

Even more interesting, from these logs we can see that the collation was successful, and that that the collator's relay chain accepted it:

 cumulus-collator: [Parachain] Starting collation. relay_parent=0xf0bf2bf83f8216548ca4b5013a240a5786603949e259d9f837f88bba5aca9ddb at=0x026671e6c343fdbb5ab71a1026aa702cfe43d3409434589fbe1ff075ed551ef0
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.595  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🙌 Starting consensus session on top of parent 0x026671e6c343fdbb5ab71a1026aa702cfe43d3409434589fbe1ff075ed551ef0
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.600  INFO tokio-runtime-worker sc_basic_authorship::basic_authorship: [Parachain] 🎁 Prepared block for proposing at 7823 (2 ms) [hash: 0xd933f8be0f9c03a26540f6420db2c740076c6678d9425b4ec150ae495c6fc6ca; parent_hash: 0x0266…1ef0; extrinsics (3): [0xcaec…3897, 0x470b…e13b, 0x1f79…cc15]]
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.606 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Processing assignments from a peer peer_id=12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU num=1
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.606 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Checked assignment source=Peer(PeerId("12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU")) message_subject=MessageSubject(0xbd08cd884606f9765a9d92ee6c2d00a168ea655c0c33db00a17dca33a989a5ae, 7, ValidatorIndex(72)) result=Accepted
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.606 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Reputation change for peer reputation=BenefitMinorFirst("Valid message with new information") peer_id=PeerId("12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU")
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.606 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Sending an assignment to peers block_hash=0xbd08cd884606f9765a9d92ee6c2d00a168ea655c0c33db00a17dca33a989a5ae claimed_candidate_index=7 local=false num_peers=3
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.607  INFO tokio-runtime-worker aura: [Parachain] 🔖 Pre-sealed block for proposal at 7823. Hash now 0x78a4a05bc8da537c1e3d26f21d1c4dae934a551c4d0e870051645b5116847acc, previously 0xd933f8be0f9c03a26540f6420db2c740076c6678d9425b4ec150ae495c6fc6ca.
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.608  INFO tokio-runtime-worker cumulus-collator: [Parachain] PoV size { header: 0.1796875kb, extrinsics: 5.7197265625kb, storage_proof: 9.3466796875kb }
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.608  INFO tokio-runtime-worker substrate: [Parachain] ✨ Imported #7823 (0x78a4…7acc)
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.608  INFO tokio-runtime-worker cumulus-collator: [Parachain] Compressed PoV size: 9.5498046875kb
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.608  INFO tokio-runtime-worker cumulus-collator: [Parachain] Produced proof-of-validity candidate. block_hash=0x78a4a05bc8da537c1e3d26f21d1c4dae934a551c4d0e870051645b5116847acc
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.611 DEBUG tokio-runtime-worker parachain::collation-generation: [Relaychain] candidate is generated candidate_hash=0x936f64b18fbf2ba1ccd2979b75219731c5e7ecbb0e934e8a455c9319d60d322b pov_hash=0x84e1b30af67914e2133f9362055efa0eae2ce3afcf5aee095369099f58b8b2b1 relay_parent=0xf0bf2bf83f8216548ca4b5013a240a5786603949e259d9f837f88bba5aca9ddb para_id=2267 traceID=195974902640512596657898995620943861553
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.611 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Received session info session_index=31556
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.611 DEBUG tokio-runtime-worker parachain::collator-protocol: [Relaychain] Accepted collation, connecting to validators. para_id=2267 relay_parent=0xf0bf…9ddb candidate_hash=0x936f64b18fbf2ba1ccd2979b75219731c5e7ecbb0e934e8a455c9319d60d322b pov_hash=0x84e1b30af67914e2133f9362055efa0eae2ce3afcf5aee095369099f58b8b2b1 core=CoreIndex(41) current_validators=[Public(dea7cae27e5dfb239a7ca5fb0649568b57afc08ed2ec5e538d4a3abb786fbc3c (5H6eLEHx...)), Public(fcf408d2b46082efffea4ddd78d114e021439b47d4a5848e15f6d3e5eca44c2e (5HnNRAfr...)), Public(4c0e2bd29d0d14bf81da32c79492dbc2bd97a594f34c982047b8a2ee4d035865 (5DnRhudq...)), Public(3a56f3c36ae08f7cfdeea6d340aa45ebd6b379f47267ca78837749054dec7b03 (5DPCTuQm...)), Public(e6e40731962e2834867cc4f482308cc34e4579ee1a5e1667c3ec36d96b36a971 (5HHScHPf...))] traceID=195974902640512596657898995620943861553
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.618 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Processing approvals from a peer peer_id=12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU num=1
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.619 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Checked approval peer_id=PeerId("12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU") message_subject=MessageSubject(0xbd08cd884606f9765a9d92ee6c2d00a168ea655c0c33db00a17dca33a989a5ae, 9, ValidatorIndex(147)) result=Accepted
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.619 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Reputation change for peer reputation=BenefitMinorFirst("Valid message with new information") peer_id=PeerId("12D3KooWLPKAJm3UECm9fVbgfw6WkrKUK64JayeruSMDcAHxXBXU")
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.619 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Sending an approval to peers block_hash=0xbd08cd884606f9765a9d92ee6c2d00a168ea655c0c33db00a17dca33a989a5ae candidate_index=9 local=false num_peers=3
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.639 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Processing assignments from a peer peer_id=12D3KooWQxG51uMhJVwSJqULapVorQRbqZ4BzkAJ2VosDQjVDifT num=1
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.639 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Checked assignment source=Peer(PeerId("12D3KooWQxG51uMhJVwSJqULapVorQRbqZ4BzkAJ2VosDQjVDifT")) message_subject=MessageSubject(0xbd08cd884606f9765a9d92ee6c2d00a168ea655c0c33db00a17dca33a989a5ae, 10, ValidatorIndex(178)) result=Accepted
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.639 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] Reputation change for peer reputation=BenefitMinorFirst("Valid message with new information") peer_id=PeerId("12D3KooWQxG51uMhJVwSJqULapVorQRbqZ4BzkAJ2VosDQjVDifT")
Jul 05 14:05:18 lease-swap-02 integritee-collator[72042]: 2023-07-05 14:05:18.639 TRACE tokio-runtime-worker parachain::approval-distribution: [Relaychain] 

The collator runs on polkadot-v0.9.42 The runtime runs on polkadot-v0.9.37: https://github.com/integritee-network/parachain/tree/1.5.35/polkadot-parachains/shell-runtime

It happens with the live Kusama network.

It seems that the UMP part is indeed the problem. If the same dispatchable is executed with non-root origin, the block is successfully produced, and I get a BadOrigin error. So, can the executed xcm operations indeed prevent the relay chain from backing a block?

Edit: After additional investigation, I can confirm that:

  • It works on a rococo-local-dev setup, where the collator's host is running on polkadot-v0.9.37.
  • The collator's substrate version does make a difference. If the host runs on v0.9.42, I get a UMP error that, however, doesn't stall the chain.
  • XCM in general seems to work
  • I made sure that the parachain account on the relay chain has some funds.

Edit: Updated the logs with a more verbose log additionally containing: basic-authorship and txpool.

3
  • But it doesn't seem to be stalling your chain, isn't it ? Jul 5, 2023 at 17:46
  • After speaking with the author it seems that the node works again after clearing the txpool (restarting the node). We might want to set a few more log targets, I would say basic-authorship and txpool then update the linked logs :) Jul 5, 2023 at 18:05
  • Updated the logs with the additional flags. Nothing seems suspicious to me yet.
    – clangenb
    Jul 6, 2023 at 14:03

1 Answer 1

1

It turns out that an update to polkadot-v0.9.42 of the runtime did solve the issue. It is not clear yet why this resolved the issue. However, this included the change to XCM v3.

1

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.