I0428 13:52:27.125828       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0428 13:52:27.125955       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0428 13:52:27.125967       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0428 13:52:27.125972       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0428 13:52:27.125975       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0428 13:52:27.125977       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0428 13:52:27.125981       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0428 13:52:27.125984       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0428 13:52:27.126136       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0428 13:52:27.126157       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0428 13:52:27.126580       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0428 13:52:27.126587       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0428 13:52:35.254929       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:35.256328       1 utils.go:199] ID: 1 GRPC request: {}
I0428 13:52:35.256421       1 utils.go:205] ID: 1 GRPC response: {}
I0428 13:52:35.258639       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:52:35.258727       1 utils.go:199] ID: 2 GRPC request: {}
I0428 13:52:35.258783       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0428 13:52:35.258882       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:52:35.265292       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:35.265398       1 utils.go:199] ID: 3 GRPC request: {}
I0428 13:52:35.265457       1 utils.go:205] ID: 3 GRPC response: {}
I0428 13:52:35.266226       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:52:35.266310       1 utils.go:199] ID: 4 GRPC request: {}
I0428 13:52:35.266519       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:52:35.267561       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:35.267862       1 utils.go:199] ID: 5 GRPC request: {}
I0428 13:52:35.267944       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0428 13:52:35.268250       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}}}]}
I0428 13:52:37.027694       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:37.027754       1 utils.go:199] ID: 6 GRPC request: {}
I0428 13:52:37.027849       1 utils.go:205] ID: 6 GRPC response: {}
I0428 13:52:37.031612       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:52:37.031643       1 utils.go:199] ID: 7 GRPC request: {}
I0428 13:52:37.031650       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0428 13:52:37.031763       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:52:37.033703       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:37.033740       1 utils.go:199] ID: 8 GRPC request: {}
I0428 13:52:37.033766       1 utils.go:205] ID: 8 GRPC response: {}
I0428 13:52:37.034834       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:52:37.034906       1 utils.go:199] ID: 9 GRPC request: {}
I0428 13:52:37.035143       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:52:37.036003       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:37.036044       1 utils.go:199] ID: 10 GRPC request: {}
I0428 13:52:37.036080       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0428 13:52:37.036289       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}}}]}
I0428 13:52:37.037143       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:37.037176       1 utils.go:199] ID: 11 GRPC request: {}
I0428 13:52:37.037186       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0428 13:52:37.037359       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}}}]}
I0428 13:52:37.037821       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:37.037856       1 utils.go:199] ID: 12 GRPC request: {}
I0428 13:52:37.037866       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0428 13:52:37.038004       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}}}]}
I0428 13:52:39.165749       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:52:39.165789       1 utils.go:199] ID: 13 GRPC request: {}
I0428 13:52:39.165800       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0428 13:52:39.165831       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:52:39.168069       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:39.168111       1 utils.go:199] ID: 14 GRPC request: {}
I0428 13:52:39.168132       1 utils.go:205] ID: 14 GRPC response: {}
I0428 13:52:39.169757       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:39.169871       1 utils.go:199] ID: 15 GRPC request: {}
I0428 13:52:39.169941       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0428 13:52:39.170205       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}}}]}
I0428 13:52:41.215564       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:41.215633       1 utils.go:199] ID: 16 GRPC request: {}
I0428 13:52:41.215683       1 utils.go:205] ID: 16 GRPC response: {}
I0428 13:52:41.218825       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:52:41.218911       1 utils.go:199] ID: 17 GRPC request: {}
I0428 13:52:41.218991       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0428 13:52:41.219142       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:52:41.221368       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0428 13:52:41.221389       1 utils.go:199] ID: 18 GRPC request: {}
I0428 13:52:41.221403       1 utils.go:205] ID: 18 GRPC response: {}
I0428 13:52:41.221814       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:52:41.221836       1 utils.go:199] ID: 19 GRPC request: {}
I0428 13:52:41.222048       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:52:41.222693       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:52:41.222848       1 utils.go:199] ID: 20 GRPC request: {}
I0428 13:52:41.222883       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0428 13:52:41.222980       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}}}]}
I0428 13:53:41.671157       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0428 13:53:41.671343       1 utils.go:199] ID: 21 GRPC request: {}
I0428 13:53:41.671463       1 utils.go:205] ID: 21 GRPC response: {}
I0428 13:54:41.672775       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0428 13:54:41.672913       1 utils.go:199] ID: 22 GRPC request: {}
I0428 13:54:41.672984       1 utils.go:205] ID: 22 GRPC response: {}
I0428 13:55:41.723698       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:41.723806       1 utils.go:199] ID: 23 GRPC request: {}
I0428 13:55:41.723858       1 utils.go:205] ID: 23 GRPC response: {}
I0428 13:55:46.912844       1 utils.go:198] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 GRPC call: /csi.v1.Controller/CreateVolume
I0428 13:55:46.913416       1 utils.go:199] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-fcda1f87-69be-4a03-b216-97c25328dc33","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-fcda1f87-69be-4a03-b216-97c25328dc33","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}}]}
I0428 13:55:46.913755       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0428 13:55:46.931186       1 omap.go:80] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0428 13:55:46.947147       1 omap.go:159] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-fcda1f87-69be-4a03-b216-97c25328dc33:6961b154-aea9-45b9-9fd1-76a21a7c04d1])
I0428 13:55:46.956580       1 omap.go:159] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 set omap keys (pool="kube", namespace="", name="csi.volume.6961b154-aea9-45b9-9fd1-76a21a7c04d1"): map[csi.imagename:csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1 csi.volname:pvc-fcda1f87-69be-4a03-b216-97c25328dc33 csi.volume.owner:default])
I0428 13:55:46.956616       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6961b154-aea9-45b9-9fd1-76a21a7c04d1) and image name (csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1) for request name (pvc-fcda1f87-69be-4a03-b216-97c25328dc33)
I0428 13:55:46.956692       1 rbd_util.go:423] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 rbd: create kube/csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1 size 5120M (features: [layering]) using mon 199.204.45.132
I0428 13:55:46.956729       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 setting image options on kube/csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1
I0428 13:55:48.983641       1 controllerserver.go:763] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 created image kube/csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1 backed for request name pvc-fcda1f87-69be-4a03-b216-97c25328dc33
I0428 13:55:49.031120       1 omap.go:159] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 set omap keys (pool="kube", namespace="", name="csi.volume.6961b154-aea9-45b9-9fd1-76a21a7c04d1"): map[csi.imageid:37d9d0a32176])
I0428 13:55:49.157992       1 utils.go:205] ID: 24 Req-ID: pvc-fcda1f87-69be-4a03-b216-97c25328dc33 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6961b154-aea9-45b9-9fd1-76a21a7c04d1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6961b154-aea9-45b9-9fd1-76a21a7c04d1"}}
I0428 13:56:41.681296       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0428 13:56:41.681376       1 utils.go:199] ID: 25 GRPC request: {}
I0428 13:56:41.682352       1 utils.go:205] ID: 25 GRPC response: {}