Make ordered channels more resilient in the face of failing packets

[seanchen1991]

Closes: #3540

Description

---

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/).
• Tagged one reviewer who will be the one responsible for shepherding this PR.

Reviewer checklist:

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

[romac]

The new test is failing with

Error: generic error

Caused by:
    error raised while creating client for chain ibcconsumer: failed when building client state

    Caused by:
        gRPC call `query_staking_params` failed with status: status: Unimplemented, message: "unknown service cosmos.staking.v1beta1.Query", details: [], metadata: MetadataMap { headers: {"content-type": "application/grpc"} }

The ibcconsumer chain probably needs ccv_consumer to be set to true in its config.

[seanchen1991]

The ibcconsumer chain probably needs ccv_consumer to be set to true in its config.

Does this need to be set in the test itself, or in an actual config file?

[romac]

I actually wonder why this test is run at all using a consumer chain?

@ljoss17 Is that expected? Do we run other ICA tests using CCV chains?

[ljoss17]

Does this need to be set in the test itself, or in an actual config file?

There are helper methods to bootstrap configurations for CCV chain tests: https://github.com/informalsystems/hermes/blob/master/tools/test-framework/src/util/interchain_security.rs#L18C13-L18C13
This is an example on how to use them:

• https://github.com/informalsystems/hermes/blob/master/tools/integration-test/src/tests/interchain_security/ica_transfer.rs#L51
• https://github.com/informalsystems/hermes/blob/master/tools/integration-test/src/tests/interchain_security/ica_transfer.rs#L63

@ljoss17 Is that expected? Do we run other ICA tests using CCV chains?

The issue happened when relaying for Stride, so I think it would be nicer to be able to run the test with CCV chains as we already have a job using Stride https://github.com/informalsystems/hermes/blob/master/.github/workflows/integration.yaml#L465. But I don't think it is necessary

[romac]

Great work @seanchen1991! 🙏

[romac]

Thanks @ljoss17 for reminding me of some outstanding issues with that PR:

After looking more into the ordered channel resilience PR, I found a few issues.

• It seems that we enable the packet clearing on start by default with ordered channels, https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/worker.rs#L129. This is a good thing in production but renders the current test ineffective since the clear on start will trigger when the supervisor is spawned for the third packet, thus relaying the second causing the test to pass
• It is still possible to test manually the feature by commenting out the || channel_ordering == Ordering::Ordered here: https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/worker.rs#L129

When testing locally with the modified version, the test doesn’t pass because Hermes doesn’t consider the packet relaying as an Error in this match

hermes/crates/relayer/src/link/relay_path.rs

Line 653 in fdc352b

match self.send_from_operational_data::<S>(&odata) {

This can be seen by the submitted log below.
The cause is the following:

1. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/link/relay_path.rs#L783 call send_from_operation_data
2. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/link/relay_sender.rs#L97 call submit
3. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos.rs#L1048 call send_messages_and_wait_commit
4. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos.rs#L719 call do_send_messages_and_wait_commit
5. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos/batch.rs#L93 call send_batched_messages_and_wait_check_tx
6. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos/retry.rs#L48 call send_tx_with_account_sequence_retry
7. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos/retry.rs#L77 call do_send_tx_with_account_sequence_retry
8. https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/chain/cosmos/retry.rs#L150 return the response as an Ok() so the error isn’t caught by the relay_path match

   hermes/crates/relayer/src/link/relay_path.rs

   Line 653 in fdc352b

   match self.send_from_operational_data::<S>(&odata) {

2023-11-15T12:44:49.184516Z INFO spawn:chain{chain=ibcconsumer}:client{client=07-tendermint-2}:connection{connection=connection-1}:channel{channel=channel-2}:worker.packet.cmd{src_chain=ibcconsumer src_port=icacontroller-stride1798cf2q3gmw5gkyv0u6wtqfy38fap2darsl0p3 src_channel=channel-2 dst_chain=ibcprovider}:relay{odata=ae8fba35 ->Destination @0-132; len=1}: ibc_relayer::link::relay_path: submitted
2023-11-15T12:44:49.184485Z INFO spawn:chain{chain=ibcconsumer}:client{client=07-tendermint-2}:connection{connection=connection-1}:channel{channel=channel-2}:worker.packet.cmd{src_chain=ibcconsumer src_port=icacontroller-stride1798cf2q3gmw5gkyv0u6wtqfy38fap2darsl0p3 src_channel=channel-2 dst_chain=ibcprovider}:relay{odata=ae8fba35 ->Destination @0-132; len=1}: ibc_relayer::link::relay_sender: response(s): 1; Error with code 21:B139F35FBDBA7EA960F723B9A90510C3FC6D7A6C2F5BDC38E5B165FB570E1AFE target_chain=ibcprovider

From my understanding and a little bit of testing manually, one solution would be to do some code matching around here for a code 21 (out of order packet) here

hermes/crates/relayer/src/chain/cosmos/retry.rs

Line 139 in fdc352b

and return a new error, e.g. OutofOrderPacket.
This could then be caught here https://github.com/informalsystems/hermes/blob/master/crates/relayer/src/link/relay_sender.rs#L98 and return a new error, e.g. OutOfOrderSend. And this new error could be caught here triggering the packet clearing.

This is the diff I used to play around for this suggestion which is now able to trigger the special clearing, but it gets this error:

2023-11-15T13:46:10.063080Z ERROR spawn:chain{chain=ibcconsumer}:client{client=07-tendermint-2}:connection{connection=connection-1}:channel{channel=channel-2}:worker.packet.cmd{src_chain=ibcconsumer src_port=icacontroller-stride1hleh224w70xp8kmnjaywdfshhy2ek42r283592 src_channel=channel-2 dst_chain=ibcprovider}:relay{odata=5c460800 ->Destination @0-131; len=1}: ibc_relayer::link::relay_path: 5/5 retries exhausted. Giving up

Show diff

diff --git a/crates/relayer/src/chain/cosmos/retry.rs b/crates/relayer/src/chain/cosmos/retry.rs
index 4d0091fc9..5e995b13e 100644
--- a/crates/relayer/src/chain/cosmos/retry.rs
+++ b/crates/relayer/src/chain/cosmos/retry.rs
@@ -137,6 +137,13 @@ async fn do_send_tx_with_account_sequence_retry(
                     Ok(response)
                 }
 
+                Code::Err(code) if code.get() == 21u32 => {
+                    warn!("packet out of order errror");
+
+                    Err(Error::non_provable_data())
+
+                },
+
                 // Gas estimation succeeded, but broadcast_tx_sync failed with unrecoverable error.
                 Code::Err(code) => {
                     // Do not increase the account s.n. since CheckTx step of broadcast_tx_sync has failed.
diff --git a/crates/relayer/src/link/error.rs b/crates/relayer/src/link/error.rs
index adf8142ec..3ac278a5e 100644
--- a/crates/relayer/src/link/error.rs
+++ b/crates/relayer/src/link/error.rs
@@ -76,6 +76,9 @@ define_error! {
                 format!("chain error when sending messages: {0}", e.event)
             },
 
+        OutOfOrderSend
+            |_| { "tried to send a packet out of order" },
+
         MissingChannelId
             { chain_id: ChainId }
             |e| {
diff --git a/crates/relayer/src/link/relay_path.rs b/crates/relayer/src/link/relay_path.rs
index a821eb8cb..8cf904111 100644
--- a/crates/relayer/src/link/relay_path.rs
+++ b/crates/relayer/src/link/relay_path.rs
@@ -671,17 +671,18 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> RelayPath<ChainA, ChainB> {
 
                     return Ok(reply);
                 }
-                Err(LinkError(error::LinkErrorDetail::Send(e), _)) => {
-                    warn!(
+                Err(LinkError(error::LinkErrorDetail::Send(_), _)) | Err(LinkError(error::LinkErrorDetail::OutOfOrderSend(_), _)) => {
+                    /*warn!(
                         "Determining whether we need to retry in response to: {}",
                         e.event
-                    );
+                    );*/
 
                     // if on an ordered channel, perform a packet clearing, but only if we
                     // are not in the middle of another packet clearing process
                     if self.ordered_channel() && i == 0 && !odata.tracking_id.is_clearing() {
                         // Do we need to specify the height for the packet clearing?
                         // Probably not, since no progress will have been made on the clearing process
+                        tracing::warn!("special clear");
                         self.relay_pending_packets(None)?;
                     }
 
@@ -698,6 +699,7 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> RelayPath<ChainA, ChainB> {
                     }
                 }
                 Err(e) => {
+                    tracing::warn!("other link error: {e}");
                     // Unrecoverable error, propagate up the stack
                     return Err(e);
                 }
diff --git a/crates/relayer/src/link/relay_sender.rs b/crates/relayer/src/link/relay_sender.rs
index c4d29fe91..48fbbe5d0 100644
--- a/crates/relayer/src/link/relay_sender.rs
+++ b/crates/relayer/src/link/relay_sender.rs
@@ -7,6 +7,7 @@ use ibc_relayer_types::events::IbcEvent;
 
 use crate::chain::handle::ChainHandle;
 use crate::chain::tracking::TrackedMsgs;
+use crate::error::Error;
 use crate::link::error::LinkError;
 use crate::link::RelaySummary;
 use crate::util::pretty::{PrettyCode, PrettyEvents};
@@ -95,9 +96,14 @@ impl Submit for AsyncSender {
     type Reply = AsyncReply;
 
     fn submit(target: &impl ChainHandle, msgs: TrackedMsgs) -> Result<Self::Reply, LinkError> {
-        let a = target
-            .send_messages_and_wait_check_tx(msgs)
-            .map_err(LinkError::relayer)?;
+        let a = match target
+            .send_messages_and_wait_check_tx(msgs) {
+                Ok(r) => Ok(r),
+                Err(e) if e.detail().to_string() == Error::non_provable_data().detail().to_string() => {
+                    Err(LinkError::out_of_order_send())
+                },
+                Err(e) => Err(LinkError::relayer(e))
+            }?;
         let reply = AsyncReply { responses: a };
 
         // Note: There may be errors in the reply, for example:
diff --git a/crates/relayer/src/worker.rs b/crates/relayer/src/worker.rs
index 915c49ce6..0c4050a92 100644
--- a/crates/relayer/src/worker.rs
+++ b/crates/relayer/src/worker.rs
@@ -1,6 +1,6 @@
 use alloc::sync::Arc;
 use core::fmt::{Display, Error as FmtError, Formatter};
-use ibc_relayer_types::core::ics04_channel::channel::Ordering;
+//use ibc_relayer_types::core::ics04_channel::channel::Ordering;
 use serde::{Deserialize, Serialize};
 use std::sync::Mutex;
 use tracing::error;
@@ -124,9 +124,9 @@ pub fn spawn_worker_tasks<ChainA: ChainHandle, ChainB: ChainHandle>(
 
             match link_res {
                 Ok(link) => {
-                    let channel_ordering = link.a_to_b.channel().ordering;
+                    let _channel_ordering = link.a_to_b.channel().ordering;
                     let should_clear_on_start =
-                        packets_config.clear_on_start || channel_ordering == Ordering::Ordered;
+                        packets_config.clear_on_start;// || channel_ordering == Ordering::Ordered;
 
                     let (cmd_tx, cmd_rx) = crossbeam_channel::unbounded();
                     let link = Arc::new(Mutex::new(link));
diff --git a/tools/integration-test/src/tests/interchain_security/ica_ordered_channel.rs b/tools/integration-test/src/tests/interchain_security/ica_ordered_channel.rs
index 42dd0877d..05b61175c 100644
--- a/tools/integration-test/src/tests/interchain_security/ica_ordered_channel.rs
+++ b/tools/integration-test/src/tests/interchain_security/ica_ordered_channel.rs
@@ -66,6 +66,8 @@ impl TestOverrides for IcaOrderedChannelTest {
         config.mode.packets.clear_on_start = false;
         config.mode.packets.clear_interval = 0;
 
+        config.mode.clients.misbehaviour = false;
+
         update_relayer_config_for_consumer_chain(config);
     }
 

[ancazamfir]

imo, we should not check on error but rather when we attempt to clear a packet on an IBC event.
Here are some tentative diffs:

index 2eb85f633..4d4471143 100644
--- a/crates/relayer/src/worker/packet.rs
+++ b/crates/relayer/src/worker/packet.rs
@@ -17,12 +17,14 @@ use ibc_proto::ibc::apps::fee::v1::{IdentifiedPacketFees, QueryIncentivizedPacke
 use ibc_proto::ibc::core::channel::v1::PacketId;
 use ibc_relayer_types::applications::ics29_fee::events::IncentivizedPacket;
 use ibc_relayer_types::applications::transfer::{Amount, Coin, RawCoin};
+use ibc_relayer_types::core::ics04_channel::channel::Ordering;
 use ibc_relayer_types::core::ics04_channel::events::WriteAcknowledgement;
 use ibc_relayer_types::core::ics04_channel::packet::Sequence;
 use ibc_relayer_types::events::{IbcEvent, IbcEventType};
 use ibc_relayer_types::Height;

 use crate::chain::handle::ChainHandle;
+use crate::chain::requests::{IncludeProof, QueryHeight, QueryNextSequenceReceiveRequest};
 use crate::config::filter::FeePolicy;
 use crate::event::source::EventBatch;
 use crate::foreign_client::HasExpiredOrFrozenError;
@@ -186,7 +188,7 @@ pub fn spawn_incentivized_packet_cmd_worker<ChainA: ChainHandle, ChainB: ChainHa
 /// Receives worker commands and handles them accordingly.
 ///
 /// Given an `IbcEvent` command, updates the schedule and initiates
-/// packet clearing if the `should_clear_on_start` flag has been toggled.
+/// packet clearing if the `should_clear_on_start` flag has been set or dependent packets must be cleared on ordred channels.
 ///
 /// Given a `NewBlock` command, checks if packet clearing should occur
 /// and performs it if so.
@@ -205,7 +207,19 @@ fn handle_packet_cmd<ChainA: ChainHandle, ChainB: ChainHandle>(
     // Handle packet clearing which is triggered from a command
     let (do_clear, maybe_height) = match &cmd {
         WorkerCmd::IbcEvents { batch } => {
-            if *should_clear_on_start {
+            let channel_ordering = link.a_to_b.channel().ordering;
+            let (_next_seq, _) = link.a_to_b.dst_chain().query_next_sequence_receive(
+                    QueryNextSequenceReceiveRequest {
+                        port_id: link.a_to_b.dst_port_id().clone(),
+                        channel_id: link.a_to_b.dst_channel_id().clone(),
+                        height: QueryHeight::Specific(batch.height),
+                    },
+                    IncludeProof::No,
+                )
+                .map_err(|e| LinkError::query(link.a_to_b.dst_chain().id(), e))?;
+            // TODO - if _next_seq is smaller than the sequence of the first packet in batch, then we should clear
+            let ordered_clear_required = channel_ordering == Ordering::Ordered;
+            if *should_clear_on_start || ordered_clear_required {
                 (true, Some(batch.height))
             } else {
                 (false, None)

[calvinaco]

Hi @seanchen1991 @romac @ancazamfir

Thanks for the great work @seanchen1991 !

I noticed this PR seems to be inactive for a while. We are now working on adding ICA support in next Cronos upgrade and making ORDERED channel more resilient in hermes is important to us.

May I ask what is the latest status of this PR? Thank you!

[romac]

@calvinaco Thanks for your interest in this PR! The PR is not quite ready yet and we haven't had time to get back to work more on it yet. We will report back when that's the case, hopefully by the end of next week.

[ljoss17]

This looks good to me, left two comments. Thanks for finalising this @romac !!

[ljoss17]

I think we can remove most of the sleeps in the test

[ljoss17]

I think we should move this in the supervisor block to insure that the clearing is done, and maybe add an assertion that the amount is correctly received

Suggested solution was adopted