I0212 17:02:35.733828       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0212 17:02:35.734390       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0212 17:02:35.734471       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0212 17:02:35.734521       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0212 17:02:35.734560       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0212 17:02:35.734612       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0212 17:02:35.734691       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0212 17:02:35.734743       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0212 17:02:35.734798       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0212 17:02:35.734826       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0212 17:02:35.737334       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0212 17:02:35.737487       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0212 17:02:40.176339       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:40.177714       1 utils.go:199] ID: 1 GRPC request: {}
I0212 17:02:40.177830       1 utils.go:205] ID: 1 GRPC response: {}
I0212 17:02:40.198103       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:02:40.198354       1 utils.go:199] ID: 2 GRPC request: {}
I0212 17:02:40.198445       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0212 17:02:40.198707       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:02:40.203075       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:40.203190       1 utils.go:199] ID: 3 GRPC request: {}
I0212 17:02:40.203311       1 utils.go:205] ID: 3 GRPC response: {}
I0212 17:02:40.208903       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:02:40.209084       1 utils.go:199] ID: 4 GRPC request: {}
I0212 17:02:40.209488       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:02:40.210697       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:40.210883       1 utils.go:199] ID: 5 GRPC request: {}
I0212 17:02:40.210956       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0212 17:02:40.211126       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 17:02:43.113167       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:43.113315       1 utils.go:199] ID: 6 GRPC request: {}
I0212 17:02:43.113389       1 utils.go:205] ID: 6 GRPC response: {}
I0212 17:02:43.116653       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:02:43.116836       1 utils.go:199] ID: 7 GRPC request: {}
I0212 17:02:43.116859       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0212 17:02:43.116974       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:02:43.118577       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:43.118714       1 utils.go:199] ID: 8 GRPC request: {}
I0212 17:02:43.118788       1 utils.go:205] ID: 8 GRPC response: {}
I0212 17:02:43.119191       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:02:43.119945       1 utils.go:199] ID: 9 GRPC request: {}
I0212 17:02:43.120129       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:02:43.120703       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:43.120789       1 utils.go:199] ID: 10 GRPC request: {}
I0212 17:02:43.120852       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0212 17:02:43.121013       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 17:02:43.121385       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:43.121565       1 utils.go:199] ID: 11 GRPC request: {}
I0212 17:02:43.121639       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0212 17:02:43.121731       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 17:02:43.122092       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:43.122163       1 utils.go:199] ID: 12 GRPC request: {}
I0212 17:02:43.122198       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0212 17:02:43.122315       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 17:02:45.672214       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:02:45.672341       1 utils.go:199] ID: 13 GRPC request: {}
I0212 17:02:45.672400       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0212 17:02:45.672471       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:02:45.675649       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:45.675725       1 utils.go:199] ID: 14 GRPC request: {}
I0212 17:02:45.675797       1 utils.go:205] ID: 14 GRPC response: {}
I0212 17:02:45.676406       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:45.676547       1 utils.go:199] ID: 15 GRPC request: {}
I0212 17:02:45.676798       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0212 17:02:45.677051       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 17:02:47.948265       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:47.948394       1 utils.go:199] ID: 16 GRPC request: {}
I0212 17:02:47.948425       1 utils.go:205] ID: 16 GRPC response: {}
I0212 17:02:47.951864       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:02:47.951933       1 utils.go:199] ID: 17 GRPC request: {}
I0212 17:02:47.952028       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0212 17:02:47.952104       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:02:47.953620       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0212 17:02:47.953669       1 utils.go:199] ID: 18 GRPC request: {}
I0212 17:02:47.953695       1 utils.go:205] ID: 18 GRPC response: {}
I0212 17:02:47.954090       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:02:47.954323       1 utils.go:199] ID: 19 GRPC request: {}
I0212 17:02:47.954423       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:02:47.955117       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:02:47.955133       1 utils.go:199] ID: 20 GRPC request: {}
I0212 17:02:47.955212       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0212 17:02:47.955365       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 17:03:48.241363       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0212 17:03:48.241512       1 utils.go:199] ID: 21 GRPC request: {}
I0212 17:03:48.241564       1 utils.go:205] ID: 21 GRPC response: {}
I0212 17:04:48.252262       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0212 17:04:48.252348       1 utils.go:199] ID: 22 GRPC request: {}
I0212 17:04:48.252378       1 utils.go:205] ID: 22 GRPC response: {}
I0212 17:05:48.240012       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0212 17:05:48.240056       1 utils.go:199] ID: 23 GRPC request: {}
I0212 17:05:48.240072       1 utils.go:205] ID: 23 GRPC response: {}
I0212 17:05:51.385607       1 utils.go:198] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f GRPC call: /csi.v1.Controller/CreateVolume
I0212 17:05:51.387288       1 utils.go:199] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-64cc90a2-68ed-4663-a00d-6166c509402f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-64cc90a2-68ed-4663-a00d-6166c509402f","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 17:05:51.388099       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0212 17:05:51.410268       1 omap.go:80] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0212 17:05:51.424460       1 omap.go:159] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-64cc90a2-68ed-4663-a00d-6166c509402f:6fd6d030-8bff-4b1c-8353-ad91e647fb44])
I0212 17:05:51.431419       1 omap.go:159] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f set omap keys (pool="kube", namespace="", name="csi.volume.6fd6d030-8bff-4b1c-8353-ad91e647fb44"): map[csi.imagename:csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44 csi.volname:pvc-64cc90a2-68ed-4663-a00d-6166c509402f csi.volume.owner:default])
I0212 17:05:51.431452       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6fd6d030-8bff-4b1c-8353-ad91e647fb44) and image name (csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44) for request name (pvc-64cc90a2-68ed-4663-a00d-6166c509402f)
I0212 17:05:51.431545       1 rbd_util.go:423] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f rbd: create kube/csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44 size 5120M (features: [layering]) using mon 199.19.213.17
I0212 17:05:51.431701       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f setting image options on kube/csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44
I0212 17:05:53.565651       1 controllerserver.go:763] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f created image kube/csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44 backed for request name pvc-64cc90a2-68ed-4663-a00d-6166c509402f
I0212 17:05:53.759260       1 omap.go:159] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f set omap keys (pool="kube", namespace="", name="csi.volume.6fd6d030-8bff-4b1c-8353-ad91e647fb44"): map[csi.imageid:37d849b173dd])
I0212 17:05:54.424993       1 utils.go:205] ID: 24 Req-ID: pvc-64cc90a2-68ed-4663-a00d-6166c509402f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6fd6d030-8bff-4b1c-8353-ad91e647fb44","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6fd6d030-8bff-4b1c-8353-ad91e647fb44"}}
I0212 17:06:48.261437       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0212 17:06:48.261477       1 utils.go:199] ID: 25 GRPC request: {}
I0212 17:06:48.261492       1 utils.go:205] ID: 25 GRPC response: {}