Selaa lähdekoodia

Log error right before assertion failurs in daemons.

Jing Yang 2 vuotta sitten
vanhempi
commit
a044b77280
3 muutettua tiedostoa jossa 33 lisäystä ja 0 poistoa
  1. 14 0
      src/apply_command.rs
  2. 8 0
      src/election.rs
  3. 11 0
      src/verify_authority.rs

+ 14 - 0
src/apply_command.rs

@@ -69,6 +69,13 @@ impl<Command: ReplicableCommand> Raft<Command> {
                     // Note that between those two nested `if`s, log start is
                     // Note that between those two nested `if`s, log start is
                     // always smaller than or equal to commit index, as
                     // always smaller than or equal to commit index, as
                     // guaranteed by the SNAPSHOT_INDEX_INVARIANT.
                     // guaranteed by the SNAPSHOT_INDEX_INVARIANT.
+                    if rf.log.start() > rf.commit_index {
+                        log::error!(
+                            "Commit index {} is before log start {}",
+                            rf.commit_index,
+                            rf.log.start()
+                        );
+                    }
                     assert!(rf.log.start() <= rf.commit_index);
                     assert!(rf.log.start() <= rf.commit_index);
                     if last_applied < rf.log.start() {
                     if last_applied < rf.log.start() {
                         let (index_term, data) = rf.log.snapshot();
                         let (index_term, data) = rf.log.snapshot();
@@ -84,6 +91,13 @@ impl<Command: ReplicableCommand> Raft<Command> {
                         let last_one = rf.commit_index + 1;
                         let last_one = rf.commit_index + 1;
                         // This is safe because commit_index is always smaller
                         // This is safe because commit_index is always smaller
                         // than log.end(), see COMMIT_INDEX_INVARIANT.
                         // than log.end(), see COMMIT_INDEX_INVARIANT.
+                        if last_one > rf.log.end() {
+                            log::error!(
+                                "Commit index {} is on or after log end {}",
+                                rf.commit_index,
+                                rf.log.end()
+                            );
+                        }
                         assert!(last_one <= rf.log.end());
                         assert!(last_one <= rf.log.end());
                         let messages: Vec<ApplyCommandMessage<Command>> = rf
                         let messages: Vec<ApplyCommandMessage<Command>> = rf
                             .log
                             .log

+ 8 - 0
src/election.rs

@@ -178,6 +178,14 @@ impl<Command: ReplicableCommand> Raft<Command> {
             // order. We should cancel the election and just wait.
             // order. We should cancel the election and just wait.
             if let Some(last_timer_count) = should_run {
             if let Some(last_timer_count) = should_run {
                 let expected_timer_count = last_timer_count + 1;
                 let expected_timer_count = last_timer_count + 1;
+                if timer_count < expected_timer_count {
+                    log::error!(
+                        "Spurious wake up. \
+                        Expecting version at least {}+1, but got {}",
+                        last_timer_count,
+                        timer_count
+                    );
+                }
                 assert!(timer_count >= expected_timer_count);
                 assert!(timer_count >= expected_timer_count);
                 // If the timer was changed more than once, we know the
                 // If the timer was changed more than once, we know the
                 // last scheduled election should have been cancelled.
                 // last scheduled election should have been cancelled.

+ 11 - 0
src/verify_authority.rs

@@ -220,6 +220,14 @@ impl VerifyAuthorityDaemon {
                 token.beats_moment[peer_index] <= ticked
                 token.beats_moment[peer_index] <= ticked
             });
             });
             let new_covered = first_not_ticked_index + state.start.0;
             let new_covered = first_not_ticked_index + state.start.0;
+            if new_covered < state.covered[peer_index].0 {
+                log::error!(
+                    "Ticked index moving backwards from {} to {} for peer {}",
+                    state.covered[peer_index].0,
+                    new_covered,
+                    peer_index,
+                );
+            }
             assert!(new_covered >= state.covered[peer_index].0);
             assert!(new_covered >= state.covered[peer_index].0);
             state.covered[peer_index].0 = new_covered;
             state.covered[peer_index].0 = new_covered;
 
 
@@ -249,6 +257,9 @@ impl VerifyAuthorityDaemon {
                         cnt += 1;
                         cnt += 1;
                     }
                     }
                 }
                 }
+                if cnt + cnt + 1 < self.beat_tickers.len() {
+                    log::error!("Token {:?} is not covered", token);
+                }
                 assert!(cnt + cnt + 1 >= self.beat_tickers.len());
                 assert!(cnt + cnt + 1 >= self.beat_tickers.len());
 
 
                 // Never verify authority before the sentinel commit index. The
                 // Never verify authority before the sentinel commit index. The