Log routing decisions in Praefectsmh-log-routing-decisions

Praefect currently doesn't log the routing decisions it makes. This
commit adds logging for the routing decisions as they can be helpful
in debugging various scenarios.

Changelog: added

2 files changed, 72 insertions, 0 deletions

diff --git a/internal/praefect/coordinator.go b/internal/praefect/coordinator.go
index ed5b71045..77e83ec5a 100644
--- a/internal/praefect/coordinator.go
+++ b/internal/praefect/coordinator.go
@@ -312,6 +312,8 @@ func (c *Coordinator) accessorStreamParameters(ctx context.Context, call grpcCal
 		return nil, fmt.Errorf("accessor call: route repository accessor: %w", err)
 	}
 
+	route.addLogFields(ctx)
+
 	b, err := rewrittenRepositoryMessage(call.methodInfo, call.msg, route.Node.Storage, route.ReplicaPath, "")
 	if err != nil {
 		return nil, fmt.Errorf("accessor call: rewrite storage: %w", err)
@@ -400,6 +402,8 @@ func (c *Coordinator) mutatorStreamParameters(ctx context.Context, call grpcCall
 		}
 	}
 
+	route.addLogFields(ctx)
+
 	primaryMessage, err := rewrittenRepositoryMessage(call.methodInfo, call.msg, route.Primary.Storage, route.ReplicaPath, route.AdditionalReplicaPath)
 	if err != nil {
 		return nil, fmt.Errorf("mutator call: rewrite storage: %w", err)
@@ -526,6 +530,8 @@ func (c *Coordinator) maintenanceStreamParameters(ctx context.Context, call grpc
 		return nil, fmt.Errorf("routing repository maintenance: %w", err)
 	}
 
+	route.addLogFields(ctx)
+
 	peerCtx := streamParametersContext(ctx)
 
 	nodeDests := make([]proxy.Destination, 0, len(route.Nodes))
@@ -711,6 +717,8 @@ func (c *Coordinator) accessorStorageStreamParameters(ctx context.Context, mi pr
 		return nil, helper.ErrInternalf("accessor storage scoped: route storage accessor %q: %w", virtualStorage, err)
 	}
 
+	node.addLogFields(ctx)
+
 	b, err := rewrittenStorageMessage(mi, msg, node.Storage)
 	if err != nil {
 		return nil, helper.ErrInvalidArgument(fmt.Errorf("accessor storage scoped: %w", err))
@@ -737,6 +745,8 @@ func (c *Coordinator) mutatorStorageStreamParameters(ctx context.Context, mi pro
 		return nil, helper.ErrInternalf("mutator storage scoped: get shard %q: %w", virtualStorage, err)
 	}
 
+	route.addLogFields(ctx)
+
 	b, err := rewrittenStorageMessage(mi, msg, route.Primary.Storage)
 	if err != nil {
 		return nil, helper.ErrInvalidArgument(fmt.Errorf("mutator storage scoped: %w", err))
diff --git a/internal/praefect/router.go b/internal/praefect/router.go
index da9dbd36f..139bd62f9 100644
--- a/internal/praefect/router.go
+++ b/internal/praefect/router.go
@@ -3,9 +3,32 @@ package praefect
 import (
 	"context"
 
+	"github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus/ctxlogrus"
+	"github.com/sirupsen/logrus"
 	"google.golang.org/grpc"
 )
 
+const (
+	logFieldRepositoryID          = "repository_id"
+	logFieldReplicaPath           = "replica_path"
+	logFieldAdditionalReplicaPath = "additional_replica_path"
+	logFieldPrimary               = "primary"
+	logFieldSecondaries           = "secondaries"
+	logFieldStorage               = "storage"
+)
+
+func addRouteLogField(ctx context.Context, fields logrus.Fields) {
+	ctxlogrus.AddFields(ctx, logrus.Fields{"route": fields})
+}
+
+func routerNodeStorages(secondaries []RouterNode) []string {
+	storages := make([]string, len(secondaries))
+	for i := range secondaries {
+		storages[i] = secondaries[i].Storage
+	}
+	return storages
+}
+
 // RepositoryAccessorRoute describes how to route a repository scoped accessor call.
 type RepositoryAccessorRoute struct {
 	// ReplicaPath is the disk path where the replicas are stored.
@@ -14,6 +37,13 @@ type RepositoryAccessorRoute struct {
 	Node RouterNode
 }
 
+func (r RepositoryAccessorRoute) addLogFields(ctx context.Context) {
+	addRouteLogField(ctx, logrus.Fields{
+		logFieldReplicaPath: r.ReplicaPath,
+		logFieldStorage:     r.Node.Storage,
+	})
+}
+
 // RouterNode is a subset of a node's configuration needed to perform
 // request routing.
 type RouterNode struct {
@@ -23,6 +53,12 @@ type RouterNode struct {
 	Connection *grpc.ClientConn
 }
 
+func (r RouterNode) addLogFields(ctx context.Context) {
+	addRouteLogField(ctx, logrus.Fields{
+		logFieldStorage: r.Storage,
+	})
+}
+
 // StorageMutatorRoute describes how to route a storage scoped mutator call.
 type StorageMutatorRoute struct {
 	// Primary is the primary node of the routing decision.
@@ -31,6 +67,13 @@ type StorageMutatorRoute struct {
 	Secondaries []RouterNode
 }
 
+func (r StorageMutatorRoute) addLogFields(ctx context.Context) {
+	addRouteLogField(ctx, logrus.Fields{
+		logFieldPrimary:     r.Primary,
+		logFieldSecondaries: routerNodeStorages(r.Secondaries),
+	})
+}
+
 // RepositoryMutatorRoute describes how to route a repository scoped mutator call.
 type RepositoryMutatorRoute struct {
 	// RepositoryID is the repository's ID as Praefect identifies it.
@@ -49,6 +92,17 @@ type RepositoryMutatorRoute struct {
 	ReplicationTargets []string
 }
 
+func (r RepositoryMutatorRoute) addLogFields(ctx context.Context) {
+	addRouteLogField(ctx, logrus.Fields{
+		logFieldRepositoryID:          r.RepositoryID,
+		logFieldReplicaPath:           r.ReplicaPath,
+		logFieldAdditionalReplicaPath: r.AdditionalReplicaPath,
+		logFieldPrimary:               r.Primary,
+		logFieldSecondaries:           routerNodeStorages(r.Secondaries),
+		"replication_targets":         r.ReplicationTargets,
+	})
+}
+
 // RepositoryMaintenanceRoute describes how to route a repository scoped maintenance call.
 type RepositoryMaintenanceRoute struct {
 	// RepositoryID is the repository's ID as Praefect identifies it.
@@ -59,6 +113,14 @@ type RepositoryMaintenanceRoute struct {
 	Nodes []RouterNode
 }
 
+func (r RepositoryMaintenanceRoute) addLogFields(ctx context.Context) {
+	addRouteLogField(ctx, logrus.Fields{
+		logFieldRepositoryID: r.RepositoryID,
+		logFieldReplicaPath:  r.ReplicaPath,
+		"storages":           routerNodeStorages(r.Nodes),
+	})
+}
+
 // Router decides which nodes to direct accessor and mutator RPCs to.
 type Router interface {
 	// RouteStorageAccessor returns the node which should serve the storage accessor request.