I0212 22:46:26.460078       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0212 22:46:26.460319       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0212 22:46:26.460383       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0212 22:46:26.460432       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0212 22:46:26.460469       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0212 22:46:26.460513       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0212 22:46:26.460548       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0212 22:46:26.460591       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0212 22:46:26.460626       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0212 22:46:26.460670       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0212 22:46:26.460978       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0212 22:46:26.461058       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0212 22:46:30.898211       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:30.899815       1 utils.go:199] ID: 1 GRPC request: {}
I0212 22:46:30.900892       1 utils.go:205] ID: 1 GRPC response: {}
I0212 22:46:30.902882       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 22:46:30.903051       1 utils.go:199] ID: 2 GRPC request: {}
I0212 22:46:30.903093       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0212 22:46:30.903210       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 22:46:30.904329       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:30.904391       1 utils.go:199] ID: 3 GRPC request: {}
I0212 22:46:30.904462       1 utils.go:205] ID: 3 GRPC response: {}
I0212 22:46:30.904727       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 22:46:30.904806       1 utils.go:199] ID: 4 GRPC request: {}
I0212 22:46:30.904949       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 22:46:30.906639       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:30.906693       1 utils.go:199] ID: 5 GRPC request: {}
I0212 22:46:30.906718       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0212 22:46:30.906817       1 utils.go:205] ID: 5 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:46:33.309703       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:33.309860       1 utils.go:199] ID: 6 GRPC request: {}
I0212 22:46:33.309939       1 utils.go:205] ID: 6 GRPC response: {}
I0212 22:46:33.313195       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 22:46:33.313209       1 utils.go:199] ID: 7 GRPC request: {}
I0212 22:46:33.313214       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0212 22:46:33.313237       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 22:46:33.314604       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:33.314642       1 utils.go:199] ID: 8 GRPC request: {}
I0212 22:46:33.314677       1 utils.go:205] ID: 8 GRPC response: {}
I0212 22:46:33.315824       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 22:46:33.315853       1 utils.go:199] ID: 9 GRPC request: {}
I0212 22:46:33.315961       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 22:46:33.319605       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:33.319718       1 utils.go:199] ID: 10 GRPC request: {}
I0212 22:46:33.319786       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0212 22:46:33.319902       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:46:33.320563       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:33.320645       1 utils.go:199] ID: 11 GRPC request: {}
I0212 22:46:33.320696       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0212 22:46:33.320793       1 utils.go:205] ID: 11 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:46:33.321886       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:33.321920       1 utils.go:199] ID: 12 GRPC request: {}
I0212 22:46:33.321931       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0212 22:46:33.322006       1 utils.go:205] ID: 12 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:46:35.762118       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 22:46:35.762195       1 utils.go:199] ID: 13 GRPC request: {}
I0212 22:46:35.762241       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0212 22:46:35.762290       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 22:46:35.764463       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:35.764539       1 utils.go:199] ID: 14 GRPC request: {}
I0212 22:46:35.764601       1 utils.go:205] ID: 14 GRPC response: {}
I0212 22:46:35.764968       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:35.765054       1 utils.go:199] ID: 15 GRPC request: {}
I0212 22:46:35.765098       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0212 22:46:35.765238       1 utils.go:205] ID: 15 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:46:38.032716       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:38.032909       1 utils.go:199] ID: 16 GRPC request: {}
I0212 22:46:38.032943       1 utils.go:205] ID: 16 GRPC response: {}
I0212 22:46:38.036076       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 22:46:38.036150       1 utils.go:199] ID: 17 GRPC request: {}
I0212 22:46:38.036209       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0212 22:46:38.036293       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 22:46:38.041329       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0212 22:46:38.041343       1 utils.go:199] ID: 18 GRPC request: {}
I0212 22:46:38.041352       1 utils.go:205] ID: 18 GRPC response: {}
I0212 22:46:38.042767       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 22:46:38.042782       1 utils.go:199] ID: 19 GRPC request: {}
I0212 22:46:38.042857       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 22:46:38.043796       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 22:46:38.043811       1 utils.go:199] ID: 20 GRPC request: {}
I0212 22:46:38.043829       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0212 22:46:38.043904       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0212 22:47:38.228013       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0212 22:47:38.228130       1 utils.go:199] ID: 21 GRPC request: {}
I0212 22:47:38.228187       1 utils.go:205] ID: 21 GRPC response: {}
I0212 22:48:38.241249       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0212 22:48:38.241356       1 utils.go:199] ID: 22 GRPC request: {}
I0212 22:48:38.241397       1 utils.go:205] ID: 22 GRPC response: {}
I0212 22:49:32.555661       1 utils.go:198] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 GRPC call: /csi.v1.Controller/CreateVolume
I0212 22:49:32.556016       1 utils.go:199] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-282e62a0-5520-4074-b920-fc7c04341915","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-282e62a0-5520-4074-b920-fc7c04341915","csi.storage.k8s.io/pvc/name":"test-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"kube"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["discard"]}},"access_mode":{"mode":1}}]}
I0212 22:49:32.556313       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0212 22:49:32.578356       1 omap.go:80] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0212 22:49:32.598355       1 omap.go:159] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-282e62a0-5520-4074-b920-fc7c04341915:d566d08f-22eb-4942-a471-47f4bc210c1a])
I0212 22:49:32.604204       1 omap.go:159] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 set omap keys (pool="kube", namespace="", name="csi.volume.d566d08f-22eb-4942-a471-47f4bc210c1a"): map[csi.imagename:csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a csi.volname:pvc-282e62a0-5520-4074-b920-fc7c04341915 csi.volume.owner:default])
I0212 22:49:32.604240       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d566d08f-22eb-4942-a471-47f4bc210c1a) and image name (csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a) for request name (pvc-282e62a0-5520-4074-b920-fc7c04341915)
I0212 22:49:32.604488       1 rbd_util.go:423] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 rbd: create kube/csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a size 5120M (features: [layering]) using mon 162.253.55.200
I0212 22:49:32.604675       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 setting image options on kube/csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a
I0212 22:49:34.536872       1 controllerserver.go:763] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 created image kube/csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a backed for request name pvc-282e62a0-5520-4074-b920-fc7c04341915
I0212 22:49:34.562072       1 omap.go:159] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 set omap keys (pool="kube", namespace="", name="csi.volume.d566d08f-22eb-4942-a471-47f4bc210c1a"): map[csi.imageid:37d8a8d85088])
I0212 22:49:34.626541       1 utils.go:205] ID: 23 Req-ID: pvc-282e62a0-5520-4074-b920-fc7c04341915 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d566d08f-22eb-4942-a471-47f4bc210c1a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d566d08f-22eb-4942-a471-47f4bc210c1a"}}
I0212 22:49:38.227831       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0212 22:49:38.227903       1 utils.go:199] ID: 24 GRPC request: {}
I0212 22:49:38.228315       1 utils.go:205] ID: 24 GRPC response: {}