I0527 06:05:49.549689       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0527 06:05:49.549818       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0527 06:05:49.549833       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0527 06:05:49.549853       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0527 06:05:49.549857       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0527 06:05:49.549860       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0527 06:05:49.549864       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0527 06:05:49.549867       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0527 06:05:49.549870       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0527 06:05:49.549878       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0527 06:05:49.550261       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0527 06:05:49.550353       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0527 06:05:51.721793       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:51.723145       1 utils.go:199] ID: 1 GRPC request: {}
I0527 06:05:51.723208       1 utils.go:205] ID: 1 GRPC response: {}
I0527 06:05:51.725790       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 06:05:51.725960       1 utils.go:199] ID: 2 GRPC request: {}
I0527 06:05:51.726067       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0527 06:05:51.726155       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 06:05:51.730963       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:51.731046       1 utils.go:199] ID: 3 GRPC request: {}
I0527 06:05:51.731075       1 utils.go:205] ID: 3 GRPC response: {}
I0527 06:05:51.731850       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 06:05:51.731975       1 utils.go:199] ID: 4 GRPC request: {}
I0527 06:05:51.732199       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 06:05:51.733096       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:51.733147       1 utils.go:199] ID: 5 GRPC request: {}
I0527 06:05:51.733157       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0527 06:05:51.733345       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}}}]}
I0527 06:05:54.322407       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:54.322443       1 utils.go:199] ID: 6 GRPC request: {}
I0527 06:05:54.322459       1 utils.go:205] ID: 6 GRPC response: {}
I0527 06:05:54.330110       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 06:05:54.330181       1 utils.go:199] ID: 7 GRPC request: {}
I0527 06:05:54.330197       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0527 06:05:54.330232       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 06:05:54.333721       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:54.333753       1 utils.go:199] ID: 8 GRPC request: {}
I0527 06:05:54.333768       1 utils.go:205] ID: 8 GRPC response: {}
I0527 06:05:54.334266       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 06:05:54.334299       1 utils.go:199] ID: 9 GRPC request: {}
I0527 06:05:54.334427       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 06:05:54.335193       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:54.335223       1 utils.go:199] ID: 10 GRPC request: {}
I0527 06:05:54.335234       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0527 06:05:54.335392       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}}}]}
I0527 06:05:54.335882       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:54.335902       1 utils.go:199] ID: 11 GRPC request: {}
I0527 06:05:54.335909       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0527 06:05:54.335969       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}}}]}
I0527 06:05:54.338453       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:54.338483       1 utils.go:199] ID: 12 GRPC request: {}
I0527 06:05:54.338493       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0527 06:05:54.338653       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}}}]}
I0527 06:05:55.495179       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 06:05:55.495283       1 utils.go:199] ID: 13 GRPC request: {}
I0527 06:05:55.495351       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0527 06:05:55.495417       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 06:05:55.497333       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:55.497379       1 utils.go:199] ID: 14 GRPC request: {}
I0527 06:05:55.497409       1 utils.go:205] ID: 14 GRPC response: {}
I0527 06:05:55.497918       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:55.497956       1 utils.go:199] ID: 15 GRPC request: {}
I0527 06:05:55.497965       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0527 06:05:55.498072       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}}}]}
I0527 06:05:56.756367       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:56.756426       1 utils.go:199] ID: 16 GRPC request: {}
I0527 06:05:56.756457       1 utils.go:205] ID: 16 GRPC response: {}
I0527 06:05:56.758935       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 06:05:56.758969       1 utils.go:199] ID: 17 GRPC request: {}
I0527 06:05:56.758980       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0527 06:05:56.759028       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 06:05:56.764097       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0527 06:05:56.764122       1 utils.go:199] ID: 18 GRPC request: {}
I0527 06:05:56.764143       1 utils.go:205] ID: 18 GRPC response: {}
I0527 06:05:56.764460       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 06:05:56.764486       1 utils.go:199] ID: 19 GRPC request: {}
I0527 06:05:56.764607       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 06:05:56.765223       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 06:05:56.765248       1 utils.go:199] ID: 20 GRPC request: {}
I0527 06:05:56.765266       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0527 06:05:56.765360       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}}}]}
I0527 06:06:56.988109       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0527 06:06:56.988177       1 utils.go:199] ID: 21 GRPC request: {}
I0527 06:06:56.988200       1 utils.go:205] ID: 21 GRPC response: {}
I0527 06:07:56.940684       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0527 06:07:56.940748       1 utils.go:199] ID: 22 GRPC request: {}
I0527 06:07:56.940772       1 utils.go:205] ID: 22 GRPC response: {}
I0527 06:08:56.940205       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0527 06:08:56.940266       1 utils.go:199] ID: 23 GRPC request: {}
I0527 06:08:56.940286       1 utils.go:205] ID: 23 GRPC response: {}
I0527 06:09:39.871239       1 utils.go:198] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c GRPC call: /csi.v1.Controller/CreateVolume
I0527 06:09:39.871974       1 utils.go:199] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c","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}}]}
I0527 06:09:39.872269       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c setting disableInUseChecks: false image features: [layering] mounter: rbd
E0527 06:09:39.892666       1 omap.go:80] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0527 06:09:39.910315       1 omap.go:159] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c:765adcb7-1dbd-41dc-898f-a32b1f1dda80])
I0527 06:09:39.915963       1 omap.go:159] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c set omap keys (pool="kube", namespace="", name="csi.volume.765adcb7-1dbd-41dc-898f-a32b1f1dda80"): map[csi.imagename:csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80 csi.volname:pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c csi.volume.owner:default])
I0527 06:09:39.915988       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-765adcb7-1dbd-41dc-898f-a32b1f1dda80) and image name (csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80) for request name (pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c)
I0527 06:09:39.916041       1 rbd_util.go:423] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c rbd: create kube/csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80 size 5120M (features: [layering]) using mon 199.19.213.11
I0527 06:09:39.916076       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c setting image options on kube/csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80
I0527 06:09:39.948487       1 controllerserver.go:763] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c created image kube/csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80 backed for request name pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c
I0527 06:09:39.981351       1 omap.go:159] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c set omap keys (pool="kube", namespace="", name="csi.volume.765adcb7-1dbd-41dc-898f-a32b1f1dda80"): map[csi.imageid:37edef45c98b])
I0527 06:09:40.078409       1 utils.go:205] ID: 24 Req-ID: pvc-55632650-e770-4c4d-90a8-17db1f5a9f4c GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-765adcb7-1dbd-41dc-898f-a32b1f1dda80","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-765adcb7-1dbd-41dc-898f-a32b1f1dda80"}}
I0527 06:09:56.952184       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0527 06:09:56.952277       1 utils.go:199] ID: 25 GRPC request: {}
I0527 06:09:56.952302       1 utils.go:205] ID: 25 GRPC response: {}