I0527 09:55:43.977666       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0527 09:55:43.977869       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0527 09:55:43.977925       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0527 09:55:43.977940       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0527 09:55:43.977952       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0527 09:55:43.977964       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0527 09:55:43.977991       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0527 09:55:43.978003       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0527 09:55:43.978016       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0527 09:55:43.978033       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0527 09:55:43.978349       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0527 09:55:43.978440       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0527 09:55:45.939438       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:45.941414       1 utils.go:199] ID: 1 GRPC request: {}
I0527 09:55:45.941516       1 utils.go:205] ID: 1 GRPC response: {}
I0527 09:55:45.946154       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 09:55:45.946211       1 utils.go:199] ID: 2 GRPC request: {}
I0527 09:55:45.946230       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0527 09:55:45.946274       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 09:55:45.947847       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:45.947893       1 utils.go:199] ID: 3 GRPC request: {}
I0527 09:55:45.947908       1 utils.go:205] ID: 3 GRPC response: {}
I0527 09:55:45.948507       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 09:55:45.948587       1 utils.go:199] ID: 4 GRPC request: {}
I0527 09:55:45.948776       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 09:55:45.949784       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:45.949844       1 utils.go:199] ID: 5 GRPC request: {}
I0527 09:55:45.949853       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0527 09:55:45.950031       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 09:55:47.186154       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:47.186244       1 utils.go:199] ID: 6 GRPC request: {}
I0527 09:55:47.186297       1 utils.go:205] ID: 6 GRPC response: {}
I0527 09:55:47.189438       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 09:55:47.189509       1 utils.go:199] ID: 7 GRPC request: {}
I0527 09:55:47.189535       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0527 09:55:47.189580       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 09:55:47.191018       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:47.191066       1 utils.go:199] ID: 8 GRPC request: {}
I0527 09:55:47.191096       1 utils.go:205] ID: 8 GRPC response: {}
I0527 09:55:47.191602       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 09:55:47.191645       1 utils.go:199] ID: 9 GRPC request: {}
I0527 09:55:47.191763       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 09:55:47.192397       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:47.192431       1 utils.go:199] ID: 10 GRPC request: {}
I0527 09:55:47.192443       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0527 09:55:47.192519       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 09:55:47.193015       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:47.193055       1 utils.go:199] ID: 11 GRPC request: {}
I0527 09:55:47.193064       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0527 09:55:47.193146       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 09:55:47.193567       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:47.193586       1 utils.go:199] ID: 12 GRPC request: {}
I0527 09:55:47.193592       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0527 09:55:47.193644       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 09:55:49.649014       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 09:55:49.649051       1 utils.go:199] ID: 13 GRPC request: {}
I0527 09:55:49.649059       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0527 09:55:49.649111       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 09:55:49.653238       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:49.653281       1 utils.go:199] ID: 14 GRPC request: {}
I0527 09:55:49.653302       1 utils.go:205] ID: 14 GRPC response: {}
I0527 09:55:49.653845       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:49.653943       1 utils.go:199] ID: 15 GRPC request: {}
I0527 09:55:49.653995       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0527 09:55:49.654161       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 09:55:51.333642       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:51.333678       1 utils.go:199] ID: 16 GRPC request: {}
I0527 09:55:51.333693       1 utils.go:205] ID: 16 GRPC response: {}
I0527 09:55:51.335903       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0527 09:55:51.335926       1 utils.go:199] ID: 17 GRPC request: {}
I0527 09:55:51.335934       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0527 09:55:51.335957       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0527 09:55:51.337535       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0527 09:55:51.337564       1 utils.go:199] ID: 18 GRPC request: {}
I0527 09:55:51.337575       1 utils.go:205] ID: 18 GRPC response: {}
I0527 09:55:51.337859       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0527 09:55:51.337878       1 utils.go:199] ID: 19 GRPC request: {}
I0527 09:55:51.337964       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0527 09:55:51.338508       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0527 09:55:51.338528       1 utils.go:199] ID: 20 GRPC request: {}
I0527 09:55:51.338536       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0527 09:55:51.338594       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 09:56:51.502019       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0527 09:56:51.502068       1 utils.go:199] ID: 21 GRPC request: {}
I0527 09:56:51.502089       1 utils.go:205] ID: 21 GRPC response: {}
I0527 09:57:51.503000       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0527 09:57:51.503069       1 utils.go:199] ID: 22 GRPC request: {}
I0527 09:57:51.503100       1 utils.go:205] ID: 22 GRPC response: {}
I0527 09:58:51.501730       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0527 09:58:51.501806       1 utils.go:199] ID: 23 GRPC request: {}
I0527 09:58:51.501830       1 utils.go:205] ID: 23 GRPC response: {}
I0527 09:59:34.490206       1 utils.go:198] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a GRPC call: /csi.v1.Controller/CreateVolume
I0527 09:59:34.490759       1 utils.go:199] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-94637141-f294-433c-865b-deff11650b7a","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-94637141-f294-433c-865b-deff11650b7a","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 09:59:34.491455       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a setting disableInUseChecks: false image features: [layering] mounter: rbd
E0527 09:59:34.508593       1 omap.go:80] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0527 09:59:34.526222       1 omap.go:159] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-94637141-f294-433c-865b-deff11650b7a:b9981e63-501d-4dd9-9537-878219240759])
I0527 09:59:34.534074       1 omap.go:159] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a set omap keys (pool="kube", namespace="", name="csi.volume.b9981e63-501d-4dd9-9537-878219240759"): map[csi.imagename:csi-vol-b9981e63-501d-4dd9-9537-878219240759 csi.volname:pvc-94637141-f294-433c-865b-deff11650b7a csi.volume.owner:default])
I0527 09:59:34.534131       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b9981e63-501d-4dd9-9537-878219240759) and image name (csi-vol-b9981e63-501d-4dd9-9537-878219240759) for request name (pvc-94637141-f294-433c-865b-deff11650b7a)
I0527 09:59:34.534272       1 rbd_util.go:423] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a rbd: create kube/csi-vol-b9981e63-501d-4dd9-9537-878219240759 size 5120M (features: [layering]) using mon 199.19.213.156
I0527 09:59:34.534407       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a setting image options on kube/csi-vol-b9981e63-501d-4dd9-9537-878219240759
I0527 09:59:34.567126       1 controllerserver.go:763] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a created image kube/csi-vol-b9981e63-501d-4dd9-9537-878219240759 backed for request name pvc-94637141-f294-433c-865b-deff11650b7a
I0527 09:59:34.607140       1 omap.go:159] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a set omap keys (pool="kube", namespace="", name="csi.volume.b9981e63-501d-4dd9-9537-878219240759"): map[csi.imageid:37ed226800f3])
I0527 09:59:34.704175       1 utils.go:205] ID: 24 Req-ID: pvc-94637141-f294-433c-865b-deff11650b7a GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-b9981e63-501d-4dd9-9537-878219240759","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b9981e63-501d-4dd9-9537-878219240759"}}
I0527 09:59:51.511788       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0527 09:59:51.511826       1 utils.go:199] ID: 25 GRPC request: {}
I0527 09:59:51.511841       1 utils.go:205] ID: 25 GRPC response: {}