I0218 10:07:10.012535       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0218 10:07:10.012641       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0218 10:07:10.012811       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0218 10:07:10.012820       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0218 10:07:10.012825       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0218 10:07:10.012893       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0218 10:07:10.012903       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0218 10:07:10.012906       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0218 10:07:10.012909       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0218 10:07:10.012912       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0218 10:07:10.014269       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0218 10:07:10.014377       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0218 10:07:14.618575       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:14.619570       1 utils.go:199] ID: 1 GRPC request: {}
I0218 10:07:14.619610       1 utils.go:205] ID: 1 GRPC response: {}
I0218 10:07:14.622263       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 10:07:14.622462       1 utils.go:199] ID: 2 GRPC request: {}
I0218 10:07:14.622529       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0218 10:07:14.622633       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 10:07:14.623574       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:14.623642       1 utils.go:199] ID: 3 GRPC request: {}
I0218 10:07:14.623705       1 utils.go:205] ID: 3 GRPC response: {}
I0218 10:07:14.623996       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 10:07:14.624161       1 utils.go:199] ID: 4 GRPC request: {}
I0218 10:07:14.624338       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 10:07:14.625187       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:14.625279       1 utils.go:199] ID: 5 GRPC request: {}
I0218 10:07:14.625337       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0218 10:07:14.625501       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}}}]}
I0218 10:07:16.535216       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:16.535254       1 utils.go:199] ID: 6 GRPC request: {}
I0218 10:07:16.535270       1 utils.go:205] ID: 6 GRPC response: {}
I0218 10:07:16.536824       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 10:07:16.536862       1 utils.go:199] ID: 7 GRPC request: {}
I0218 10:07:16.536909       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0218 10:07:16.537024       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 10:07:16.538081       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:16.538258       1 utils.go:199] ID: 8 GRPC request: {}
I0218 10:07:16.538333       1 utils.go:205] ID: 8 GRPC response: {}
I0218 10:07:16.539233       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 10:07:16.539248       1 utils.go:199] ID: 9 GRPC request: {}
I0218 10:07:16.539324       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 10:07:16.546398       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:16.546452       1 utils.go:199] ID: 10 GRPC request: {}
I0218 10:07:16.546465       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0218 10:07:16.546541       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}}}]}
I0218 10:07:16.547207       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:16.547292       1 utils.go:199] ID: 11 GRPC request: {}
I0218 10:07:16.547341       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0218 10:07:16.547476       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}}}]}
I0218 10:07:16.547980       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:16.548051       1 utils.go:199] ID: 12 GRPC request: {}
I0218 10:07:16.548086       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0218 10:07:16.548313       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}}}]}
I0218 10:07:18.854929       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 10:07:18.854957       1 utils.go:199] ID: 13 GRPC request: {}
I0218 10:07:18.854963       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0218 10:07:18.854981       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 10:07:18.856644       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:18.856658       1 utils.go:199] ID: 14 GRPC request: {}
I0218 10:07:18.856667       1 utils.go:205] ID: 14 GRPC response: {}
I0218 10:07:18.856869       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:18.856881       1 utils.go:199] ID: 15 GRPC request: {}
I0218 10:07:18.856887       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0218 10:07:18.856949       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}}}]}
I0218 10:07:26.628340       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:26.628461       1 utils.go:199] ID: 16 GRPC request: {}
I0218 10:07:26.628529       1 utils.go:205] ID: 16 GRPC response: {}
I0218 10:07:26.630391       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 10:07:26.630423       1 utils.go:199] ID: 17 GRPC request: {}
I0218 10:07:26.630436       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0218 10:07:26.630470       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 10:07:26.631638       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0218 10:07:26.631654       1 utils.go:199] ID: 18 GRPC request: {}
I0218 10:07:26.631665       1 utils.go:205] ID: 18 GRPC response: {}
I0218 10:07:26.632857       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 10:07:26.632874       1 utils.go:199] ID: 19 GRPC request: {}
I0218 10:07:26.632935       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 10:07:26.634149       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 10:07:26.634165       1 utils.go:199] ID: 20 GRPC request: {}
I0218 10:07:26.634171       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0218 10:07:26.634217       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}}}]}
I0218 10:08:27.007219       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0218 10:08:27.007604       1 utils.go:199] ID: 21 GRPC request: {}
I0218 10:08:27.007844       1 utils.go:205] ID: 21 GRPC response: {}
I0218 10:09:27.008348       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0218 10:09:27.008388       1 utils.go:199] ID: 22 GRPC request: {}
I0218 10:09:27.008649       1 utils.go:205] ID: 22 GRPC response: {}
I0218 10:10:13.611469       1 utils.go:198] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c GRPC call: /csi.v1.Controller/CreateVolume
I0218 10:10:13.611766       1 utils.go:199] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c","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}}]}
I0218 10:10:13.611922       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c setting disableInUseChecks: false image features: [layering] mounter: rbd
E0218 10:10:13.639273       1 omap.go:80] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0218 10:10:13.660405       1 omap.go:159] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c:3b8c00a5-a6fb-4aee-9454-6d7080197d1d])
I0218 10:10:13.668320       1 omap.go:159] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c set omap keys (pool="kube", namespace="", name="csi.volume.3b8c00a5-a6fb-4aee-9454-6d7080197d1d"): map[csi.imagename:csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d csi.volname:pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c csi.volume.owner:default])
I0218 10:10:13.668525       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3b8c00a5-a6fb-4aee-9454-6d7080197d1d) and image name (csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d) for request name (pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c)
I0218 10:10:13.668730       1 rbd_util.go:423] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c rbd: create kube/csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d size 5120M (features: [layering]) using mon 199.19.213.128
I0218 10:10:13.668874       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c setting image options on kube/csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d
I0218 10:10:15.458135       1 controllerserver.go:763] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c created image kube/csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d backed for request name pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c
I0218 10:10:15.487729       1 omap.go:159] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c set omap keys (pool="kube", namespace="", name="csi.volume.3b8c00a5-a6fb-4aee-9454-6d7080197d1d"): map[csi.imageid:37d9a4e0fb0b])
I0218 10:10:15.588631       1 utils.go:205] ID: 23 Req-ID: pvc-ac66e173-aa9a-4658-82e4-fdbe5d9d145c GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-3b8c00a5-a6fb-4aee-9454-6d7080197d1d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3b8c00a5-a6fb-4aee-9454-6d7080197d1d"}}
I0218 10:10:27.006151       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0218 10:10:27.006186       1 utils.go:199] ID: 24 GRPC request: {}
I0218 10:10:27.006206       1 utils.go:205] ID: 24 GRPC response: {}