From 706cd88065c6d698966b189b30781e02dd2ce209 Mon Sep 17 00:00:00 2001 From: Nikhil-Ladha Date: Mon, 19 May 2025 11:51:19 +0530 Subject: [PATCH] rbd: improve logging for rpc calls added logging of reqID for volume group rpc calls. Also, added logs for replication rpc calls which are helpful during debugging of issues related to failover/relocate. Signed-off-by: Nikhil-Ladha --- internal/csi-addons/rbd/replication.go | 4 ++++ internal/csi-common/utils.go | 28 ++++++++++++++++---------- internal/rbd/mirror.go | 12 +++++++++++ 3 files changed, 33 insertions(+), 11 deletions(-) diff --git a/internal/csi-addons/rbd/replication.go b/internal/csi-addons/rbd/replication.go index 40982e90a..026af6445 100644 --- a/internal/csi-addons/rbd/replication.go +++ b/internal/csi-addons/rbd/replication.go @@ -306,6 +306,7 @@ func (rs *ReplicationServer) EnableVolumeReplication(ctx context.Context, return nil, status.Error(codes.Internal, err.Error()) } + log.UsefulLog(ctx, "mirror state is %s", info.GetState()) if info.GetState() != librbd.MirrorImageEnabled.String() { err = rbdVol.HandleParentImageExistence(ctx, flattenMode) if err != nil { @@ -371,6 +372,7 @@ func (rs *ReplicationServer) DisableVolumeReplication(ctx context.Context, return nil, status.Error(codes.Internal, err.Error()) } + log.UsefulLog(ctx, "mirror state is %s", info.GetState()) switch info.GetState() { // image is already in disabled state case librbd.MirrorImageDisabled.String(): @@ -433,6 +435,7 @@ func (rs *ReplicationServer) PromoteVolume(ctx context.Context, return nil, status.Error(codes.Internal, err.Error()) } + log.UsefulLog(ctx, "mirror state is %s, primary: %s", info.GetState(), info.IsPrimary()) if info.GetState() != librbd.MirrorImageEnabled.String() { return nil, status.Errorf( @@ -533,6 +536,7 @@ func (rs *ReplicationServer) DemoteVolume(ctx context.Context, return nil, status.Error(codes.Internal, err.Error()) } + log.UsefulLog(ctx, "mirror state is %s, primary: %s", info.GetState(), info.IsPrimary()) if info.GetState() != librbd.MirrorImageEnabled.String() { return nil, status.Errorf( diff --git a/internal/csi-common/utils.go b/internal/csi-common/utils.go index e9ac2ce69..b487ee9c8 100644 --- a/internal/csi-common/utils.go +++ b/internal/csi-common/utils.go @@ -29,6 +29,7 @@ import ( "github.com/container-storage-interface/spec/lib/go/csi" "github.com/csi-addons/spec/lib/go/replication" + "github.com/csi-addons/spec/lib/go/volumegroup" grpc_middleware "github.com/grpc-ecosystem/go-grpc-middleware" "github.com/kubernetes-csi/csi-lib-utils/protosanitizer" "google.golang.org/grpc" @@ -222,18 +223,23 @@ func getReqID(req interface{}) string { reqID = r.GetGroupSnapshotId() // Replication - case *replication.EnableVolumeReplicationRequest: - reqID = GetIDFromReplication(r) - case *replication.DisableVolumeReplicationRequest: - reqID = GetIDFromReplication(r) - case *replication.PromoteVolumeRequest: - reqID = GetIDFromReplication(r) - case *replication.DemoteVolumeRequest: - reqID = GetIDFromReplication(r) - case *replication.ResyncVolumeRequest: - reqID = GetIDFromReplication(r) - case *replication.GetVolumeReplicationInfoRequest: + case *replication.EnableVolumeReplicationRequest, + *replication.DisableVolumeReplicationRequest, + *replication.PromoteVolumeRequest, + *replication.DemoteVolumeRequest, + *replication.ResyncVolumeRequest, + *replication.GetVolumeReplicationInfoRequest: reqID = GetIDFromReplication(r) + + // VolumeGroup + case *volumegroup.CreateVolumeGroupRequest: + reqID = r.GetName() + case *volumegroup.ModifyVolumeGroupMembershipRequest: + reqID = r.GetVolumeGroupId() + case *volumegroup.DeleteVolumeGroupRequest: + reqID = r.GetVolumeGroupId() + case *volumegroup.ControllerGetVolumeGroupRequest: + reqID = r.GetVolumeGroupId() } return reqID diff --git a/internal/rbd/mirror.go b/internal/rbd/mirror.go index 4f3c154a1..3bcae1cee 100644 --- a/internal/rbd/mirror.go +++ b/internal/rbd/mirror.go @@ -120,6 +120,8 @@ func (rm *rbdMirror) EnableMirroring(ctx context.Context, mode librbd.ImageMirro return fmt.Errorf("failed to enable mirroring on %q with error: %w", rm, err) } + log.DebugLog(ctx, "mirroring is enabled on the image %q", rm) + return nil } @@ -141,6 +143,8 @@ func (rm *rbdMirror) DisableMirroring(ctx context.Context, force bool) error { return fmt.Errorf("failed to disable mirroring on %q with error: %w", rm, err) } + log.DebugLog(ctx, "mirroring is disabled on the image %q", rm) + return nil } @@ -183,6 +187,8 @@ func (rm *rbdMirror) Promote(ctx context.Context, force bool) error { return fmt.Errorf("failed to promote image %q with error: %w", rm, err) } + log.DebugLog(ctx, "image %q has been promoted", rm) + return nil } @@ -213,6 +219,8 @@ func (rm *rbdMirror) ForcePromote(ctx context.Context, cr *util.Credentials) err return fmt.Errorf("failed to promote image %q with stderror: %s", rm, stderr) } + log.DebugLog(ctx, "image %q has been force promoted", rm) + return nil } @@ -234,6 +242,8 @@ func (rm *rbdMirror) Demote(ctx context.Context) error { return fmt.Errorf("failed to demote image %q with error: %w", rm, err) } + log.DebugLog(ctx, "image %q has been demoted", rm) + return nil } @@ -259,6 +269,8 @@ func (rm *rbdMirror) Resync(ctx context.Context) error { return fmt.Errorf("failed to resync image %q with error: %w", rm, err) } + log.DebugLog(ctx, "issued resync on image %q", rm) + // delay until the state is syncing, or until 1+2+4+8+16 seconds passed delay := 1 * time.Second for {