Add debugging

Release note: None

pkg/cmd/roachtest/tpcc.go

@@ -158,7 +158,7 @@ func runTPCC(ctx context.Context, t *test, c *cluster, opts tpccOptions) {
 			c.Run(ctx, crdbNodes, "sudo zfs rollback data1@pristine")
 			c.Start(ctx, t, crdbNodes, startArgsDontEncrypt)
 		} else {
-			c.Start(ctx, t, crdbNodes, startArgsDontEncrypt)
+			c.Start(ctx, t, crdbNodes, startArgsDontEncrypt, startArgs("--args='--vmodule=*raft=3,replica*=2'"))
 			c.Run(ctx, workloadNode, tpccFixturesCmd(t, cloud, opts.Warehouses, ""))
 		}
 	}()
@@ -247,7 +247,7 @@ func registerTPCC(r *testRegistry) {
 			t.l.Printf("computed headroom warehouses of %d\n", headroomWarehouses)
 			runTPCC(ctx, t, c, tpccOptions{
 				Warehouses: headroomWarehouses,
-				Duration:   120 * time.Minute,
+				Duration:   120 * time.Second,
 			})
 		},
 	})

pkg/storage/replica.go

@@ -582,6 +582,9 @@ func (r *Replica) cleanupFailedProposal(p *ProposalData) {
 // cleanupFailedProposalLocked is like cleanupFailedProposal, but requires
 // the Replica mutex to be exclusively held.
 func (r *Replica) cleanupFailedProposalLocked(p *ProposalData) {
+	if log.V(1) {
+		log.Infof(p.ctx, "cleanupFailedProposalLocked %+v", p)
+	}
 	// Clear the proposal from the proposals map. May be a no-op if the
 	// proposal has not yet been inserted into the map.
 	delete(r.mu.proposals, p.idKey)

pkg/storage/replica_proposal.go

@@ -116,6 +116,11 @@ type ProposalData struct {
 	Request *roachpb.BatchRequest
 }
 
+func (proposal *ProposalData) String() string {
+	return fmt.Sprintf("ProposalData{id: %v, maxLeaseIndex: %v, quota %v}",
+		proposal.idKey, proposal.command.MaxLeaseIndex, proposal.quotaSize)
+}
+
 // finishApplication is called when a command application has finished. The
 // method will be called downstream of Raft if the command required consensus,
 // but can be called upstream of Raft if the command did not and was never

pkg/storage/replica_proposal_quota.go

@@ -235,6 +235,14 @@ func (r *Replica) updateProposalQuotaRaftMuLocked(
 		for _, rel := range r.mu.quotaReleaseQueue[:numReleases] {
 			sum += rel
 		}
+
+		if r.mu.proposalQuotaBaseIndex+numReleases > r.mu.lastIndex {
+			log.Fatalf(ctx, "proposalQuotaBaseIndex (%d) + numReleases (%d) > lastIndex (%d), %v",
+				r.mu.proposalQuotaBaseIndex, numReleases, r.mu.lastIndex, r.mu.quotaReleaseQueue)
+		} else if r.mu.proposalQuotaBaseIndex+uint64(len(r.mu.quotaReleaseQueue)) > r.mu.lastIndex {
+			log.Fatalf(ctx, "proposalQuotaBaseIndex (%d) + len(quotaReleaseQueue) (%d) > lastIndex (%d), %v",
+				r.mu.proposalQuotaBaseIndex, len(r.mu.quotaReleaseQueue), r.mu.lastIndex, r.mu.quotaReleaseQueue)
+		}
 		r.mu.proposalQuotaBaseIndex += numReleases
 		r.mu.quotaReleaseQueue = r.mu.quotaReleaseQueue[numReleases:]
 

pkg/storage/replica_raft.go

@@ -932,9 +932,9 @@ func (r *Replica) refreshProposalsLocked(refreshAtDelta int, reason refreshRaftR
 	if log.V(1) && len(reproposals) > 0 {
 		ctx := r.AnnotateCtx(context.TODO())
 		log.Infof(ctx,
-			"pending commands: reproposing %d (at %d.%d) %s",
+			"pending commands: reproposing %d (at %d.%d) %v %s %v",
 			len(reproposals), r.mu.state.RaftAppliedIndex,
-			r.mu.state.LeaseAppliedIndex, reason)
+			r.mu.state.LeaseAppliedIndex, reason, reproposals)
 	}
 
 	// Reproposals are those commands which we weren't able to send back to the