rbd: add additional logging details for stream server #5411

Rakshith-R · 2025-07-04T05:23:38Z

Describe what this PR does

This commit adds stream server interceptor
for logging purposes.

Related issues

Updated: #5346
Depends-on: #5347

Example logs:

I0703 11:24:29.955375       1 utils.go:328] ID: 22 GRPC call: /csi.v1.SnapshotMetadata/GetMetadataDelta
I0703 11:24:29.964025       1 utils.go:306] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b GRPC GetMetadataAllocatedRequest: {"base_snapshot_id":"0001-0009-rook-ceph-0000000000000001-a97e2e4f-5037-4e54-bda8-72c64d99c3f8","max_results":10,"secrets":"**stripped**","starting_offset":123213,"target_snapshot_id":"0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b"}
I0703 11:24:29.964097       1 utils.go:309] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b GRPC request: {"base_snapshot_id":"0001-0009-rook-ceph-0000000000000001-a97e2e4f-5037-4e54-bda8-72c64d99c3f8","max_results":10,"secrets":"**stripped**","starting_offset":123213,"target_snapshot_id":"0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b"}
I0703 11:24:30.048654       1 omap.go:89] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b got omap values: (pool="replicapool", namespace="", name="csi.snap.a97e2e4f-5037-4e54-bda8-72c64d99c3f8"): map[csi.imageid:142a23f27e1c5 csi.imagename:csi-snap-a97e2e4f-5037-4e54-bda8-72c64d99c3f8 csi.snapname:snapshot-cdb2d067-2a23-49df-9dc0-0ea92fbda35f csi.source:csi-vol-ec868036-7a20-4daa-ba78-c3e6013fd623 csi.volume.encryptKMS:metadata csi.volume.encryptionType:block csi.volume.owner:default]
I0703 11:24:30.134643       1 omap.go:89] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b got omap values: (pool="replicapool", namespace="", name="csi.snap.c5512d55-9590-4943-a562-2d3484fc083b"): map[csi.imageid:142a28525e576 csi.imagename:csi-snap-c5512d55-9590-4943-a562-2d3484fc083b csi.snapname:snapshot-6310f9a1-b46e-4e3c-b0a7-cdc934bd3af7 csi.source:csi-vol-ec868036-7a20-4daa-ba78-c3e6013fd623 csi.volume.encryptKMS:metadata csi.volume.encryptionType:block csi.volume.owner:default]
I0703 11:24:30.188244       1 sms_controllerserver.go:56] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b using requested maxResults: 10
I0703 11:24:30.378853       1 sms_controllerserver.go:223] ID: 22 Req-ID: 0001-0009-rook-ceph-0000000000000001-c5512d55-9590-4943-a562-2d3484fc083b successfully streamed metadata delta

Checklist:

Commit Message Formatting: Commit titles and messages follow
guidelines in the developer
guide.
Reviewed the developer guide on Submitting a Pull
Request
Pending release
notes
updated with breaking and/or notable changes for the next major release.
Documentation has been updated, if necessary.
Unit tests have been added, if necessary.
Integration tests have been added, if necessary.

Show available bot commands

These commands are normally not required, but in case of issues, leave any of
the following bot commands in an otherwise empty comment in this PR:

/retest ci/centos/<job-name>: retest the <job-name> after unrelated
failure (please report the failure too!)

Madhu-1 · 2025-07-04T05:45:51Z

internal/csi-common/utils.go

+	case *volumegroup.DeleteVolumeGroupRequest:
+		reqID = r.GetVolumeGroupId()
+	case *volumegroup.ControllerGetVolumeGroupRequest:
+		reqID = r.GetVolumeGroupId()


why volumegroup?

why volumegroup?

This got modified by mistake, fixed now

i still see the case, looks like the latest code is not pushed?

i still see the case, looks like the latest code is not pushed?

sorry 🤦 its pushed now

Madhu-1 · 2025-07-04T05:48:22Z

internal/csi-common/utils.go

+	err := s.ServerStream.RecvMsg(req)
+	if err != nil {
+		klog.Errorf(log.Log(s.ctx, "GRPC error: %v"), err)
+	}


Move this line to last so that request is logged first followed by error

https://github.com/grpc-ecosystem/go-grpc-middleware/blob/cc754e60cb814827ec3915e8e27c9822d7856745/interceptors/validator/interceptors.go#L67-L75

Moved the error log to last.
But RecvMsg needs to called first to fill in the req object in order to be able to extract reqID.
Added example logs to pr description .

PTAL

nixpanic · 2025-07-04T13:21:23Z

/test ci/centos/mini-e2e/k8s-1.30

nixpanic · 2025-07-04T13:25:07Z

/test ci/centos/mini-e2e/k8s-1.30

Madhu-1

small nits.

Madhu-1 · 2025-07-08T06:47:21Z

internal/csi-common/utils.go

+// NewMiddlewareStreamServerOptions creates a new grpc.ServerOption that configures a
+// common format for log messages and other gRPC related handlers.


Can you please update the comment to specify this is for Stream one

Madhu-1 · 2025-07-08T06:48:06Z

internal/csi-common/utils.go

+func (s *wrapperServerStream) Context() context.Context {
+	return s.ctx
+}


what is the use of this helper?

what is the use of this helper?

This wraps around the ServerStream so that so to provide this context with additional details(ID, ReqID).

example

https://github.com/grpc-ecosystem/go-grpc-middleware/blob/cc754e60cb814827ec3915e8e27c9822d7856745/wrappers.go#L19-L22

Modified the function definition to explain it better now.

nixpanic · 2025-07-08T16:07:38Z

@Mergifyio rebase

This commit adds stream server interceptor to inject additional logging details. Signed-off-by: Rakshith R <rar@redhat.com>

mergify · 2025-07-08T16:08:19Z

rebase

✅ Branch has been successfully rebased

nixpanic · 2025-07-08T16:08:22Z

@Mergifyio queue

mergify · 2025-07-08T16:08:52Z

queue

🛑 The pull request has been removed from the queue `default`

The merge conditions cannot be satisfied due to failing checks.

You can take a look at Queue: Embarked in merge queue check runs for more details about the failure.

ceph-csi-bot · 2025-07-08T16:09:06Z

/test ci/centos/upgrade-tests-cephfs

ceph-csi-bot · 2025-07-08T16:09:07Z

/test ci/centos/upgrade-tests-rbd

ceph-csi-bot · 2025-07-08T16:09:08Z

/test ci/centos/k8s-e2e-external-storage/1.31

ceph-csi-bot · 2025-07-08T16:09:09Z

/test ci/centos/k8s-e2e-external-storage/1.32

ceph-csi-bot · 2025-07-08T16:09:09Z

/test ci/centos/mini-e2e-helm/k8s-1.31

ceph-csi-bot · 2025-07-08T16:09:09Z

/test ci/centos/mini-e2e-helm/k8s-1.32

ceph-csi-bot · 2025-07-08T16:09:10Z

/test ci/centos/mini-e2e/k8s-1.31

ceph-csi-bot · 2025-07-08T16:09:10Z

/test ci/centos/mini-e2e/k8s-1.32

ceph-csi-bot · 2025-07-08T16:09:28Z

/test ci/centos/k8s-e2e-external-storage/1.33

ceph-csi-bot · 2025-07-08T16:09:29Z

/test ci/centos/mini-e2e-helm/k8s-1.33

ceph-csi-bot · 2025-07-08T16:09:30Z

/test ci/centos/mini-e2e/k8s-1.33

mergify · 2025-07-08T16:10:12Z

This pull request has been removed from the queue for the following reason: checks failed.

The merge conditions cannot be satisfied due to failing checks:

You may have to fix your CI before adding the pull request to the queue again.
If you update this pull request, to fix the CI, it will automatically be requeued once the queue conditions match again.
If you think this was a flaky issue instead, you can requeue the pull request, without updating it, by posting a @mergifyio requeue comment.

iPraveenParihar · 2025-07-09T06:30:46Z

/retest ci/centos/k8s-e2e-external-storage/1.31

iPraveenParihar · 2025-07-09T06:30:56Z

/retest ci/centos/mini-e2e-helm/k8s-1.32

iPraveenParihar · 2025-07-09T06:31:06Z

/retest ci/centos/mini-e2e/k8s-1.31

iPraveenParihar · 2025-07-09T06:31:14Z

/retest ci/centos/mini-e2e/k8s-1.32

nixpanic · 2025-07-09T08:45:30Z

@Mergifyio requeue

mergify · 2025-07-09T08:45:34Z

requeue

✅ The queue state of this pull request has been cleaned. It can be re-embarked automatically

Rakshith-R requested review from a team July 4, 2025 05:23

mergify bot added the component/rbd Issues related to RBD label Jul 4, 2025

Rakshith-R force-pushed the add-cbt-stream-logs branch from d8f587f to db02f74 Compare July 4, 2025 05:41

Madhu-1 requested changes Jul 4, 2025

View reviewed changes

Rakshith-R force-pushed the add-cbt-stream-logs branch from db02f74 to b1ecbd8 Compare July 8, 2025 05:28

Rakshith-R requested a review from Madhu-1 July 8, 2025 05:36

Rakshith-R force-pushed the add-cbt-stream-logs branch 2 times, most recently from 92f8758 to 7e69c5f Compare July 8, 2025 06:26

Madhu-1 reviewed Jul 8, 2025

View reviewed changes

Rakshith-R force-pushed the add-cbt-stream-logs branch 2 times, most recently from 5c2b485 to efafa7d Compare July 8, 2025 07:07

Rakshith-R requested a review from Madhu-1 July 8, 2025 07:08

Madhu-1 approved these changes Jul 8, 2025

View reviewed changes

Rakshith-R requested review from a team and nixpanic July 8, 2025 11:08

nixpanic approved these changes Jul 8, 2025

View reviewed changes

rbd: add additional logging details for stream server

4fc0ec4

This commit adds stream server interceptor to inject additional logging details. Signed-off-by: Rakshith R <rar@redhat.com>

nixpanic force-pushed the add-cbt-stream-logs branch from efafa7d to 4fc0ec4 Compare July 8, 2025 16:08

mergify bot added the ok-to-test Label to trigger E2E tests label Jul 8, 2025

ceph-csi-bot removed the ok-to-test Label to trigger E2E tests label Jul 8, 2025

mergify bot merged commit 17ec8f8 into ceph:devel Jul 9, 2025
46 of 49 checks passed

Rakshith-R mentioned this pull request Sep 1, 2025

Add support for Changed Block Tracking feature #5346

Open

4 tasks

		// NewMiddlewareStreamServerOptions creates a new grpc.ServerOption that configures a
		// common format for log messages and other gRPC related handlers.

rbd: add additional logging details for stream server #5411

rbd: add additional logging details for stream server #5411

Uh oh!

Conversation

Rakshith-R commented Jul 4, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Describe what this PR does

Related issues

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

nixpanic commented Jul 4, 2025

Uh oh!

nixpanic commented Jul 4, 2025

Uh oh!

Madhu-1 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

nixpanic commented Jul 8, 2025

Uh oh!

mergify bot commented Jul 8, 2025

✅ Branch has been successfully rebased

Uh oh!

nixpanic commented Jul 8, 2025

Uh oh!

mergify bot commented Jul 8, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

🛑 The pull request has been removed from the queue default

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

ceph-csi-bot commented Jul 8, 2025

Uh oh!

mergify bot commented Jul 8, 2025

Uh oh!

iPraveenParihar commented Jul 9, 2025

Uh oh!

iPraveenParihar commented Jul 9, 2025

Uh oh!

iPraveenParihar commented Jul 9, 2025

Uh oh!

iPraveenParihar commented Jul 9, 2025

Uh oh!

nixpanic commented Jul 9, 2025

Rakshith-R commented Jul 4, 2025 •

edited

Loading

mergify bot commented Jul 8, 2025 •

edited

Loading

🛑 The pull request has been removed from the queue `default`