Merge pull request #6129 from jferrant/bug/post-block-infinite-loop-signers

Signers should not infinitely loop when posting a block to the node

Author: kantai

stacks-signer/src/client/mod.rs

@@ -28,7 +28,7 @@ use libstackerdb::Error as StackerDBError;
 pub use stackerdb::*;
 pub use stacks_client::*;
 use stacks_common::codec::Error as CodecError;
-use stacks_common::debug;
+use stacks_common::{debug, warn};
 
 /// Backoff timer initial interval in milliseconds
 const BACKOFF_INITIAL_INTERVAL: u64 = 128;
@@ -103,7 +103,7 @@ pub enum ClientError {
 pub fn retry_with_exponential_backoff<F, E, T>(request_fn: F) -> Result<T, ClientError>
 where
     F: FnMut() -> Result<T, backoff::Error<E>>,
-    E: std::fmt::Debug,
+    E: std::fmt::Debug + Into<ClientError>,
 {
     let notify = |err, dur| {
         debug!(
@@ -117,7 +117,16 @@ where
         .with_max_elapsed_time(Some(Duration::from_secs(BACKOFF_MAX_ELAPSED)))
         .build();
 
-    backoff::retry_notify(backoff_timer, request_fn, notify).map_err(|_| ClientError::RetryTimeout)
+    backoff::retry_notify(backoff_timer, request_fn, notify).map_err(|e| match e {
+        backoff::Error::Permanent(err) => {
+            warn!("Non-retry error during request: {err:?}");
+            err.into()
+        }
+        backoff::Error::Transient { err, .. } => {
+            warn!("Exceeded max retries during request: {err:?}");
+            err.into()
+        }
+    })
 }
 
 #[cfg(test)]

stacks-signer/src/client/stacks_client.rs

@@ -14,8 +14,6 @@
 // You should have received a copy of the GNU General Public License
 // along with this program.  If not, see <http://www.gnu.org/licenses/>.
 use std::collections::{HashMap, VecDeque};
-use std::fmt::Display;
-use std::time::{Duration, Instant};
 
 use blockstack_lib::chainstate::nakamoto::NakamotoBlock;
 use blockstack_lib::chainstate::stacks::boot::{NakamotoSignerEntry, SIGNERS_NAME};
@@ -602,36 +600,6 @@ impl StacksClient {
         Ok(account_entry)
     }
 
-    /// Post a block to the stacks-node, retry forever on errors.
-    ///
-    /// In tests, this panics if the retry takes longer than 30 seconds.
-    pub fn post_block_until_ok<F: Display>(&self, log_fmt: &F, block: &NakamotoBlock) -> bool {
-        debug!("StacksClient: Posting block to stacks node";
-            "signer_signature_hash" => %block.header.signer_signature_hash(),
-            "block_id" => %block.header.block_id(),
-            "block_height" => %block.header.chain_length,
-        );
-        let start_time = Instant::now();
-        loop {
-            match self.post_block(block) {
-                Ok(block_push_result) => {
-                    debug!("{log_fmt}: Block pushed to stacks node: {block_push_result:?}");
-                    return block_push_result;
-                }
-                Err(e) => {
-                    if cfg!(any(test, feature = "testing"))
-                        && start_time.elapsed() > Duration::from_secs(30)
-                    {
-                        panic!(
-                            "{log_fmt}: Timed out in test while pushing block to stacks node: {e}"
-                        );
-                    }
-                    warn!("{log_fmt}: Failed to push block to stacks node: {e}. Retrying...");
-                }
-            };
-        }
-    }
-
     /// Try to post a completed nakamoto block to our connected stacks-node
     /// Returns `true` if the block was accepted or `false` if the block
     ///   was rejected.
@@ -644,22 +612,30 @@ impl StacksClient {
         let path = format!("{}{}?broadcast=1", self.http_origin, postblock_v3::PATH);
         let timer = crate::monitoring::actions::new_rpc_call_timer(&path, &self.http_origin);
         let send_request = || {
-            self.stacks_node_client
+            let response = self
+                .stacks_node_client
                 .post(&path)
                 .header("Content-Type", "application/octet-stream")
                 .header(AUTHORIZATION, self.auth_password.clone())
                 .body(block.serialize_to_vec())
                 .send()
                 .map_err(|e| {
                     debug!("Failed to submit block to the Stacks node: {e:?}");
-                    backoff::Error::transient(e)
-                })
+                    backoff::Error::transient(ClientError::from(e))
+                })?;
+            if !response.status().is_success() {
+                warn!(
+                    "Failed to post block to stacks-node, will retry until limit reached";
+                    "http_status" => %response.status(),
+                );
+                return Err(backoff::Error::transient(ClientError::RequestFailure(
+                    response.status(),
+                )));
+            }
+            Ok(response)
         };
         let response = retry_with_exponential_backoff(send_request)?;
         timer.stop_and_record();
-        if !response.status().is_success() {
-            return Err(ClientError::RequestFailure(response.status()));
-        }
         let post_block_resp = response.json::<StacksBlockAcceptedData>()?;
         Ok(post_block_resp.accepted)
     }

stacks-signer/src/v0/signer.rs

@@ -455,7 +455,7 @@ impl Signer {
                             if self.test_skip_block_broadcast(b) {
                                 return;
                             }
-                            stacks_client.post_block_until_ok(self, b);
+                            self.handle_post_block(stacks_client, b);
                         }
                         SignerMessage::MockProposal(mock_proposal) => {
                             let epoch = match stacks_client.get_node_epoch() {
@@ -1528,12 +1528,11 @@ impl Signer {
     }
 
     fn broadcast_signed_block(
-        &self,
+        &mut self,
         stacks_client: &StacksClient,
         mut block: NakamotoBlock,
         addrs_to_sigs: &HashMap<StacksAddress, MessageSignature>,
     ) {
-        let block_hash = block.header.signer_signature_hash();
         // collect signatures for the block
         let signatures: Vec<_> = self
             .signer_addresses
@@ -1548,17 +1547,25 @@ impl Signer {
         if self.test_skip_block_broadcast(&block) {
             return;
         }
-        debug!(
-            "{self}: Broadcasting Stacks block {} to node",
-            &block.block_id()
-        );
-        stacks_client.post_block_until_ok(self, &block);
+        self.handle_post_block(stacks_client, &block);
+    }
 
-        if let Err(e) = self
-            .signer_db
-            .set_block_broadcasted(&block_hash, get_epoch_time_secs())
-        {
-            warn!("{self}: Failed to set block broadcasted for {block_hash}: {e:?}");
+    /// Attempt to post a block to the stacks-node and handle the result
+    pub fn handle_post_block(&mut self, stacks_client: &StacksClient, block: &NakamotoBlock) {
+        let block_hash = block.header.signer_signature_hash();
+        match stacks_client.post_block(block) {
+            Ok(accepted) => {
+                debug!("{self}: Block {block_hash} accepted by stacks node: {accepted}");
+                if let Err(e) = self
+                    .signer_db
+                    .set_block_broadcasted(&block_hash, get_epoch_time_secs())
+                {
+                    warn!("{self}: Failed to set block broadcasted for {block_hash}: {e:?}");
+                }
+            }
+            Err(e) => {
+                warn!("{self}: Failed to broadcast block {block_hash} to the node: {e}")
+            }
         }
     }
 

testnet/stacks-node/src/tests/signer/v0.rs

@@ -3493,7 +3493,9 @@ fn tx_replay_rejected_when_forking_across_reward_cycle() {
         let commits_count = submitted_commits.load(Ordering::SeqCst);
         next_block_and(btc_controller, 60, || {
             let commits_submitted = submitted_commits.load(Ordering::SeqCst);
-            Ok(commits_submitted > commits_count)
+            Ok(commits_submitted > commits_count
+                && get_chain_info(&signer_test.running_nodes.conf).burn_block_height
+                    > current_burn_height)
         })
         .unwrap();
     }
@@ -3502,6 +3504,18 @@ fn tx_replay_rejected_when_forking_across_reward_cycle() {
     assert_eq!(0, post_fork_tx_nonce);
 
     info!("----- Check Signers Tx Replay state -----");
+
+    let info = get_chain_info(&signer_test.running_nodes.conf);
+    let all_signers = signer_test.signer_test_pks();
+    wait_for_state_machine_update(
+        30,
+        &info.pox_consensus,
+        info.burn_block_height,
+        None,
+        &all_signers,
+        SUPPORTED_SIGNER_PROTOCOL_VERSION,
+    )
+    .expect("Timed out waiting for signer states to update");
     let (signer_states, _) = signer_test.get_burn_updated_states();
     for state in signer_states {
         assert!(