I0709 15:34:45.246975       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0709 15:34:45.247122       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0709 15:34:45.247135       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0709 15:34:45.247139       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0709 15:34:45.247143       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0709 15:34:45.247146       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0709 15:34:45.247163       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0709 15:34:45.247167       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0709 15:34:45.247170       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0709 15:34:45.247173       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0709 15:34:45.247778       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0709 15:34:45.247809       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0709 15:34:52.886486       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:52.889237       1 utils.go:199] ID: 1 GRPC request: {}
I0709 15:34:52.889341       1 utils.go:205] ID: 1 GRPC response: {}
I0709 15:34:52.893611       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:34:52.893724       1 utils.go:199] ID: 2 GRPC request: {}
I0709 15:34:52.893752       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0709 15:34:52.893809       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:34:52.898012       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:52.898068       1 utils.go:199] ID: 3 GRPC request: {}
I0709 15:34:52.898140       1 utils.go:205] ID: 3 GRPC response: {}
I0709 15:34:52.898883       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:34:52.899023       1 utils.go:199] ID: 4 GRPC request: {}
I0709 15:34:52.899338       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:34:52.900981       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:52.901168       1 utils.go:199] ID: 5 GRPC request: {}
I0709 15:34:52.901211       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0709 15:34:52.901539       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:34:54.334527       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:54.334590       1 utils.go:199] ID: 6 GRPC request: {}
I0709 15:34:54.334614       1 utils.go:205] ID: 6 GRPC response: {}
I0709 15:34:54.336491       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:34:54.336517       1 utils.go:199] ID: 7 GRPC request: {}
I0709 15:34:54.336525       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0709 15:34:54.336555       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:34:54.340522       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:54.340543       1 utils.go:199] ID: 8 GRPC request: {}
I0709 15:34:54.340556       1 utils.go:205] ID: 8 GRPC response: {}
I0709 15:34:54.341003       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:34:54.341024       1 utils.go:199] ID: 9 GRPC request: {}
I0709 15:34:54.341127       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:34:54.342019       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:54.342132       1 utils.go:199] ID: 10 GRPC request: {}
I0709 15:34:54.342234       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0709 15:34:54.342425       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:34:54.343235       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:54.343258       1 utils.go:199] ID: 11 GRPC request: {}
I0709 15:34:54.343267       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0709 15:34:54.343333       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:34:54.343942       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:54.344016       1 utils.go:199] ID: 12 GRPC request: {}
I0709 15:34:54.344032       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0709 15:34:54.344181       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:34:55.888131       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:34:55.888174       1 utils.go:199] ID: 13 GRPC request: {}
I0709 15:34:55.888225       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0709 15:34:55.888260       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:34:55.891232       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:55.891256       1 utils.go:199] ID: 14 GRPC request: {}
I0709 15:34:55.891314       1 utils.go:205] ID: 14 GRPC response: {}
I0709 15:34:55.892133       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:55.892162       1 utils.go:199] ID: 15 GRPC request: {}
I0709 15:34:55.892204       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0709 15:34:55.892388       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:34:57.343030       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:57.343105       1 utils.go:199] ID: 16 GRPC request: {}
I0709 15:34:57.343131       1 utils.go:205] ID: 16 GRPC response: {}
I0709 15:34:57.346026       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 15:34:57.346069       1 utils.go:199] ID: 17 GRPC request: {}
I0709 15:34:57.346079       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0709 15:34:57.346108       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 15:34:57.348282       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0709 15:34:57.348319       1 utils.go:199] ID: 18 GRPC request: {}
I0709 15:34:57.348330       1 utils.go:205] ID: 18 GRPC response: {}
I0709 15:34:57.348699       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 15:34:57.348723       1 utils.go:199] ID: 19 GRPC request: {}
I0709 15:34:57.348821       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 15:34:57.353975       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 15:34:57.353997       1 utils.go:199] ID: 20 GRPC request: {}
I0709 15:34:57.354007       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0709 15:34:57.354154       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:35:57.589158       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0709 15:35:57.589227       1 utils.go:199] ID: 21 GRPC request: {}
I0709 15:35:57.589261       1 utils.go:205] ID: 21 GRPC response: {}
I0709 15:36:57.543806       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0709 15:36:57.544130       1 utils.go:199] ID: 22 GRPC request: {}
I0709 15:36:57.544168       1 utils.go:205] ID: 22 GRPC response: {}
I0709 15:37:57.540218       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0709 15:37:57.540322       1 utils.go:199] ID: 23 GRPC request: {}
I0709 15:37:57.540355       1 utils.go:205] ID: 23 GRPC response: {}
I0709 15:38:57.552689       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0709 15:38:57.552751       1 utils.go:199] ID: 24 GRPC request: {}
I0709 15:38:57.553073       1 utils.go:205] ID: 24 GRPC response: {}
I0709 15:39:19.578803       1 utils.go:198] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 GRPC call: /csi.v1.Controller/CreateVolume
I0709 15:39:19.579176       1 utils.go:199] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-59db2a9f-d976-4740-b4d3-051ca3d56064","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-59db2a9f-d976-4740-b4d3-051ca3d56064","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:39:19.579443       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0709 15:39:19.601635       1 omap.go:80] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0709 15:39:19.623929       1 omap.go:159] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-59db2a9f-d976-4740-b4d3-051ca3d56064:654f4065-806e-4517-8614-15e27fed4ade])
I0709 15:39:19.631378       1 omap.go:159] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 set omap keys (pool="kube", namespace="", name="csi.volume.654f4065-806e-4517-8614-15e27fed4ade"): map[csi.imagename:csi-vol-654f4065-806e-4517-8614-15e27fed4ade csi.volname:pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 csi.volume.owner:default])
I0709 15:39:19.631428       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-654f4065-806e-4517-8614-15e27fed4ade) and image name (csi-vol-654f4065-806e-4517-8614-15e27fed4ade) for request name (pvc-59db2a9f-d976-4740-b4d3-051ca3d56064)
I0709 15:39:19.631534       1 rbd_util.go:423] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 rbd: create kube/csi-vol-654f4065-806e-4517-8614-15e27fed4ade size 5120M (features: [layering]) using mon 199.19.213.183
I0709 15:39:19.631595       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 setting image options on kube/csi-vol-654f4065-806e-4517-8614-15e27fed4ade
I0709 15:39:19.674018       1 controllerserver.go:763] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 created image kube/csi-vol-654f4065-806e-4517-8614-15e27fed4ade backed for request name pvc-59db2a9f-d976-4740-b4d3-051ca3d56064
I0709 15:39:19.709477       1 omap.go:159] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 set omap keys (pool="kube", namespace="", name="csi.volume.654f4065-806e-4517-8614-15e27fed4ade"): map[csi.imageid:37f4ba541cc9])
I0709 15:39:19.820796       1 utils.go:205] ID: 25 Req-ID: pvc-59db2a9f-d976-4740-b4d3-051ca3d56064 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-654f4065-806e-4517-8614-15e27fed4ade","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-654f4065-806e-4517-8614-15e27fed4ade"}}
I0709 15:39:57.540051       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0709 15:39:57.540225       1 utils.go:199] ID: 26 GRPC request: {}
I0709 15:39:57.540298       1 utils.go:205] ID: 26 GRPC response: {}