I0810 22:30:41.331367       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0810 22:30:41.331519       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0810 22:30:41.331543       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0810 22:30:41.331549       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0810 22:30:41.331553       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0810 22:30:41.331557       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0810 22:30:41.331563       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0810 22:30:41.331569       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0810 22:30:41.331575       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0810 22:30:41.331580       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0810 22:30:41.331952       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0810 22:30:41.331966       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0810 22:30:44.236161       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:44.238158       1 utils.go:199] ID: 1 GRPC request: {}
I0810 22:30:44.238239       1 utils.go:205] ID: 1 GRPC response: {}
I0810 22:30:44.241484       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0810 22:30:44.241571       1 utils.go:199] ID: 2 GRPC request: {}
I0810 22:30:44.241589       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0810 22:30:44.241642       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0810 22:30:44.243611       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:44.243663       1 utils.go:199] ID: 3 GRPC request: {}
I0810 22:30:44.243683       1 utils.go:205] ID: 3 GRPC response: {}
I0810 22:30:44.244445       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0810 22:30:44.244526       1 utils.go:199] ID: 4 GRPC request: {}
I0810 22:30:44.244712       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0810 22:30:44.245894       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:44.245943       1 utils.go:199] ID: 5 GRPC request: {}
I0810 22:30:44.245949       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0810 22:30:44.246068       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}}}]}
I0810 22:30:46.627518       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:46.627625       1 utils.go:199] ID: 6 GRPC request: {}
I0810 22:30:46.627659       1 utils.go:205] ID: 6 GRPC response: {}
I0810 22:30:46.631605       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0810 22:30:46.631643       1 utils.go:199] ID: 7 GRPC request: {}
I0810 22:30:46.631687       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0810 22:30:46.631770       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0810 22:30:46.634683       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:46.634708       1 utils.go:199] ID: 8 GRPC request: {}
I0810 22:30:46.634753       1 utils.go:205] ID: 8 GRPC response: {}
I0810 22:30:46.635299       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0810 22:30:46.635401       1 utils.go:199] ID: 9 GRPC request: {}
I0810 22:30:46.635521       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0810 22:30:46.636136       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:46.636153       1 utils.go:199] ID: 10 GRPC request: {}
I0810 22:30:46.636160       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0810 22:30:46.636282       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}}}]}
I0810 22:30:46.636940       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:46.636970       1 utils.go:199] ID: 11 GRPC request: {}
I0810 22:30:46.636976       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0810 22:30:46.637123       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}}}]}
I0810 22:30:46.638260       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:46.638304       1 utils.go:199] ID: 12 GRPC request: {}
I0810 22:30:46.638375       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0810 22:30:46.638504       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}}}]}
I0810 22:30:47.894071       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0810 22:30:47.894187       1 utils.go:199] ID: 13 GRPC request: {}
I0810 22:30:47.894236       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0810 22:30:47.894329       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0810 22:30:47.897232       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:47.897272       1 utils.go:199] ID: 14 GRPC request: {}
I0810 22:30:47.897319       1 utils.go:205] ID: 14 GRPC response: {}
I0810 22:30:47.898100       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:47.898174       1 utils.go:199] ID: 15 GRPC request: {}
I0810 22:30:47.898200       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0810 22:30:47.898539       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}}}]}
I0810 22:30:49.204691       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:49.204747       1 utils.go:199] ID: 16 GRPC request: {}
I0810 22:30:49.204764       1 utils.go:205] ID: 16 GRPC response: {}
I0810 22:30:49.214470       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0810 22:30:49.214504       1 utils.go:199] ID: 17 GRPC request: {}
I0810 22:30:49.214515       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0810 22:30:49.214547       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0810 22:30:49.216821       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0810 22:30:49.216911       1 utils.go:199] ID: 18 GRPC request: {}
I0810 22:30:49.216952       1 utils.go:205] ID: 18 GRPC response: {}
I0810 22:30:49.218968       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0810 22:30:49.218999       1 utils.go:199] ID: 19 GRPC request: {}
I0810 22:30:49.219153       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0810 22:30:49.225571       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0810 22:30:49.225608       1 utils.go:199] ID: 20 GRPC request: {}
I0810 22:30:49.225620       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0810 22:30:49.225745       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}}}]}
I0810 22:31:49.452179       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0810 22:31:49.452230       1 utils.go:199] ID: 21 GRPC request: {}
I0810 22:31:49.452269       1 utils.go:205] ID: 21 GRPC response: {}
I0810 22:32:49.397332       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0810 22:32:49.397875       1 utils.go:199] ID: 22 GRPC request: {}
I0810 22:32:49.397921       1 utils.go:205] ID: 22 GRPC response: {}
I0810 22:33:42.075436       1 utils.go:198] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 GRPC call: /csi.v1.Controller/CreateVolume
I0810 22:33:42.075880       1 utils.go:199] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-234f1450-30aa-4cd3-9d30-b0a021f05728","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-234f1450-30aa-4cd3-9d30-b0a021f05728","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}}]}
I0810 22:33:42.076201       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0810 22:33:42.094898       1 omap.go:80] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0810 22:33:42.105880       1 omap.go:159] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-234f1450-30aa-4cd3-9d30-b0a021f05728:95a5827a-5aaa-4340-a5a8-9352c4736005])
I0810 22:33:42.108858       1 omap.go:159] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 set omap keys (pool="kube", namespace="", name="csi.volume.95a5827a-5aaa-4340-a5a8-9352c4736005"): map[csi.imagename:csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005 csi.volname:pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 csi.volume.owner:default])
I0810 22:33:42.108968       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-95a5827a-5aaa-4340-a5a8-9352c4736005) and image name (csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005) for request name (pvc-234f1450-30aa-4cd3-9d30-b0a021f05728)
I0810 22:33:42.109218       1 rbd_util.go:423] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 rbd: create kube/csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005 size 5120M (features: [layering]) using mon 199.19.213.235
I0810 22:33:42.109335       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 setting image options on kube/csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005
I0810 22:33:42.130621       1 controllerserver.go:763] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 created image kube/csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005 backed for request name pvc-234f1450-30aa-4cd3-9d30-b0a021f05728
I0810 22:33:42.154168       1 omap.go:159] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 set omap keys (pool="kube", namespace="", name="csi.volume.95a5827a-5aaa-4340-a5a8-9352c4736005"): map[csi.imageid:38044715197e])
I0810 22:33:42.217634       1 utils.go:205] ID: 23 Req-ID: pvc-234f1450-30aa-4cd3-9d30-b0a021f05728 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-95a5827a-5aaa-4340-a5a8-9352c4736005","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-95a5827a-5aaa-4340-a5a8-9352c4736005"}}
I0810 22:33:49.393509       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0810 22:33:49.393561       1 utils.go:199] ID: 24 GRPC request: {}
I0810 22:33:49.393585       1 utils.go:205] ID: 24 GRPC response: {}