Skip to content
This repository has been archived by the owner on Mar 20, 2024. It is now read-only.

message_race_loop still update required header to latest even if no new nonces on source_finalized_updated. #344

Closed
hackfisher opened this issue Dec 7, 2021 · 2 comments
Closed

message_race_loop still update required header to latest even if no new nonces on source_finalized_updated. #344

hackfisher opened this issue Dec 7, 2021 · 2 comments
Labels
A0-pleasereview Pull request needs code review.

Comments

@hackfisher
Copy link
Contributor 

[2021-12-06T23:53:35Z TRACE finality_relay::finality_loop] Considering range of headers (8186014; 8186010]
[2021-12-06T23:53:35Z TRACE finality_relay::finality_loop] Can not improve selected Crab finality proof None. No unjustified headers and recent proofs
[2021-12-06T23:53:35Z DEBUG messages_relay::message_lane_loop] Received state from Crab node: ClientState { best_self: HeaderId(8186018, 0x7315a7e75dce411c14b8d5e3f128ac0da1630496507111dfbf2a259aae8bf713), best_finalized_self: HeaderId(8186015, 0x4727ea887eef10242d2701b1483ffe8d98a41e2e1530f13fc6183dd1fee58804), best_finalized_peer_at_best_self: HeaderId(6225408, 0xea1db9acef190c683e953e79186d20d5e72a725701c5d1bd5f15f0aedbb4f75b) }
[2021-12-06T23:53:35Z DEBUG messages_relay::message_race_loop] Asking Crab::MessagesDelivery about best message nonces
[2021-12-06T23:53:36Z DEBUG messages_relay::message_race_loop] Received best nonces from Crab::MessagesDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 0, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 0, messages_in_oldest_entry: 0, total_messages: 0 } } }
[2021-12-06T23:53:36Z DEBUG messages_relay::message_lane_loop] Received state from Darwinia node: ClientState { best_self: HeaderId(6225497, 0x796599eb75b0ee0acffb3317dcfa89d0b7efe48cf74789e27c8966cff0fb647b), best_finalized_self: HeaderId(6225494, 0x7e59188248f05ca9e505ef07f38ca0403ccf3821b4ce6869e337ba0917a755e8), best_finalized_peer_at_best_self: HeaderId(8186014, 0xe4568141c79fbc2deb8577dd931649abcfcf0f439da657738f00b9ca0f44e11f) }
[2021-12-06T23:53:36Z DEBUG messages_relay::message_race_loop] Asking Darwinia::MessagesDelivery about message nonces
[2021-12-06T23:53:36Z DEBUG messages_relay::message_race_loop] Asking Darwinia::ReceivingConfirmationsDelivery about best message nonces
[2021-12-06T23:53:37Z DEBUG messages_relay::message_race_loop] Received best nonces from Darwinia::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: () }
[2021-12-06T23:53:37Z DEBUG messages_relay::message_race_loop] Asking Darwinia::ReceivingConfirmationsDelivery about finalized message nonces
[2021-12-06T23:53:37Z DEBUG messages_relay::message_race_loop] Received nonces from Darwinia::MessagesDelivery: SourceClientNonces { new_nonces: {}, confirmed_nonce: Some(0) }
[2021-12-06T23:53:37Z DEBUG messages_relay::message_race_loop] Received finalized nonces from Darwinia::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: () }
[2021-12-06T23:53:37Z TRACE relay_utils::metrics::global] Refreshed process metrics: CPU=1.656516432762146, memory=174985216
[2021-12-06T23:53:37Z TRACE relay_utils::metrics::global] Refreshed process metrics: CPU=1.657323956489563, memory=174985216
[2021-12-06T23:53:37Z DEBUG messages_relay::message_lane_loop] Asking Darwinia node about its state
[2021-12-06T23:53:38Z DEBUG messages_relay::message_lane_loop] Asking Crab node about its state
[2021-12-06T23:53:38Z DEBUG messages_relay::message_lane_loop] Received state from Crab node: ClientState { best_self: HeaderId(8186019, 0x628fb65a6d258d01edead9b4e75121fb01ff7af40ebf8a2259f47e3a58551860), best_finalized_self: HeaderId(8186016, 0x067aedc60b0832636def51959f9f08b8e33e411346c53726fa1b457d26cf3b10), best_finalized_peer_at_best_self: HeaderId(6225408, 0xea1db9acef190c683e953e79186d20d5e72a725701c5d1bd5f15f0aedbb4f75b) }
[2021-12-06T23:53:38Z DEBUG messages_relay::message_race_loop] Asking Crab::MessagesDelivery about message nonces
[2021-12-06T23:53:38Z INFO  messages_relay::message_race_loop] Synced Some(3) of Some(3) nonces in Darwinia::ReceivingConfirmationsDelivery -> Crab::ReceivingConfirmationsDelivery race
[2021-12-06T23:53:38Z DEBUG messages_relay::message_race_loop] Asking Crab::ReceivingConfirmationsDelivery about best message nonces
[2021-12-06T23:53:38Z DEBUG messages_relay::message_race_loop] Received best nonces from Crab::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 3, nonces_data: () }
[2021-12-06T23:53:38Z DEBUG messages_relay::message_race_loop] Asking Crab::ReceivingConfirmationsDelivery about finalized message nonces
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Received nonces from Crab::MessagesDelivery: SourceClientNonces { new_nonces: {}, confirmed_nonce: Some(3) }
[2021-12-06T23:53:39Z TRACE substrate_relay_helper::on_demand_headers] More Crab headers required in on-demand-Crab-to-Darwinia relay. Going to sync up to the 8186016
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Received finalized nonces from Crab::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 3, nonces_data: () }
[2021-12-06T23:53:39Z WARN  relay_utils::metrics] Failed to update metric 'Some("Crab_to_Darwinia_MessageLane_00000000_Crab_Darwinia_to_Crab_conversion_rate")': ()
[2021-12-06T23:53:39Z DEBUG messages_relay::message_lane_loop] Received state from Darwinia node: ClientState { best_self: HeaderId(6225497, 0xb9572a7594613a1be0f36ea81e078622eab6c0d487b9e021a9e16ae4cc159d4f), best_finalized_self: HeaderId(6225494, 0x7e59188248f05ca9e505ef07f38ca0403ccf3821b4ce6869e337ba0917a755e8), best_finalized_peer_at_best_self: HeaderId(8186014, 0xe4568141c79fbc2deb8577dd931649abcfcf0f439da657738f00b9ca0f44e11f) }
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Asking Darwinia::MessagesDelivery about best message nonces
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Asking Darwinia::ReceivingConfirmationsDelivery about message nonces
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Received nonces from Darwinia::ReceivingConfirmationsDelivery: SourceClientNonces { new_nonces: 4..=3, confirmed_nonce: None }
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Received best nonces from Darwinia::MessagesDelivery: TargetClientNonces { latest_nonce: 3, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 2, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 1, messages_in_oldest_entry: 1, total_messages: 1 } } }
[2021-12-06T23:53:39Z DEBUG messages_relay::message_race_loop] Asking Darwinia::MessagesDelivery about finalized message nonces
[2021-12-06T23:53:40Z TRACE relay_utils::metrics::global] Refreshed process metrics: CPU=1.7638412714004517, memory=174985216
[2021-12-06T23:53:40Z TRACE relay_utils::metrics::global] Refreshed process metrics: CPU=1.6662582159042358, memory=174985216
[2021-12-06T23:53:40Z DEBUG messages_relay::message_race_loop] Received finalized nonces from Darwinia::MessagesDelivery: TargetClientNonces { latest_nonce: 3, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 2, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 1, messages_in_oldest_entry: 1, total_messages: 1 } } }
[2021-12-06T23:53:40Z DEBUG messages_relay::message_lane_loop] Asking Crab node about its state
[2021-12-06T23:53:41Z DEBUG messages_relay::message_lane_loop] Asking Darwinia node about its state
[2021-12-06T23:53:41Z DEBUG messages_relay::message_lane_loop] Received state from Crab node: ClientState { best_self: HeaderId(8186019, 0x628fb65a6d258d01edead9b4e75121fb01ff7af40ebf8a2259f47e3a58551860), best_finalized_self: HeaderId(8186017, 0x3f3322bb4019c25b490e01bb2f212b31497bb61d90cf57fc1df03dce78f752b7), best_finalized_peer_at_best_self: HeaderId(6225408, 0xea1db9acef190c683e953e79186d20d5e72a725701c5d1bd5f15f0aedbb4f75b) }
[2021-12-06T23:53:41Z INFO  messages_relay::message_race_loop] Synced Some(0) of Some(0) nonces in Darwinia::MessagesDelivery -> Crab::MessagesDelivery race
[2021-12-06T23:53:41Z DEBUG messages_relay::message_race_loop] Asking Crab::MessagesDelivery about best message nonces
[2021-12-06T23:53:41Z INFO  messages_relay::message_race_loop] Synced Some(0) of Some(0) nonces in Crab::ReceivingConfirmationsDelivery -> Darwinia::ReceivingConfirmationsDelivery race
[2021-12-06T23:53:41Z DEBUG messages_relay::message_race_loop] Asking Crab::ReceivingConfirmationsDelivery about message nonces
[2021-12-06T23:53:41Z WARN  relay_utils::metrics] Failed to update metric 'Some("Darwinia_to_Crab_MessageLane_00000000_Darwinia_Crab_to_Darwinia_conversion_rate")': ()
[2021-12-06T23:53:41Z DEBUG messages_relay::message_race_loop] Received nonces from Crab::ReceivingConfirmationsDelivery: SourceClientNonces { new_nonces: 1..=0, confirmed_nonce: None }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Received best nonces from Crab::MessagesDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 0, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 0, messages_in_oldest_entry: 0, total_messages: 0 } } }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Asking Crab::MessagesDelivery about finalized message nonces
[2021-12-06T23:53:42Z DEBUG messages_relay::message_lane_loop] Received state from Darwinia node: ClientState { best_self: HeaderId(6225497, 0xb9572a7594613a1be0f36ea81e078622eab6c0d487b9e021a9e16ae4cc159d4f), best_finalized_self: HeaderId(6225495, 0xee487a12f2cc97df10936d20b79b1be80bf201bfdcea819c01bfabf3633e835f), best_finalized_peer_at_best_self: HeaderId(8186014, 0xe4568141c79fbc2deb8577dd931649abcfcf0f439da657738f00b9ca0f44e11f) }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Asking Darwinia::ReceivingConfirmationsDelivery about best message nonces
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Asking Darwinia::MessagesDelivery about message nonces
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Received best nonces from Darwinia::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: () }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Asking Darwinia::ReceivingConfirmationsDelivery about finalized message nonces
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Received finalized nonces from Darwinia::ReceivingConfirmationsDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: () }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Received nonces from Darwinia::MessagesDelivery: SourceClientNonces { new_nonces: {}, confirmed_nonce: Some(0) }
[2021-12-06T23:53:42Z DEBUG messages_relay::message_race_loop] Received finalized nonces from Crab::MessagesDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 0, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 0, messages_in_oldest_entry: 0, total_messages: 0 } } }
[2021-12-06T23:53:42Z TRACE finality_relay::finality_loop] Considering range of headers (8186014; 8186016]
[2021-12-06T23:53:43Z TRACE finality_relay::finality_loop] Read 3 finality proofs from Darwinia finality stream for headers in range [Some(6225493); Some(6225495)]
[2021-12-06T23:53:43Z TRACE finality_relay::finality_loop] Trying to improve selected Darwinia finality proof None. Headers range: [6225409; 6225434]. Proofs range: [6225435; 6225495].Trying to improve to: 6225435. Result: failed
[2021-12-06T23:53:43Z TRACE finality_relay::finality_loop] Read 2 finality proofs from Crab finality stream for headers in range [Some(8186016); Some(8186017)]
[2021-12-06T23:53:43Z TRACE finality_relay::finality_loop] Trying to improve selected Crab finality proof None. Headers range: [8186015; 8186016]. Proofs range: [8186015; 8186017].Trying to improve to: 8186016. Result: improved
[2021-12-06T23:53:43Z DEBUG finality_relay::finality_loop] Going to submit finality proof of Crab header #8186016 to Darwinia
[2021-12-06T23:53:43Z DEBUG messages_relay::message_lane_loop] Asking Darwinia node about its state
[2021-12-06T23:53:44Z DEBUG messages_relay::message_lane_loop] Asking Crab node about its state
[2021-12-06T23:53:44Z TRACE relay_substrate_client::client] Sent transaction to Darwinia node: 0x2be2424358fecb38372f9cad9db8a11a9728a7429fc121703bf0f28ded4e9145
@hackfisher
Copy link
Contributor Author

hackfisher commented Dec 7, 2021 •
edited
Loading

This can be reproduced when there are >= 2 bridger running, and be triggered to a feedback loop by one of the bridgers start to update finalized source on target(due to mandatory or new message).

This feedback loop result that two bridgers will continuing send finality proof transactions until one of them run out of funds.
Bridger is signaled to drag required_finalized_number to best_finalized, and after finalized source on target successfully, will signal other bridgers to do the same thing.

@hackfisher
Copy link
Contributor Author

hackfisher commented Dec 9, 2021 •
edited
Loading

Fixed in darwinia-network/darwinia-messages-substrate@47262eb

Not merge into master yet, still in paritytech/parity-bridges-common@master...darwinia-network:denny-try-fix

@hackfisher hackfisher reopened this Dec 9, 2021
@hackfisher hackfisher mentioned this issue Dec 10, 2021
Merged
@hackfisher hackfisher added the A0-pleasereview Pull request needs code review. label Dec 13, 2021
@fewensa fewensa mentioned this issue Feb 18, 2022
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
A0-pleasereview Pull request needs code review.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@hackfisher