Fixed account seq. nr logic in the error case (informalsystems#1406)

* Quick fix tentative for informalsystems#1402.

* Better logging

* Added additional context in log

* Single-line error msg is better for loggers

* Fix for informalsystems#1404

* Consistent logging approach

* Apply suggestions from code review

Co-authored-by: Shoaib Ahmed <sufialhussaini@gmail.com>

* Standardized error code for out of gas

* Add .changelog entry

* Reverted log-level for clear packets logs

Co-authored-by: Shoaib Ahmed <sufialhussaini@gmail.com>
Co-authored-by: Romain Ruetschi <romain@informal.systems>

.changelog/unreleased/bug-fixes/ibc-relayer/1402-fix-account-seq-error-case.md

@@ -0,0 +1,3 @@
+- Only increase cached account sequence number when `broadcast_tx_sync` fails,
+  therefore ensuring that the cached sequence number stays in sync with the
+  node. ([#1402](https://github.com/informalsystems/ibc-rs/issues/1402))

relayer/src/chain/cosmos.rs

@@ -71,14 +71,17 @@ use ibc_proto::ibc::core::connection::v1::{
     QueryClientConnectionsRequest, QueryConnectionsRequest,
 };
 
-use crate::config::{AddressType, ChainConfig, GasPrice};
 use crate::error::Error;
 use crate::event::monitor::{EventMonitor, EventReceiver};
 use crate::keyring::{KeyEntry, KeyRing, Store};
 use crate::light_client::tendermint::LightClient as TmLightClient;
 use crate::light_client::LightClient;
 use crate::light_client::Verified;
 use crate::{chain::QueryResponse, event::monitor::TxMonitorCmd};
+use crate::{
+    config::{AddressType, ChainConfig, GasPrice},
+    sdk_error::sdk_error_from_tx_sync_error_code,
+};
 
 use super::{ChainEndpoint, HealthCheck};
 
@@ -295,9 +298,23 @@ impl CosmosSdkChain {
 
         let response = self.block_on(broadcast_tx_sync(self, tx_bytes))?;
 
-        debug!("[{}] send_tx: broadcast_tx_sync: {:?}", self.id(), response);
-
-        self.incr_account_sequence()?;
+        match response.code {
+            tendermint::abci::Code::Ok => {
+                // A success means the account s.n. was increased
+                self.incr_account_sequence()?;
+                debug!("[{}] send_tx: broadcast_tx_sync: {:?}", self.id(), response);
+            }
+            tendermint::abci::Code::Err(code) => {
+                // Avoid increasing the account s.n. if CheckTx failed
+                // Log the error
+                error!(
+                    "[{}] send_tx: broadcast_tx_sync: {:?}: diagnostic: {:?}",
+                    self.id(),
+                    response,
+                    sdk_error_from_tx_sync_error_code(code)
+                );
+            }
+        }
 
         Ok(response)
     }

relayer/src/connection.rs

@@ -1122,6 +1122,7 @@ fn check_destination_connection_state(
             == expected_connection.counterparty().connection_id();
 
     // TODO check versions and store prefix
+    // https://github.com/informalsystems/ibc-rs/issues/1389
 
     if good_state && good_client_ids && good_connection_ids {
         Ok(())

relayer/src/link/relay_path.rs

@@ -864,25 +864,32 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> RelayPath<ChainA, ChainB> {
             .query_txs(query)
             .map_err(LinkError::relayer)?;
 
-        let mut packet_sequences = vec![];
-        for event in events_result.iter() {
-            match event {
-                IbcEvent::SendPacket(send_event) => {
-                    packet_sequences.push(send_event.packet.sequence);
-                    if packet_sequences.len() > 10 {
-                        // Enough to print the first 10
-                        break;
+        if events_result.is_empty() {
+            info!(
+                "[{}] found zero unprocessed SendPacket events on source chain, nothing to do",
+                self
+            );
+        } else {
+            let mut packet_sequences = vec![];
+            for event in events_result.iter() {
+                match event {
+                    IbcEvent::SendPacket(send_event) => {
+                        packet_sequences.push(send_event.packet.sequence);
+                        if packet_sequences.len() >= 10 {
+                            // Enough to print the first 10
+                            break;
+                        }
                     }
+                    _ => return Err(LinkError::unexpected_event(event.clone())),
                 }
-                _ => return Err(LinkError::unexpected_event(event.clone())),
             }
+            info!(
+                "[{}] found unprocessed SendPacket events for {:?} (first 10 shown here; total={})",
+                self,
+                packet_sequences,
+                events_result.len()
+            );
         }
-        info!(
-            "[{}] found unprocessed SendPacket events for {:?} (first 10 shown here; total={})",
-            self,
-            packet_sequences,
-            events_result.len()
-        );
 
         Ok((events_result, query_height))
     }
@@ -946,22 +953,29 @@ impl<ChainA: ChainHandle, ChainB: ChainHandle> RelayPath<ChainA, ChainB> {
             }))
             .map_err(|e| LinkError::query(self.src_chain().id(), e))?;
 
-        let mut packet_sequences = vec![];
-        for event in events_result.iter() {
-            match event {
-                IbcEvent::WriteAcknowledgement(write_ack_event) => {
-                    packet_sequences.push(write_ack_event.packet.sequence);
-                    if packet_sequences.len() > 10 {
-                        // Enough to print the first 10
-                        break;
+        if events_result.is_empty() {
+            info!(
+                "[{}] found zero unprocessed WriteAcknowledgement events on source chain, nothing to do",
+                self
+            );
+        } else {
+            let mut packet_sequences = vec![];
+            for event in events_result.iter() {
+                match event {
+                    IbcEvent::WriteAcknowledgement(write_ack_event) => {
+                        packet_sequences.push(write_ack_event.packet.sequence);
+                        if packet_sequences.len() >= 10 {
+                            // Enough to print the first 10
+                            break;
+                        }
+                    }
+                    _ => {
+                        return Err(LinkError::unexpected_event(event.clone()));
                     }
-                }
-                _ => {
-                    return Err(LinkError::unexpected_event(event.clone()));
                 }
             }
+            info!("[{}] found unprocessed WriteAcknowledgement events for {:?} (first 10 shown here; total={})", self, packet_sequences, events_result.len());
         }
-        info!("[{}] found unprocessed WriteAcknowledgement events for {:?} (first 10 shown here; total={})", self, packet_sequences, events_result.len());
 
         Ok((events_result, query_height))
     }

relayer/src/sdk_error.rs

@@ -15,6 +15,10 @@ define_error! {
         UnknownSdk
             { code: u32 }
             |e| { format!("unknown SDK error: {}", e.code) },
+
+        OutOfGas
+            { code: u32 }
+            |_| { "the price configuration for this chain may be too low! please check the `gas_price.price` Hermes config.toml".to_string() },
     }
 }
 
@@ -166,3 +170,17 @@ pub fn sdk_error_from_tx_result(result: &TxResult) -> SdkError {
         }
     }
 }
+
+/// Converts error codes originating from `broadcast_tx_sync` responses
+/// into IBC relayer domain-type errors.
+/// See [`tendermint_rpc::endpoint::broadcast::tx_sync::Response`].
+/// Cf: https://github.com/cosmos/cosmos-sdk/blob/v0.42.10/types/errors/errors.go
+pub fn sdk_error_from_tx_sync_error_code(code: u32) -> SdkError {
+    match code {
+        // The primary reason (we know of) causing broadcast_tx_sync to fail
+        // is due to "out of gas" errors. These are unrecoverable at the moment
+        // on the Hermes side. We'll inform the user to check for misconfig.
+        11 => SdkError::out_of_gas(code),
+        _ => SdkError::unknown_sdk(code),
+    }
+}

relayer/src/supervisor/spawn.rs

@@ -297,8 +297,8 @@ impl<'a, Chain: ChainHandle + 'static> SpawnContext<'a, Chain> {
             ),
             Err(e) => error!(
                 "skipped workers for connection {} on chain {}, reason: {}",
-                chain.id(),
                 connection.connection_id,
+                chain.id(),
                 e
             ),
         }