I0414 10:47:24.381515       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0414 10:47:24.381639       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0414 10:47:24.381655       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0414 10:47:24.381658       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0414 10:47:24.381661       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0414 10:47:24.381664       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0414 10:47:24.381668       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0414 10:47:24.381670       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0414 10:47:24.381673       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0414 10:47:24.381676       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0414 10:47:24.381977       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0414 10:47:24.382075       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0414 10:47:28.161826       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:28.163969       1 utils.go:199] ID: 1 GRPC request: {}
I0414 10:47:28.164201       1 utils.go:205] ID: 1 GRPC response: {}
I0414 10:47:28.168234       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0414 10:47:28.168341       1 utils.go:199] ID: 2 GRPC request: {}
I0414 10:47:28.168379       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0414 10:47:28.168444       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0414 10:47:28.169800       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:28.169826       1 utils.go:199] ID: 3 GRPC request: {}
I0414 10:47:28.169841       1 utils.go:205] ID: 3 GRPC response: {}
I0414 10:47:28.170243       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0414 10:47:28.170323       1 utils.go:199] ID: 4 GRPC request: {}
I0414 10:47:28.170466       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0414 10:47:28.171124       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:28.171324       1 utils.go:199] ID: 5 GRPC request: {}
I0414 10:47:28.171344       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0414 10:47:28.171660       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}}}]}
I0414 10:47:30.473423       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:30.473463       1 utils.go:199] ID: 6 GRPC request: {}
I0414 10:47:30.473486       1 utils.go:205] ID: 6 GRPC response: {}
I0414 10:47:30.476569       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0414 10:47:30.476606       1 utils.go:199] ID: 7 GRPC request: {}
I0414 10:47:30.476653       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0414 10:47:30.476729       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0414 10:47:30.478522       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:30.478544       1 utils.go:199] ID: 8 GRPC request: {}
I0414 10:47:30.478557       1 utils.go:205] ID: 8 GRPC response: {}
I0414 10:47:30.479452       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0414 10:47:30.479544       1 utils.go:199] ID: 9 GRPC request: {}
I0414 10:47:30.479768       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0414 10:47:30.481018       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:30.481200       1 utils.go:199] ID: 10 GRPC request: {}
I0414 10:47:30.481228       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0414 10:47:30.481500       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}}}]}
I0414 10:47:30.482295       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:30.482317       1 utils.go:199] ID: 11 GRPC request: {}
I0414 10:47:30.482327       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0414 10:47:30.482690       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}}}]}
I0414 10:47:30.483184       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:30.483240       1 utils.go:199] ID: 12 GRPC request: {}
I0414 10:47:30.483270       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0414 10:47:30.483369       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}}}]}
I0414 10:47:31.734636       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0414 10:47:31.734685       1 utils.go:199] ID: 13 GRPC request: {}
I0414 10:47:31.734696       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0414 10:47:31.734726       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0414 10:47:31.739394       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:31.739418       1 utils.go:199] ID: 14 GRPC request: {}
I0414 10:47:31.739432       1 utils.go:205] ID: 14 GRPC response: {}
I0414 10:47:31.739955       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:31.739992       1 utils.go:199] ID: 15 GRPC request: {}
I0414 10:47:31.740009       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0414 10:47:31.740155       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}}}]}
I0414 10:47:33.324780       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:33.324856       1 utils.go:199] ID: 16 GRPC request: {}
I0414 10:47:33.324883       1 utils.go:205] ID: 16 GRPC response: {}
I0414 10:47:33.332122       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0414 10:47:33.332208       1 utils.go:199] ID: 17 GRPC request: {}
I0414 10:47:33.332246       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0414 10:47:33.332311       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0414 10:47:33.334727       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0414 10:47:33.334761       1 utils.go:199] ID: 18 GRPC request: {}
I0414 10:47:33.334779       1 utils.go:205] ID: 18 GRPC response: {}
I0414 10:47:33.335211       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0414 10:47:33.335285       1 utils.go:199] ID: 19 GRPC request: {}
I0414 10:47:33.335399       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0414 10:47:33.336181       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0414 10:47:33.336205       1 utils.go:199] ID: 20 GRPC request: {}
I0414 10:47:33.336213       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0414 10:47:33.336317       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}}}]}
I0414 10:48:33.570009       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0414 10:48:33.570076       1 utils.go:199] ID: 21 GRPC request: {}
I0414 10:48:33.570259       1 utils.go:205] ID: 21 GRPC response: {}
I0414 10:49:33.523884       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0414 10:49:33.527820       1 utils.go:199] ID: 22 GRPC request: {}
I0414 10:49:33.527921       1 utils.go:205] ID: 22 GRPC response: {}
I0414 10:50:33.522418       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0414 10:50:33.522471       1 utils.go:199] ID: 23 GRPC request: {}
I0414 10:50:33.522500       1 utils.go:205] ID: 23 GRPC response: {}
I0414 10:50:36.754984       1 utils.go:198] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a GRPC call: /csi.v1.Controller/CreateVolume
I0414 10:50:36.755764       1 utils.go:199] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a","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}}]}
I0414 10:50:36.756241       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a setting disableInUseChecks: false image features: [layering] mounter: rbd
E0414 10:50:36.774487       1 omap.go:80] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0414 10:50:36.790868       1 omap.go:159] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a:56ad3e41-cec3-4e74-9f96-aaf6fd365b49])
I0414 10:50:36.796369       1 omap.go:159] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a set omap keys (pool="kube", namespace="", name="csi.volume.56ad3e41-cec3-4e74-9f96-aaf6fd365b49"): map[csi.imagename:csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49 csi.volname:pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a csi.volume.owner:default])
I0414 10:50:36.796526       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-56ad3e41-cec3-4e74-9f96-aaf6fd365b49) and image name (csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49) for request name (pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a)
I0414 10:50:36.796696       1 rbd_util.go:423] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a rbd: create kube/csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49 size 5120M (features: [layering]) using mon 199.204.45.205
I0414 10:50:36.796844       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a setting image options on kube/csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49
I0414 10:50:38.582602       1 controllerserver.go:763] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a created image kube/csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49 backed for request name pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a
I0414 10:50:38.615519       1 omap.go:159] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a set omap keys (pool="kube", namespace="", name="csi.volume.56ad3e41-cec3-4e74-9f96-aaf6fd365b49"): map[csi.imageid:37d925c9313c])
I0414 10:50:38.740201       1 utils.go:205] ID: 24 Req-ID: pvc-9447d857-823f-4d33-9b78-bf9c6b9dc29a GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-56ad3e41-cec3-4e74-9f96-aaf6fd365b49","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-56ad3e41-cec3-4e74-9f96-aaf6fd365b49"}}
I0414 10:51:33.535680       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0414 10:51:33.535717       1 utils.go:199] ID: 25 GRPC request: {}
I0414 10:51:33.535736       1 utils.go:205] ID: 25 GRPC response: {}