Race in relayer may cause justification optimization failures during session changes

[svyatonik]

[BridgeHubKusama_to_BridgeHubPolkadot_MessageLane_00000000] 2023-07-26 14:39:04 +00 ERROR bridge Error asking for source headers at BridgeHubKusama::ReceivingConfirmationsDelivery: Custom("Failed to optimize Polkadot GRANDPA jutification for header HeaderId(66, 0x14e54ba9afd98b60290d5b92c0748ab80fae6e73867b58af4ecbf8c557014ddc): Error::TooLowCumulativeWeight"). Retrying in 0.401206738

[svyatonik]

A bit chaotic (sorry) steps to reproduce:

1. use cumulus branch sv-bridges-and-new-message-queue everywhere;
2. go through README.md (https://github.com/paritytech/cumulus/blob/sv-bridges-and-new-message-queue/parachains/runtimes/bridge-hubs/README.md);
3. do

./scripts/bridges_kusama_polkadot.sh init-asset-hub-kusama-local
./scripts/bridges_kusama_polkadot.sh init-asset-hub-polkadot-local
./scripts/bridges_kusama_polkadot.sh init-bridge-hub-kusama-local

after starting Polkadot, Kusama and relay 5) then just send some messages using ./scripts/bridges_kusama_polkadot.sh reserve-transfer-assets-from-asset-hub-kusama-local (other direction doesn't work yet). Or you can use the node script to submit many messages at once:

const { ApiPromise, WsProvider } = require('@polkadot/api');
const { Keyring } = require('@polkadot/keyring');

async function main () {
    // Initialise the provider to connect to the local node
    const provider = new WsProvider('ws://127.0.0.1:9910');

    // Create the API and wait until ready
    const api = await ApiPromise.create({ provider });

    // Start generating XCM messages
    const alice = new Keyring({ type: 'sr25519' }).addFromUri('//Alice');
    for (let i = 0; i < 10000; i++) {
        await api.tx.polkadotXcm
            .limitedReserveTransferAssets(
                { "V3": { "parents": 2, "interior": { "X2": [ { "GlobalConsensus": "Polkadot" }, { "Parachain": 1000 } ] } } },
                { "V3": { "parents": 0, "interior": { "X1": { "AccountId32": { "id": [212, 53, 147, 199, 21, 253, 211, 28, 97, 20, 26, 189, 4, 169, 159, 214, 130, 44, 133, 88, 133, 76, 205, 227, 154, 86, 132, 231, 165, 109, 162, 125] } } } } },
                { "V3": [ { "id": { "Concrete": { "parents": 1, "interior": "Here" } }, "fun": { "Fungible": 1000000 } } ] },
                0,
                "Unlimited"
            )
            .signAndSend(alice, { nonce: -1 });
    }
}

main().catch(console.error).finally(() => process.exit());

[svyatonik]

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn my_test() {
        use bp_kusama::*;
        use hex_literal::hex;

        let finalized_target: (Hash, BlockNumber) = Decode::decode(&mut &hex!("163406cb8f3613599a899a71f2c68a322b55489ee0dce4d18cfa249495d05e4c42000000")[..]).unwrap();
        let authorities_set_id = 1;
        let authorities_set: Vec<(AuthorityId, u64)> = Decode::decode(&mut &hex!("0c31eb7ea49d20a0c204e3dce2266c9921d7142894f5e00dfbb3ae12bec2ca5399010000000000000069fe9e19cd695dea4645da747b484c4d5de0a932c3e26b7ee773b61b70380763010000000000000080a096b5a2a905ce8f229915509195a0d049143ca3f79556f5cddcbcec8d03ad0100000000000000")[..]).unwrap();
        let mut justification: GrandpaJustification<Header> = Decode::decode(&mut &hex!("0800000000000000163406cb8f3613599a899a71f2c68a322b55489ee0dce4d18cfa249495d05e4c420000000c163406cb8f3613599a899a71f2c68a322b55489ee0dce4d18cfa249495d05e4c420000006849e0ed591859efaa2fd0657a5dd4ff41f6c278a6fcde0f3ca32004a8afc430db6f8508651e3caf57932781359c53de1234b83e0f2b2c3b3f53f20b1038e30131eb7ea49d20a0c204e3dce2266c9921d7142894f5e00dfbb3ae12bec2ca5399163406cb8f3613599a899a71f2c68a322b55489ee0dce4d18cfa249495d05e4c420000004a888c7efe14863358678a0fb03389b01bc491edb8ef55b8673df1514c065b9d0a19ccb0eb57518fba46a1f80bb6aa8e332e681ac4c63a4292f4520910ae1d0969fe9e19cd695dea4645da747b484c4d5de0a932c3e26b7ee773b61b70380763163406cb8f3613599a899a71f2c68a322b55489ee0dce4d18cfa249495d05e4c42000000f8609051276468199edea522b9f33d78dd48edad1832592d525dbb5d981e0d3873c4a9f4757d82008a21550cfced7c6a1763d59835b7bfd0166bd7019df0aa0780a096b5a2a905ce8f229915509195a0d049143ca3f79556f5cddcbcec8d03ad00")[..]).unwrap();

        println!("{:?}", finalized_target);
        println!("{:?}", authorities_set);
        println!("{:?}", justification);

        verify_and_optimize_justification(
            finalized_target,
            authorities_set_id,
            &VoterSet::new(authorities_set).unwrap(),
            &mut justification,
        ).unwrap()
    }
}

[svyatonik]

So I think the reason is: https://github.com/paritytech/parity-bridges-common/blob/master/relays/lib-substrate-relay/src/finality/engine.rs#L178 So it isn't super important :) @serban300 we may ignore it for now

[serban300]

The link above doesn't work anymore because of the latest changes to the repo. Posting a link to a previous commit:

https://github.com/paritytech/parity-bridges-common/blob/3c7c271d2e9112ef0da372b59252cb7fbfb4994a/relays/lib-substrate-relay/src/finality/engine.rs#L178

[serban300]

Looks like this is desired behavior. Resolving the issue for the moment.