I0419 11:07:28.648756       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0419 11:07:28.648900       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0419 11:07:28.648914       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0419 11:07:28.648917       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0419 11:07:28.648919       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0419 11:07:28.648922       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0419 11:07:28.648925       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0419 11:07:28.648928       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0419 11:07:28.648931       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0419 11:07:28.648933       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0419 11:07:28.649356       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0419 11:07:28.649392       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0419 11:07:39.413518       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:39.415792       1 utils.go:199] ID: 1 GRPC request: {}
I0419 11:07:39.415890       1 utils.go:205] ID: 1 GRPC response: {}
I0419 11:07:39.418749       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 11:07:39.418819       1 utils.go:199] ID: 2 GRPC request: {}
I0419 11:07:39.418835       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0419 11:07:39.418887       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 11:07:39.421163       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:39.421206       1 utils.go:199] ID: 3 GRPC request: {}
I0419 11:07:39.421230       1 utils.go:205] ID: 3 GRPC response: {}
I0419 11:07:39.421870       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 11:07:39.422008       1 utils.go:199] ID: 4 GRPC request: {}
I0419 11:07:39.422352       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 11:07:39.423467       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:39.423560       1 utils.go:199] ID: 5 GRPC request: {}
I0419 11:07:39.423584       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0419 11:07:39.423902       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}}}]}
I0419 11:07:41.402943       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:41.403088       1 utils.go:199] ID: 6 GRPC request: {}
I0419 11:07:41.403126       1 utils.go:205] ID: 6 GRPC response: {}
I0419 11:07:41.407621       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 11:07:41.407706       1 utils.go:199] ID: 7 GRPC request: {}
I0419 11:07:41.407726       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0419 11:07:41.407789       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 11:07:41.409842       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:41.409876       1 utils.go:199] ID: 8 GRPC request: {}
I0419 11:07:41.410044       1 utils.go:205] ID: 8 GRPC response: {}
I0419 11:07:41.410674       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 11:07:41.410722       1 utils.go:199] ID: 9 GRPC request: {}
I0419 11:07:41.410831       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 11:07:41.411465       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:41.411512       1 utils.go:199] ID: 10 GRPC request: {}
I0419 11:07:41.411535       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0419 11:07:41.411606       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}}}]}
I0419 11:07:41.412070       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:41.412089       1 utils.go:199] ID: 11 GRPC request: {}
I0419 11:07:41.412095       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0419 11:07:41.412179       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}}}]}
I0419 11:07:41.412802       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:41.412882       1 utils.go:199] ID: 12 GRPC request: {}
I0419 11:07:41.412900       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0419 11:07:41.413032       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}}}]}
I0419 11:07:42.950286       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 11:07:42.950320       1 utils.go:199] ID: 13 GRPC request: {}
I0419 11:07:42.950328       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0419 11:07:42.950353       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 11:07:42.953034       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:42.953054       1 utils.go:199] ID: 14 GRPC request: {}
I0419 11:07:42.953067       1 utils.go:205] ID: 14 GRPC response: {}
I0419 11:07:42.953582       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:42.953606       1 utils.go:199] ID: 15 GRPC request: {}
I0419 11:07:42.953614       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0419 11:07:42.953725       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}}}]}
I0419 11:07:44.425957       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:44.426054       1 utils.go:199] ID: 16 GRPC request: {}
I0419 11:07:44.426085       1 utils.go:205] ID: 16 GRPC response: {}
I0419 11:07:44.430439       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 11:07:44.430466       1 utils.go:199] ID: 17 GRPC request: {}
I0419 11:07:44.430475       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0419 11:07:44.430498       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 11:07:44.433182       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0419 11:07:44.433220       1 utils.go:199] ID: 18 GRPC request: {}
I0419 11:07:44.433240       1 utils.go:205] ID: 18 GRPC response: {}
I0419 11:07:44.433701       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 11:07:44.433739       1 utils.go:199] ID: 19 GRPC request: {}
I0419 11:07:44.433827       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 11:07:44.434516       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 11:07:44.434540       1 utils.go:199] ID: 20 GRPC request: {}
I0419 11:07:44.434550       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0419 11:07:44.434629       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}}}]}
I0419 11:08:47.292594       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0419 11:08:47.292642       1 utils.go:199] ID: 21 GRPC request: {}
I0419 11:08:47.292664       1 utils.go:205] ID: 21 GRPC response: {}
I0419 11:09:47.293708       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0419 11:09:47.293896       1 utils.go:199] ID: 22 GRPC request: {}
I0419 11:09:47.293932       1 utils.go:205] ID: 22 GRPC response: {}
I0419 11:10:47.292095       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0419 11:10:47.292163       1 utils.go:199] ID: 23 GRPC request: {}
I0419 11:10:47.292199       1 utils.go:205] ID: 23 GRPC response: {}
I0419 11:10:55.071636       1 utils.go:198] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d GRPC call: /csi.v1.Controller/CreateVolume
I0419 11:10:55.072436       1 utils.go:199] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-f03ee0ad-b273-436a-b446-47b98500760d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-f03ee0ad-b273-436a-b446-47b98500760d","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}}]}
I0419 11:10:55.073017       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0419 11:10:55.089993       1 omap.go:80] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0419 11:10:55.107675       1 omap.go:159] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-f03ee0ad-b273-436a-b446-47b98500760d:cadf8585-d2e6-44ee-8db6-32c022d93253])
I0419 11:10:55.115614       1 omap.go:159] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d set omap keys (pool="kube", namespace="", name="csi.volume.cadf8585-d2e6-44ee-8db6-32c022d93253"): map[csi.imagename:csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253 csi.volname:pvc-f03ee0ad-b273-436a-b446-47b98500760d csi.volume.owner:default])
I0419 11:10:55.115653       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-cadf8585-d2e6-44ee-8db6-32c022d93253) and image name (csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253) for request name (pvc-f03ee0ad-b273-436a-b446-47b98500760d)
I0419 11:10:55.115841       1 rbd_util.go:423] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d rbd: create kube/csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253 size 5120M (features: [layering]) using mon 199.204.45.109
I0419 11:10:55.115958       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d setting image options on kube/csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253
I0419 11:10:57.575500       1 controllerserver.go:763] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d created image kube/csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253 backed for request name pvc-f03ee0ad-b273-436a-b446-47b98500760d
I0419 11:10:57.633479       1 omap.go:159] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d set omap keys (pool="kube", namespace="", name="csi.volume.cadf8585-d2e6-44ee-8db6-32c022d93253"): map[csi.imageid:37d9469b1bfd])
I0419 11:10:57.738798       1 utils.go:205] ID: 24 Req-ID: pvc-f03ee0ad-b273-436a-b446-47b98500760d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-cadf8585-d2e6-44ee-8db6-32c022d93253","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-cadf8585-d2e6-44ee-8db6-32c022d93253"}}
I0419 11:11:47.303940       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0419 11:11:47.303993       1 utils.go:199] ID: 25 GRPC request: {}
I0419 11:11:47.304016       1 utils.go:205] ID: 25 GRPC response: {}