Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

For all got N < expected M sequence number errors, retry only once from runtime #2450

Merged
merged 4 commits into from
Jul 22, 2022

Conversation

romac
Copy link
Member

@romac romac commented Jul 21, 2022

Closes: #2411

Description

TBD


PR author checklist:

  • Added changelog entry, using unclog.
  • Added tests: integration (for Hermes) or unit/mock tests (for modules).
  • Linked to GitHub issue.
  • Updated code comments and documentation (e.g., docs/).

Reviewer checklist:

  • Reviewed Files changed in the GitHub PR explorer.
  • Manually tested (in case integration/unit/mock tests are absent).

@romac
Copy link
Member Author

romac commented Jul 22, 2022

I can confirm this solves the issue seen in #2411. By following the instructions in the issue, we indeed see Hermes retry to send the packet after the account sequence mismatch error:

Command logs

❯ hermes tx ft-transfer --dst-chain ibc-0 --src-chain ibc-1 --src-port transfer --src-channel channel-0 --amount 20 --timeout-height-offset 5
    Finished dev [unoptimized + debuginfo] target(s) in 0.42s
     Running `target/debug/hermes tx ft-transfer --dst-chain ibc-0 --src-chain ibc-1 --src-port transfer --src-channel channel-0 --amount 20 --timeout-height-offset 5`
2022-07-22T10:59:40.289656Z  INFO ThreadId(01) using default configuration from '/Users/coromac/.hermes/config.toml'
2022-07-22T10:59:40.293139Z DEBUG ThreadId(01) Message: TransferOptions { packet_src_port_id: PortId("transfer"), packet_src_channel_id: ChannelId("channel-0"), amount: Amount(20), denom: "samoleans", receiver: None, timeout_height_offset: 5, timeout_duration: 0ns, number_msgs: 1 }
2022-07-22T10:59:40.412494Z DEBUG ThreadId(01) connection hop underlying the channel: ConnectionEnd { state: Open, client_id: ClientId("07-tendermint-0"), counterparty: Counterparty { client_id: ClientId("07-tendermint-0"), connection_id: Some(ConnectionId("connection-0")), prefix: ibc }, versions: [Version { identifier: "1", features: ["ORDER_ORDERED", "ORDER_UNORDERED"] }], delay_period: 0ns }
2022-07-22T10:59:43.200205Z DEBUG ThreadId(01) client state underlying the channel: Tendermint(ClientState { chain_id: ChainId { id: "ibc-0", version: 0 }, trust_level: TrustThreshold { numerator: 1, denominator: 3 }, trusting_period: 1209600s, unbonding_period: 1814400s, max_clock_drift: 40s, latest_height: Height { revision: 0, height: 405 }, proof_specs: ProofSpecs([ProofSpec(ProofSpec { leaf_spec: Some(LeafOp { hash: Sha256, prehash_key: NoHash, prehash_value: Sha256, length: VarProto, prefix: [0] }), inner_spec: Some(InnerSpec { child_order: [0, 1], child_size: 33, min_prefix_length: 4, max_prefix_length: 12, empty_child: [], hash: Sha256 }), max_depth: 0, min_depth: 0 }), ProofSpec(ProofSpec { leaf_spec: Some(LeafOp { hash: Sha256, prehash_key: NoHash, prehash_value: Sha256, length: VarProto, prefix: [0] }), inner_spec: Some(InnerSpec { child_order: [0, 1], child_size: 32, min_prefix_length: 1, max_prefix_length: 1, empty_child: [], hash: Sha256 }), max_depth: 0, min_depth: 0 })]), upgrade_path: ["upgrade", "upgradedIBCState"], allow_update: AllowUpdate { after_expiry: true, after_misbehaviour: true }, frozen_height: None })
2022-07-22T10:59:43.214224Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: max fee, for use in tx simulation: Fee { amount: "100001stake", gas_limit: 10000000 }
2022-07-22T10:59:43.219981Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}:estimate_gas: tx simulation successful, gas amount used: 89375
2022-07-22T10:59:43.220537Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: send_tx: using 89375 gas, fee Fee { amount: "984stake", gas_limit: 98312 } id=ibc-1
2022-07-22T10:59:43.224134Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: broadcast_tx_sync: Response { code: Ok, data: Data([]), log: Log("[]"), hash: transaction::Hash(84D18412FD8F3A0B57AB402204A0841240AB1741ADDFED14B61F4DE3BAC76C43) }
2022-07-22T10:59:43.224547Z  INFO ThreadId(15) send_tx_commit{id=ft-transfer}: wait_for_block_commits: waiting for commit of tx hashes(s) 84D18412FD8F3A0B57AB402204A0841240AB1741ADDFED14B61F4DE3BAC76C43 id=ibc-1
2022-07-22T10:59:48.330627Z TRACE ThreadId(15) send_tx_commit{id=ft-transfer}: wait_for_block_commits: retrieved 1 tx results after 5106ms id=ibc-1
Success: [
    SendPacket(
        SendPacket - h:1-411, seq:11, path:channel-0/transfer->channel-0/transfer, toh:0-415, tos:Timestamp(NoTimestamp)),
    ),
]

❯ hermes tx ft-transfer --dst-chain ibc-0 --src-chain ibc-1 --src-port transfer --src-channel channel-0 --amount 20 --timeout-height-offset 5
    Finished dev [unoptimized + debuginfo] target(s) in 0.40s
     Running `target/debug/hermes tx ft-transfer --dst-chain ibc-0 --src-chain ibc-1 --src-port transfer --src-channel channel-0 --amount 20 --timeout-height-offset 5`
2022-07-22T10:59:49.608229Z  INFO ThreadId(01) using default configuration from '/Users/coromac/.hermes/config.toml'
2022-07-22T10:59:49.611610Z DEBUG ThreadId(01) Message: TransferOptions { packet_src_port_id: PortId("transfer"), packet_src_channel_id: ChannelId("channel-0"), amount: Amount(20), denom: "samoleans", receiver: None, timeout_height_offset: 5, timeout_duration: 0ns, number_msgs: 1 }
2022-07-22T10:59:49.713144Z DEBUG ThreadId(01) connection hop underlying the channel: ConnectionEnd { state: Open, client_id: ClientId("07-tendermint-0"), counterparty: Counterparty { client_id: ClientId("07-tendermint-0"), connection_id: Some(ConnectionId("connection-0")), prefix: ibc }, versions: [Version { identifier: "1", features: ["ORDER_ORDERED", "ORDER_UNORDERED"] }], delay_period: 0ns }
2022-07-22T10:59:52.278459Z DEBUG ThreadId(01) client state underlying the channel: Tendermint(ClientState { chain_id: ChainId { id: "ibc-0", version: 0 }, trust_level: TrustThreshold { numerator: 1, denominator: 3 }, trusting_period: 1209600s, unbonding_period: 1814400s, max_clock_drift: 40s, latest_height: Height { revision: 0, height: 405 }, proof_specs: ProofSpecs([ProofSpec(ProofSpec { leaf_spec: Some(LeafOp { hash: Sha256, prehash_key: NoHash, prehash_value: Sha256, length: VarProto, prefix: [0] }), inner_spec: Some(InnerSpec { child_order: [0, 1], child_size: 33, min_prefix_length: 4, max_prefix_length: 12, empty_child: [], hash: Sha256 }), max_depth: 0, min_depth: 0 }), ProofSpec(ProofSpec { leaf_spec: Some(LeafOp { hash: Sha256, prehash_key: NoHash, prehash_value: Sha256, length: VarProto, prefix: [0] }), inner_spec: Some(InnerSpec { child_order: [0, 1], child_size: 32, min_prefix_length: 1, max_prefix_length: 1, empty_child: [], hash: Sha256 }), max_depth: 0, min_depth: 0 })]), upgrade_path: ["upgrade", "upgradedIBCState"], allow_update: AllowUpdate { after_expiry: true, after_misbehaviour: true }, frozen_height: None })
2022-07-22T10:59:52.292212Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: max fee, for use in tx simulation: Fee { amount: "100001stake", gas_limit: 10000000 }
2022-07-22T10:59:52.298449Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}:estimate_gas: tx simulation successful, gas amount used: 89381
2022-07-22T10:59:52.299039Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: send_tx: using 89381 gas, fee Fee { amount: "984stake", gas_limit: 98319 } id=ibc-1
2022-07-22T10:59:52.302573Z DEBUG ThreadId(15) send_tx_commit{id=ft-transfer}:send_tx_with_account_sequence_retry{id=ibc-1}: broadcast_tx_sync: Response { code: Ok, data: Data([]), log: Log("[]"), hash: transaction::Hash(882F501363949326154641F0F4EF2465BECCA3E1EC6ADD170C07E2CAB935A38C) }
2022-07-22T10:59:52.302992Z  INFO ThreadId(15) send_tx_commit{id=ft-transfer}: wait_for_block_commits: waiting for commit of tx hashes(s) 882F501363949326154641F0F4EF2465BECCA3E1EC6ADD170C07E2CAB935A38C id=ibc-1
2022-07-22T10:59:53.484254Z TRACE ThreadId(15) send_tx_commit{id=ft-transfer}: wait_for_block_commits: retrieved 1 tx results after 1181ms id=ibc-1
Success: [
    SendPacket(
        SendPacket - h:1-412, seq:12, path:channel-0/transfer->channel-0/transfer, toh:0-417, tos:Timestamp(NoTimestamp)),
    ),
]

Excerpt from Hermes logs

2022-07-22T11:00:02.130813Z DEBUG ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}: max fee, for use in tx simulation: Fee { amount: "100001stake", gas_limit: 10000000 }

2022-07-22T11:00:02.239664Z ERROR ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}:estimate_gas: failed to simulate tx. propagating error to caller: gRPC call failed with status: status: Unknown, message: "account sequence mismatch, expected 26, got 24: incorrect account sequence", details: [], metadata: MetadataMap { headers: {"content-type": "application/grpc", "x-cosmos-block-height": "413"} }
2022-07-22T11:00:02.240019Z  WARN ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}: failed at estimate_gas step mismatching account sequence
   0: gRPC call failed with status: status: Unknown, message: "account sequence mismatch, expected 26, got 24: incorrect account sequence", details: [], metadata: MetadataMap { headers: {"content-type": "application/grpc", "x-cosmos-block-height": "413"} }

2022-07-22T11:00:02.261210Z  INFO ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}: refresh: retrieved account sequence=26 number=7
2022-07-22T11:00:02.562719Z DEBUG ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}: max fee, for use in tx simulation: Fee { amount: "100001stake", gas_limit: 10000000 }
2022-07-22T11:00:02.568746Z DEBUG ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}:estimate_gas: tx simulation successful, gas amount used: 129643
2022-07-22T11:00:02.569056Z DEBUG ThreadId(34) send_tx_check{id=1f310ed8}:send_tx_with_account_sequence_retry{id=ibc-1}: send_tx: using 129643 gas, fee Fee { amount: "1427stake", gas_limit: 142607 } id=ibc-1
2022-07-22T11:00:02.573673Z  INFO ThreadId(37) packet_cmd{src_chain=ibc-0 src_port=transfer src_channel=channel-0 dst_chain=ibc-1}:relay{odata=1f310ed8 ->Destination @0-413; len=1}: [Async~>ibc-1] response(s): 1; Ok:DD1231C8AE29EAB0872722DB1A915FE825128C347D6A024BEF49E5216121E75D

2022-07-22T11:00:02.573728Z  INFO ThreadId(37) packet_cmd{src_chain=ibc-0 src_port=transfer src_channel=channel-0 dst_chain=ibc-1}:relay{odata=1f310ed8 ->Destination @0-413; len=1}: success

@romac romac marked this pull request as ready for review July 22, 2022 10:54
@romac romac merged commit 9cd56b9 into master Jul 22, 2022
@romac romac deleted the anca/2411-retry-snerr branch July 22, 2022 15:09
hu55a1n1 pushed a commit to hu55a1n1/hermes that referenced this pull request Sep 13, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Hermes selective retry upon account sequence mismatch
2 participants