I0709 15:38:40.758165       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0709 15:38:40.758315       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0709 15:38:40.758328       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0709 15:38:40.758331       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0709 15:38:40.758335       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0709 15:38:40.758339       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0709 15:38:40.758346       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0709 15:38:40.758353       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0709 15:38:40.758359       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0709 15:38:40.758362       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0709 15:38:40.758688       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0709 15:38:40.758707       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0709 15:38:43.404832       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:43.406662       1 utils.go:199] ID: 1 GRPC request: {}
I0709 15:38:43.406733       1 utils.go:205] ID: 1 GRPC response: {}
I0709 15:38:43.409142       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:38:43.409201       1 utils.go:199] ID: 2 GRPC request: {}
I0709 15:38:43.409220       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0709 15:38:43.409271       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:38:43.411585       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:43.411627       1 utils.go:199] ID: 3 GRPC request: {}
I0709 15:38:43.411647       1 utils.go:205] ID: 3 GRPC response: {}
I0709 15:38:43.412186       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:38:43.412387       1 utils.go:199] ID: 4 GRPC request: {}
I0709 15:38:43.412648       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:38:43.413698       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:38:43.413890       1 utils.go:199] ID: 5 GRPC request: {}
I0709 15:38:43.414047       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0709 15:38:43.414314       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}}}]}
I0709 15:38:44.824133       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:44.824231       1 utils.go:199] ID: 6 GRPC request: {}
I0709 15:38:44.824296       1 utils.go:205] ID: 6 GRPC response: {}
I0709 15:38:44.827510       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:38:44.827532       1 utils.go:199] ID: 7 GRPC request: {}
I0709 15:38:44.827539       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0709 15:38:44.827562       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:38:44.829512       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:44.829574       1 utils.go:199] ID: 8 GRPC request: {}
I0709 15:38:44.829621       1 utils.go:205] ID: 8 GRPC response: {}
I0709 15:38:44.830187       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:38:44.830208       1 utils.go:199] ID: 9 GRPC request: {}
I0709 15:38:44.830345       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:38:44.830993       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:38:44.831050       1 utils.go:199] ID: 10 GRPC request: {}
I0709 15:38:44.831087       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0709 15:38:44.831229       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}}}]}
I0709 15:38:44.831748       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:38:44.831769       1 utils.go:199] ID: 11 GRPC request: {}
I0709 15:38:44.831775       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0709 15:38:44.831899       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}}}]}
I0709 15:38:44.832194       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:38:44.832213       1 utils.go:199] ID: 12 GRPC request: {}
I0709 15:38:44.832289       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0709 15:38:44.832415       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}}}]}
I0709 15:38:56.073556       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:38:56.073630       1 utils.go:199] ID: 13 GRPC request: {}
I0709 15:38:56.073672       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0709 15:38:56.073745       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:38:56.077420       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:56.077481       1 utils.go:199] ID: 14 GRPC request: {}
I0709 15:38:56.077499       1 utils.go:205] ID: 14 GRPC response: {}
I0709 15:38:56.078234       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:38:56.078344       1 utils.go:199] ID: 15 GRPC request: {}
I0709 15:38:56.078363       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0709 15:38:56.078527       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}}}]}
I0709 15:39:00.165451       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0709 15:39:00.165499       1 utils.go:199] ID: 16 GRPC request: {}
I0709 15:39:00.165545       1 utils.go:205] ID: 16 GRPC response: {}
I0709 15:39:00.167669       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:39:00.167690       1 utils.go:199] ID: 17 GRPC request: {}
I0709 15:39:00.167710       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0709 15:39:00.167760       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:39:00.175935       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0709 15:39:00.176028       1 utils.go:199] ID: 18 GRPC request: {}
I0709 15:39:00.176066       1 utils.go:205] ID: 18 GRPC response: {}
I0709 15:39:00.176580       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:39:00.176634       1 utils.go:199] ID: 19 GRPC request: {}
I0709 15:39:00.176797       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:39:00.180131       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:39:00.180181       1 utils.go:199] ID: 20 GRPC request: {}
I0709 15:39:00.180193       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0709 15:39:00.180327       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}}}]}
I0709 15:40:00.420326       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0709 15:40:00.420385       1 utils.go:199] ID: 21 GRPC request: {}
I0709 15:40:00.420405       1 utils.go:205] ID: 21 GRPC response: {}
I0709 15:41:00.390068       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0709 15:41:00.390125       1 utils.go:199] ID: 22 GRPC request: {}
I0709 15:41:00.390164       1 utils.go:205] ID: 22 GRPC response: {}
I0709 15:42:00.389196       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0709 15:42:00.389256       1 utils.go:199] ID: 23 GRPC request: {}
I0709 15:42:00.389280       1 utils.go:205] ID: 23 GRPC response: {}
I0709 15:43:00.400872       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0709 15:43:00.400919       1 utils.go:199] ID: 24 GRPC request: {}
I0709 15:43:00.400954       1 utils.go:205] ID: 24 GRPC response: {}
I0709 15:43:08.191281       1 utils.go:198] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce GRPC call: /csi.v1.Controller/CreateVolume
I0709 15:43:08.191676       1 utils.go:199] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce","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}}]}
I0709 15:43:08.191999       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce setting disableInUseChecks: false image features: [layering] mounter: rbd
E0709 15:43:08.213212       1 omap.go:80] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0709 15:43:08.230648       1 omap.go:159] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce:57bb4284-e5b1-4862-8fd6-2365af55017b])
I0709 15:43:08.239259       1 omap.go:159] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce set omap keys (pool="kube", namespace="", name="csi.volume.57bb4284-e5b1-4862-8fd6-2365af55017b"): map[csi.imagename:csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b csi.volname:pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce csi.volume.owner:default])
I0709 15:43:08.239287       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-57bb4284-e5b1-4862-8fd6-2365af55017b) and image name (csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b) for request name (pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce)
I0709 15:43:08.239372       1 rbd_util.go:423] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce rbd: create kube/csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b size 5120M (features: [layering]) using mon 199.19.213.48
I0709 15:43:08.239420       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce setting image options on kube/csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b
I0709 15:43:08.286726       1 controllerserver.go:763] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce created image kube/csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b backed for request name pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce
I0709 15:43:08.328895       1 omap.go:159] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce set omap keys (pool="kube", namespace="", name="csi.volume.57bb4284-e5b1-4862-8fd6-2365af55017b"): map[csi.imageid:37f45b059069])
I0709 15:43:08.431621       1 utils.go:205] ID: 25 Req-ID: pvc-dded7ddf-ee4b-42ec-913f-faf92e5bf0ce GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-57bb4284-e5b1-4862-8fd6-2365af55017b","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-57bb4284-e5b1-4862-8fd6-2365af55017b"}}
I0709 15:44:00.389250       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0709 15:44:00.389312       1 utils.go:199] ID: 26 GRPC request: {}
I0709 15:44:00.389335       1 utils.go:205] ID: 26 GRPC response: {}