I0418 09:11:25.933362       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0418 09:11:25.933616       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0418 09:11:25.933647       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0418 09:11:25.933656       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0418 09:11:25.933660       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0418 09:11:25.933663       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0418 09:11:25.933667       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0418 09:11:25.933670       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0418 09:11:25.933672       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0418 09:11:25.933675       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0418 09:11:25.934092       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0418 09:11:25.934132       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0418 09:11:28.125782       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:28.128033       1 utils.go:199] ID: 1 GRPC request: {}
I0418 09:11:28.128233       1 utils.go:205] ID: 1 GRPC response: {}
I0418 09:11:28.134701       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 09:11:28.134816       1 utils.go:199] ID: 2 GRPC request: {}
I0418 09:11:28.134842       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0418 09:11:28.134913       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 09:11:28.136492       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:28.136524       1 utils.go:199] ID: 3 GRPC request: {}
I0418 09:11:28.136551       1 utils.go:205] ID: 3 GRPC response: {}
I0418 09:11:28.137038       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 09:11:28.137153       1 utils.go:199] ID: 4 GRPC request: {}
I0418 09:11:28.137385       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 09:11:28.138138       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:28.138189       1 utils.go:199] ID: 5 GRPC request: {}
I0418 09:11:28.138201       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0418 09:11:28.138352       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}}}]}
I0418 09:11:29.296908       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:29.296952       1 utils.go:199] ID: 6 GRPC request: {}
I0418 09:11:29.296969       1 utils.go:205] ID: 6 GRPC response: {}
I0418 09:11:29.300169       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 09:11:29.300233       1 utils.go:199] ID: 7 GRPC request: {}
I0418 09:11:29.300258       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0418 09:11:29.300344       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 09:11:29.303463       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:29.303488       1 utils.go:199] ID: 8 GRPC request: {}
I0418 09:11:29.303508       1 utils.go:205] ID: 8 GRPC response: {}
I0418 09:11:29.304023       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 09:11:29.304047       1 utils.go:199] ID: 9 GRPC request: {}
I0418 09:11:29.304145       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 09:11:29.304951       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:29.305038       1 utils.go:199] ID: 10 GRPC request: {}
I0418 09:11:29.305094       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0418 09:11:29.305226       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}}}]}
I0418 09:11:29.305862       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:29.305885       1 utils.go:199] ID: 11 GRPC request: {}
I0418 09:11:29.305893       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0418 09:11:29.305968       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}}}]}
I0418 09:11:29.306455       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:29.306524       1 utils.go:199] ID: 12 GRPC request: {}
I0418 09:11:29.306551       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0418 09:11:29.306711       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}}}]}
I0418 09:11:31.281106       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 09:11:31.281166       1 utils.go:199] ID: 13 GRPC request: {}
I0418 09:11:31.281182       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0418 09:11:31.281226       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 09:11:31.292742       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:31.292795       1 utils.go:199] ID: 14 GRPC request: {}
I0418 09:11:31.292819       1 utils.go:205] ID: 14 GRPC response: {}
I0418 09:11:31.293232       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:31.293293       1 utils.go:199] ID: 15 GRPC request: {}
I0418 09:11:31.293318       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0418 09:11:31.293437       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}}}]}
I0418 09:11:34.218833       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:34.218882       1 utils.go:199] ID: 16 GRPC request: {}
I0418 09:11:34.218909       1 utils.go:205] ID: 16 GRPC response: {}
I0418 09:11:34.222929       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 09:11:34.223067       1 utils.go:199] ID: 17 GRPC request: {}
I0418 09:11:34.223151       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0418 09:11:34.223311       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 09:11:34.225503       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0418 09:11:34.225534       1 utils.go:199] ID: 18 GRPC request: {}
I0418 09:11:34.225546       1 utils.go:205] ID: 18 GRPC response: {}
I0418 09:11:34.225963       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 09:11:34.225982       1 utils.go:199] ID: 19 GRPC request: {}
I0418 09:11:34.226073       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 09:11:34.227161       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 09:11:34.227179       1 utils.go:199] ID: 20 GRPC request: {}
I0418 09:11:34.227187       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0418 09:11:34.227257       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}}}]}
I0418 09:12:34.420163       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0418 09:12:34.420226       1 utils.go:199] ID: 21 GRPC request: {}
I0418 09:12:34.420259       1 utils.go:205] ID: 21 GRPC response: {}
I0418 09:13:34.403160       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0418 09:13:34.403348       1 utils.go:199] ID: 22 GRPC request: {}
I0418 09:13:34.403444       1 utils.go:205] ID: 22 GRPC response: {}
I0418 09:14:31.635290       1 utils.go:198] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 GRPC call: /csi.v1.Controller/CreateVolume
I0418 09:14:31.635575       1 utils.go:199] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12","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}}]}
I0418 09:14:31.638893       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0418 09:14:31.656643       1 omap.go:80] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0418 09:14:31.674255       1 omap.go:159] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12:60dacd08-a2f9-446d-97d1-f99245f34899])
I0418 09:14:31.680479       1 omap.go:159] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 set omap keys (pool="kube", namespace="", name="csi.volume.60dacd08-a2f9-446d-97d1-f99245f34899"): map[csi.imagename:csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899 csi.volname:pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 csi.volume.owner:default])
I0418 09:14:31.680513       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-60dacd08-a2f9-446d-97d1-f99245f34899) and image name (csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899) for request name (pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12)
I0418 09:14:31.680587       1 rbd_util.go:423] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 rbd: create kube/csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899 size 5120M (features: [layering]) using mon 199.204.45.33
I0418 09:14:31.680633       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 setting image options on kube/csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899
I0418 09:14:33.270185       1 controllerserver.go:763] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 created image kube/csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899 backed for request name pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12
I0418 09:14:33.305219       1 omap.go:159] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 set omap keys (pool="kube", namespace="", name="csi.volume.60dacd08-a2f9-446d-97d1-f99245f34899"): map[csi.imageid:37d9675892fb])
I0418 09:14:33.403356       1 utils.go:205] ID: 23 Req-ID: pvc-034ff1b5-3182-4ed0-9009-96b757cb3d12 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-60dacd08-a2f9-446d-97d1-f99245f34899","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-60dacd08-a2f9-446d-97d1-f99245f34899"}}
I0418 09:14:34.442927       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0418 09:14:34.442987       1 utils.go:199] ID: 24 GRPC request: {}
I0418 09:14:34.443010       1 utils.go:205] ID: 24 GRPC response: {}