I0524 07:17:52.766219       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0524 07:17:52.766343       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0524 07:17:52.766358       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0524 07:17:52.766363       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0524 07:17:52.766367       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0524 07:17:52.766369       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0524 07:17:52.766373       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0524 07:17:52.766375       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0524 07:17:52.766378       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0524 07:17:52.766381       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0524 07:17:52.766729       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0524 07:17:52.766745       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0524 07:17:55.235526       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0524 07:17:55.238025       1 utils.go:199] ID: 1 GRPC request: {}
I0524 07:17:55.238303       1 utils.go:205] ID: 1 GRPC response: {}
I0524 07:17:55.244530       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0524 07:17:55.244694       1 utils.go:199] ID: 2 GRPC request: {}
I0524 07:17:55.244724       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0524 07:17:55.244829       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0524 07:17:55.247478       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0524 07:17:55.247534       1 utils.go:199] ID: 3 GRPC request: {}
I0524 07:17:55.247623       1 utils.go:205] ID: 3 GRPC response: {}
I0524 07:17:55.248621       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0524 07:17:55.248704       1 utils.go:199] ID: 4 GRPC request: {}
I0524 07:17:55.248950       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0524 07:17:55.250269       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:17:55.250474       1 utils.go:199] ID: 5 GRPC request: {}
I0524 07:17:55.250496       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0524 07:17:55.250722       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}}}]}
I0524 07:17:56.838129       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0524 07:17:56.838187       1 utils.go:199] ID: 6 GRPC request: {}
I0524 07:17:56.838213       1 utils.go:205] ID: 6 GRPC response: {}
I0524 07:17:56.840539       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0524 07:17:56.840594       1 utils.go:199] ID: 7 GRPC request: {}
I0524 07:17:56.840605       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0524 07:17:56.840647       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0524 07:17:56.842558       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0524 07:17:56.842595       1 utils.go:199] ID: 8 GRPC request: {}
I0524 07:17:56.842648       1 utils.go:205] ID: 8 GRPC response: {}
I0524 07:17:56.843230       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0524 07:17:56.843380       1 utils.go:199] ID: 9 GRPC request: {}
I0524 07:17:56.843698       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0524 07:17:56.844882       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:17:56.845028       1 utils.go:199] ID: 10 GRPC request: {}
I0524 07:17:56.845047       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0524 07:17:56.845232       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}}}]}
I0524 07:17:56.845971       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:17:56.846020       1 utils.go:199] ID: 11 GRPC request: {}
I0524 07:17:56.846035       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0524 07:17:56.846142       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}}}]}
I0524 07:17:56.846627       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:17:56.846687       1 utils.go:199] ID: 12 GRPC request: {}
I0524 07:17:56.846699       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0524 07:17:56.846832       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}}}]}
I0524 07:18:06.994574       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0524 07:18:06.994637       1 utils.go:199] ID: 13 GRPC request: {}
I0524 07:18:06.994649       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0524 07:18:06.994687       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0524 07:18:06.997094       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0524 07:18:06.997177       1 utils.go:199] ID: 14 GRPC request: {}
I0524 07:18:06.997209       1 utils.go:205] ID: 14 GRPC response: {}
I0524 07:18:06.997735       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:18:06.997765       1 utils.go:199] ID: 15 GRPC request: {}
I0524 07:18:06.997775       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0524 07:18:06.997889       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}}}]}
I0524 07:18:09.271635       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0524 07:18:09.271784       1 utils.go:199] ID: 16 GRPC request: {}
I0524 07:18:09.271993       1 utils.go:205] ID: 16 GRPC response: {}
I0524 07:18:09.275914       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0524 07:18:09.276021       1 utils.go:199] ID: 17 GRPC request: {}
I0524 07:18:09.276101       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0524 07:18:09.276216       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0524 07:18:09.280981       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0524 07:18:09.281006       1 utils.go:199] ID: 18 GRPC request: {}
I0524 07:18:09.281024       1 utils.go:205] ID: 18 GRPC response: {}
I0524 07:18:09.281514       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0524 07:18:09.281565       1 utils.go:199] ID: 19 GRPC request: {}
I0524 07:18:09.281701       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0524 07:18:09.282419       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0524 07:18:09.282444       1 utils.go:199] ID: 20 GRPC request: {}
I0524 07:18:09.282453       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0524 07:18:09.282566       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}}}]}
I0524 07:19:09.450285       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0524 07:19:09.450345       1 utils.go:199] ID: 21 GRPC request: {}
I0524 07:19:09.450369       1 utils.go:205] ID: 21 GRPC response: {}
I0524 07:20:09.449930       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0524 07:20:09.450010       1 utils.go:199] ID: 22 GRPC request: {}
I0524 07:20:09.450039       1 utils.go:205] ID: 22 GRPC response: {}
I0524 07:21:09.449350       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0524 07:21:09.449409       1 utils.go:199] ID: 23 GRPC request: {}
I0524 07:21:09.449435       1 utils.go:205] ID: 23 GRPC response: {}
I0524 07:21:52.371776       1 utils.go:198] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 GRPC call: /csi.v1.Controller/CreateVolume
I0524 07:21:52.372071       1 utils.go:199] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5640110e-14c1-45d1-8201-0f015a926915","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5640110e-14c1-45d1-8201-0f015a926915","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}}]}
I0524 07:21:52.372270       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0524 07:21:52.397880       1 omap.go:80] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0524 07:21:52.415250       1 omap.go:159] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5640110e-14c1-45d1-8201-0f015a926915:a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a])
I0524 07:21:52.422968       1 omap.go:159] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 set omap keys (pool="kube", namespace="", name="csi.volume.a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a"): map[csi.imagename:csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a csi.volname:pvc-5640110e-14c1-45d1-8201-0f015a926915 csi.volume.owner:default])
I0524 07:21:52.423025       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a) and image name (csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a) for request name (pvc-5640110e-14c1-45d1-8201-0f015a926915)
I0524 07:21:52.423105       1 rbd_util.go:423] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 rbd: create kube/csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a size 5120M (features: [layering]) using mon 199.204.45.53
I0524 07:21:52.423184       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 setting image options on kube/csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a
I0524 07:21:52.454177       1 controllerserver.go:763] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 created image kube/csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a backed for request name pvc-5640110e-14c1-45d1-8201-0f015a926915
I0524 07:21:52.495370       1 omap.go:159] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 set omap keys (pool="kube", namespace="", name="csi.volume.a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a"): map[csi.imageid:37ed847f5944])
I0524 07:21:52.603782       1 utils.go:205] ID: 24 Req-ID: pvc-5640110e-14c1-45d1-8201-0f015a926915 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a5b5cf7b-dfe8-4541-9fbf-ddd5e5f87b8a"}}
I0524 07:22:09.462138       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0524 07:22:09.462391       1 utils.go:199] ID: 25 GRPC request: {}
I0524 07:22:09.462424       1 utils.go:205] ID: 25 GRPC response: {}