Merge #153949

153949: kvserver: assign some Dev logs to KvExec/KvDistribution r=tbg a=tbg

See individual commits.

Epic: none

Co-authored-by: Tobias Grieger <[email protected]>

Author: craig[bot]

pkg/kv/kvserver/addressing_test.go

@@ -210,16 +210,16 @@ func TestUpdateRangeAddressing(t *testing.T) {
 
 		if test.split {
 			if log.V(1) {
-				log.Dev.Infof(ctx, "test case %d: split %q-%q at %q", i, left.StartKey, right.EndKey, left.EndKey)
+				log.KvExec.Infof(ctx, "test case %d: split %q-%q at %q", i, left.StartKey, right.EndKey, left.EndKey)
 			}
 		} else {
 			if log.V(1) {
-				log.Dev.Infof(ctx, "test case %d: merge %q-%q + %q-%q", i, left.StartKey, left.EndKey, left.EndKey, right.EndKey)
+				log.KvExec.Infof(ctx, "test case %d: merge %q-%q + %q-%q", i, left.StartKey, left.EndKey, left.EndKey, right.EndKey)
 			}
 		}
 		for _, meta := range metas {
 			if log.V(1) {
-				log.Dev.Infof(ctx, "%q", meta.key)
+				log.KvExec.Infof(ctx, "%q", meta.key)
 			}
 		}
 

pkg/kv/kvserver/app_batch.go

@@ -84,7 +84,7 @@ func (b *appBatch) assertAndCheckCommand(
 	ctx context.Context, cmd *raftlog.ReplicatedCmd, state *kvserverpb.ReplicaState, isLocal bool,
 ) (kvserverbase.ForcedErrResult, error) {
 	if log.V(4) {
-		log.Dev.Infof(ctx, "processing command %x: raftIndex=%d maxLeaseIndex=%d closedts=%s",
+		log.KvExec.Infof(ctx, "processing command %x: raftIndex=%d maxLeaseIndex=%d closedts=%s",
 			cmd.ID, cmd.Index(), cmd.Cmd.MaxLeaseIndex, cmd.Cmd.ClosedTimestamp)
 	}
 
@@ -138,7 +138,7 @@ func (b *appBatch) addWriteBatch(
 		return nil
 	}
 	if mutations, err := storage.BatchCount(wb.Data); err != nil {
-		log.Dev.Errorf(ctx, "unable to read header of committed WriteBatch: %+v", err)
+		log.KvExec.Errorf(ctx, "unable to read header of committed WriteBatch: %+v", err)
 	} else {
 		b.numMutations += mutations
 	}

pkg/kv/kvserver/client_lease_test.go

@@ -231,7 +231,7 @@ func TestGossipNodeLivenessOnLeaseChange(t *testing.T) {
 		t.Fatalf("no store has gossiped %s; gossip contents: %+v",
 			nodeLivenessKey, tc.GetFirstStoreFromServer(t, 0).Gossip().GetInfoStatus())
 	}
-	log.Dev.Infof(context.Background(), "%s gossiped from s%d",
+	log.KvExec.Infof(context.Background(), "%s gossiped from s%d",
 		nodeLivenessKey, initialServerId)
 
 	newServerIdx := (initialServerId + 1) % numStores

pkg/kv/kvserver/client_merge_test.go

@@ -1921,7 +1921,7 @@ func TestStoreRangeMergeRHSLeaseExpiration(t *testing.T) {
 			// When this test was written, it would always produce the above
 			// interleaving, and successfully trigger the race when run with the race
 			// detector enabled about 50% of the time.
-			log.Dev.Infof(ctx, "starting req %d", i)
+			log.KvDistribution.Infof(ctx, "starting req %d", i)
 			var req kvpb.Request
 			if i%2 == 0 {
 				req = getArgs(rhsSentinel)
@@ -4167,7 +4167,7 @@ func TestStoreRangeMergeRaftSnapshot(t *testing.T) {
 		}
 
 		// Restore Raft traffic to the LHS on store2.
-		log.Dev.Infof(ctx, "restored traffic to store 2")
+		log.KvDistribution.Infof(ctx, "restored traffic to store 2")
 		tc.Servers[2].RaftTransport().(*kvserver.RaftTransport).ListenIncomingRaftMessages(store2.Ident.StoreID, &unreliableRaftHandler{
 			rangeID:                    aRepl0.RangeID,
 			IncomingRaftMessageHandler: store2,

pkg/kv/kvserver/client_raft_epoch_leases_test.go

@@ -274,9 +274,9 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 		// can increment it again later.
 		_, err := tc.Server(0).DB().Inc(ctx, key, 1)
 		require.NoError(t, err)
-		log.Dev.Infof(ctx, "test: waiting for initial values...")
+		log.KvExec.Infof(ctx, "test: waiting for initial values...")
 		tc.WaitForValues(t, key, []int64{1, 1, 1})
-		log.Dev.Infof(ctx, "test: waiting for initial values... done")
+		log.KvExec.Infof(ctx, "test: waiting for initial values... done")
 	}
 
 	// Partition the original leader from its followers. We do this by installing
@@ -291,7 +291,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	//        x      x
 	//      [1]<---->[2]
 	//
-	log.Dev.Infof(ctx, "test: partitioning node")
+	log.KvExec.Infof(ctx, "test: partitioning node")
 	const partitionNodeIdx = 0
 	partitionStore := tc.GetFirstStoreFromServer(t, partitionNodeIdx)
 	partRepl, err := partitionStore.GetReplica(rngDesc.RangeID)
@@ -325,12 +325,12 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	}
 
 	// Stop the heartbeats so that n1's lease can expire.
-	log.Dev.Infof(ctx, "test: suspending heartbeats for n1")
+	log.KvExec.Infof(ctx, "test: suspending heartbeats for n1")
 	resumeN1Heartbeats := partitionStore.GetStoreConfig().NodeLiveness.PauseAllHeartbeatsForTest()
 
 	// Wait until another replica campaigns and becomes leader, replacing the
 	// partitioned one.
-	log.Dev.Infof(ctx, "test: waiting for leadership transfer")
+	log.KvExec.Infof(ctx, "test: waiting for leadership transfer")
 	testutils.SucceedsSoon(t, func() error {
 		// Make sure this replica has not inadvertently quiesced. We need the
 		// replica ticking so that it campaigns.
@@ -348,7 +348,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	})
 
 	leaderReplicaID := roachpb.ReplicaID(otherRepl.RaftStatus().Lead)
-	log.Dev.Infof(ctx, "test: the leader is replica ID %d", leaderReplicaID)
+	log.KvExec.Infof(ctx, "test: the leader is replica ID %d", leaderReplicaID)
 	if leaderReplicaID != 2 && leaderReplicaID != 3 {
 		t.Fatalf("expected leader to be 1 or 2, was: %d", leaderReplicaID)
 	}
@@ -358,7 +358,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	require.NoError(t, err)
 
 	// Wait until the lease expires.
-	log.Dev.Infof(ctx, "test: waiting for lease expiration")
+	log.KvExec.Infof(ctx, "test: waiting for lease expiration")
 	partitionedReplica, err := partitionStore.GetReplica(rngDesc.RangeID)
 	require.NoError(t, err)
 	testutils.SucceedsSoon(t, func() error {
@@ -375,11 +375,11 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 		}
 		return nil
 	})
-	log.Dev.Infof(ctx, "test: lease expired")
+	log.KvExec.Infof(ctx, "test: lease expired")
 
 	{
 		// Write something to generate some Raft log entries and then truncate the log.
-		log.Dev.Infof(ctx, "test: incrementing")
+		log.KvExec.Infof(ctx, "test: incrementing")
 		incArgs := incrementArgs(key, 1)
 		sender := leaderStore.TestSender()
 		_, pErr := kv.SendWrapped(ctx, sender, incArgs)
@@ -392,7 +392,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	// Truncate the log at index+1 (log entries < N are removed, so this includes
 	// the increment). This means that the partitioned replica will need a
 	// snapshot to catch up.
-	log.Dev.Infof(ctx, "test: truncating log...")
+	log.KvExec.Infof(ctx, "test: truncating log...")
 	truncArgs := &kvpb.TruncateLogRequest{
 		RequestHeader: kvpb.RequestHeader{
 			Key: key,
@@ -408,7 +408,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	// Resume n1's heartbeats and wait for it to become live again. This is to
 	// ensure that the rest of the test does not somehow fool itself because n1 is
 	// not live.
-	log.Dev.Infof(ctx, "test: resuming n1 heartbeats")
+	log.KvExec.Infof(ctx, "test: resuming n1 heartbeats")
 	resumeN1Heartbeats()
 
 	// Resolve the partition, but continue blocking snapshots destined for the
@@ -418,7 +418,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 	// allow the replica in question to figure out that it's not the leader any
 	// more. As long as it is completely partitioned, the replica continues
 	// believing that it is the leader, and lease acquisition requests block.
-	log.Dev.Infof(ctx, "test: removing partition")
+	log.KvExec.Infof(ctx, "test: removing partition")
 	slowSnapHandler := &slowSnapRaftHandler{
 		rangeID:                    rngDesc.RangeID,
 		waitCh:                     make(chan struct{}),
@@ -439,7 +439,7 @@ func TestRequestsOnLaggingReplicaEpochLeases(t *testing.T) {
 
 	// Now we're going to send a request to the behind replica, and we expect it
 	// to not block; we expect a redirection to the leader.
-	log.Dev.Infof(ctx, "test: sending request")
+	log.KvExec.Infof(ctx, "test: sending request")
 	timeoutCtx, cancel := context.WithTimeout(ctx, 10*time.Second)
 	defer cancel()
 	for {
@@ -549,7 +549,7 @@ func TestSnapshotAfterTruncationWithUncommittedTailEpochLeases(t *testing.T) {
 	//        x      x
 	//      [1]<---->[2]
 	//
-	log.Dev.Infof(ctx, "test: installing unreliable Raft transports")
+	log.KvExec.Infof(ctx, "test: installing unreliable Raft transports")
 	for _, s := range []int{0, 1, 2} {
 		h := &unreliableRaftHandler{
 			rangeID:                    partRepl.RangeID,
@@ -572,7 +572,7 @@ func TestSnapshotAfterTruncationWithUncommittedTailEpochLeases(t *testing.T) {
 	// not succeed before their context is canceled, but they will be appended
 	// to the partitioned replica's Raft log because it is currently the Raft
 	// leader.
-	log.Dev.Infof(ctx, "test: sending writes to partitioned replica")
+	log.KvExec.Infof(ctx, "test: sending writes to partitioned replica")
 	g := ctxgroup.WithContext(ctx)
 	otherKeys := make([]roachpb.Key, 32)
 	otherKeys[0] = key.Next()
@@ -609,7 +609,7 @@ func TestSnapshotAfterTruncationWithUncommittedTailEpochLeases(t *testing.T) {
 	nonPartitionedSenders[0] = tc.GetFirstStoreFromServer(t, 1).TestSender()
 	nonPartitionedSenders[1] = tc.GetFirstStoreFromServer(t, 2).TestSender()
 
-	log.Dev.Infof(ctx, "test: sending write to transfer lease")
+	log.KvExec.Infof(ctx, "test: sending write to transfer lease")
 	incArgs = incrementArgs(key, incB)
 	var i int
 	var newLeaderRepl *kvserver.Replica
@@ -632,15 +632,15 @@ func TestSnapshotAfterTruncationWithUncommittedTailEpochLeases(t *testing.T) {
 		newLeaderReplSender = tc.GetFirstStoreFromServer(t, newLeaderStoreIdx).TestSender()
 		return nil
 	})
-	log.Dev.Infof(ctx, "test: waiting for values...")
+	log.KvExec.Infof(ctx, "test: waiting for values...")
 	tc.WaitForValues(t, key, []int64{incA, incAB, incAB})
-	log.Dev.Infof(ctx, "test: waiting for values... done")
+	log.KvExec.Infof(ctx, "test: waiting for values... done")
 
 	index := newLeaderRepl.GetLastIndex()
 
 	// Truncate the log at index+1 (log entries < N are removed, so this
 	// includes the increment).
-	log.Dev.Infof(ctx, "test: truncating log")
+	log.KvExec.Infof(ctx, "test: truncating log")
 	truncArgs := truncateLogArgs(index+1, partRepl.RangeID)
 	truncArgs.Key = partRepl.Desc().StartKey.AsRawKey()
 	testutils.SucceedsSoon(t, func() error {
@@ -659,7 +659,7 @@ func TestSnapshotAfterTruncationWithUncommittedTailEpochLeases(t *testing.T) {
 	snapsBefore := snapsMetric.Count()
 
 	// Remove the partition. Snapshot should follow.
-	log.Dev.Infof(ctx, "test: removing the partition")
+	log.KvExec.Infof(ctx, "test: removing the partition")
 	for _, s := range []int{0, 1, 2} {
 		tc.Servers[s].RaftTransport().(*kvserver.RaftTransport).ListenIncomingRaftMessages(tc.Target(s).StoreID, &unreliableRaftHandler{
 			rangeID:                    partRepl.RangeID,

pkg/kv/kvserver/client_raft_helpers_test.go

@@ -85,7 +85,7 @@ func (h *unreliableRaftHandler) HandleRaftRequest(
 			if h.name != "" {
 				prefix = fmt.Sprintf("[%s] ", h.name)
 			}
-			log.Dev.Infof(
+			log.KvExec.Infof(
 				ctx,
 				"%sdropping r%d Raft message %s",
 				prefix,
@@ -105,7 +105,7 @@ func (h *unreliableRaftHandler) HandleRaftRequest(
 			if h.name != "" {
 				prefix = fmt.Sprintf("[%s] ", h.name)
 			}
-			log.Dev.Infof(
+			log.KvExec.Infof(
 				ctx,
 				"%s [raft] r%d Raft message %s",
 				prefix,
@@ -420,10 +420,10 @@ func setupPartitionedRangeWithHandlers(
 					DropStoreLivenessMsg: func(msg *storelivenesspb.Message) bool {
 						drop := shouldDropStoreLivenessMessage(msg.From.StoreID, msg.To.StoreID)
 						if drop {
-							log.Dev.Infof(context.Background(), "dropping StoreLiveness msg %s from store %d: to %d",
+							log.KvExec.Infof(context.Background(), "dropping StoreLiveness msg %s from store %d: to %d",
 								msg.Type, msg.From.StoreID, msg.To.StoreID)
 						} else {
-							log.Dev.Infof(context.Background(), "allowing StoreLiveness msg %s from store %d: to %d",
+							log.KvExec.Infof(context.Background(), "allowing StoreLiveness msg %s from store %d: to %d",
 								msg.Type, msg.From.StoreID, msg.To.StoreID)
 						}
 						return drop