I0515 15:25:21.035568       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0515 15:25:21.035822       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0515 15:25:21.035843       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0515 15:25:21.035849       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0515 15:25:21.035853       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0515 15:25:21.035858       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0515 15:25:21.035863       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0515 15:25:21.035867       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0515 15:25:21.035872       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0515 15:25:21.035880       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0515 15:25:21.036381       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0515 15:25:21.036393       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0515 15:25:27.269279       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:27.270559       1 utils.go:199] ID: 1 GRPC request: {}
I0515 15:25:27.270622       1 utils.go:205] ID: 1 GRPC response: {}
I0515 15:25:27.274511       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 15:25:27.274639       1 utils.go:199] ID: 2 GRPC request: {}
I0515 15:25:27.274654       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0515 15:25:27.274713       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 15:25:27.276416       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:27.276446       1 utils.go:199] ID: 3 GRPC request: {}
I0515 15:25:27.276543       1 utils.go:205] ID: 3 GRPC response: {}
I0515 15:25:27.276930       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 15:25:27.276981       1 utils.go:199] ID: 4 GRPC request: {}
I0515 15:25:27.277105       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 15:25:27.278418       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:27.278516       1 utils.go:199] ID: 5 GRPC request: {}
I0515 15:25:27.278528       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0515 15:25:27.278684       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}}}]}
I0515 15:25:30.358388       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:30.358595       1 utils.go:199] ID: 6 GRPC request: {}
I0515 15:25:30.358704       1 utils.go:205] ID: 6 GRPC response: {}
I0515 15:25:30.362864       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 15:25:30.362902       1 utils.go:199] ID: 7 GRPC request: {}
I0515 15:25:30.362910       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0515 15:25:30.362995       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 15:25:30.364875       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:30.364895       1 utils.go:199] ID: 8 GRPC request: {}
I0515 15:25:30.364926       1 utils.go:205] ID: 8 GRPC response: {}
I0515 15:25:30.365514       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 15:25:30.365615       1 utils.go:199] ID: 9 GRPC request: {}
I0515 15:25:30.365878       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 15:25:30.366843       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:30.366872       1 utils.go:199] ID: 10 GRPC request: {}
I0515 15:25:30.366923       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0515 15:25:30.367130       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}}}]}
I0515 15:25:30.367770       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:30.367789       1 utils.go:199] ID: 11 GRPC request: {}
I0515 15:25:30.367795       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0515 15:25:30.367912       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}}}]}
I0515 15:25:30.368748       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:30.368780       1 utils.go:199] ID: 12 GRPC request: {}
I0515 15:25:30.368789       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0515 15:25:30.368939       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}}}]}
I0515 15:25:31.724788       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 15:25:31.724817       1 utils.go:199] ID: 13 GRPC request: {}
I0515 15:25:31.724831       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0515 15:25:31.724867       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 15:25:31.728016       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:31.728042       1 utils.go:199] ID: 14 GRPC request: {}
I0515 15:25:31.728075       1 utils.go:205] ID: 14 GRPC response: {}
I0515 15:25:31.728586       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:31.728602       1 utils.go:199] ID: 15 GRPC request: {}
I0515 15:25:31.728608       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0515 15:25:31.728688       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}}}]}
I0515 15:25:33.082935       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:33.083000       1 utils.go:199] ID: 16 GRPC request: {}
I0515 15:25:33.083029       1 utils.go:205] ID: 16 GRPC response: {}
I0515 15:25:33.088582       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 15:25:33.089342       1 utils.go:199] ID: 17 GRPC request: {}
I0515 15:25:33.089441       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0515 15:25:33.089480       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 15:25:33.094475       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0515 15:25:33.094519       1 utils.go:199] ID: 18 GRPC request: {}
I0515 15:25:33.094535       1 utils.go:205] ID: 18 GRPC response: {}
I0515 15:25:33.095426       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 15:25:33.095466       1 utils.go:199] ID: 19 GRPC request: {}
I0515 15:25:33.095583       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 15:25:33.096365       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 15:25:33.096386       1 utils.go:199] ID: 20 GRPC request: {}
I0515 15:25:33.096396       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0515 15:25:33.096501       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}}}]}
I0515 15:26:33.254019       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0515 15:26:33.254256       1 utils.go:199] ID: 21 GRPC request: {}
I0515 15:26:33.254423       1 utils.go:205] ID: 21 GRPC response: {}
I0515 15:27:33.256501       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0515 15:27:33.256692       1 utils.go:199] ID: 22 GRPC request: {}
I0515 15:27:33.256800       1 utils.go:205] ID: 22 GRPC response: {}
I0515 15:28:33.306911       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0515 15:28:33.307070       1 utils.go:199] ID: 23 GRPC request: {}
I0515 15:28:33.307163       1 utils.go:205] ID: 23 GRPC response: {}
I0515 15:28:45.164208       1 utils.go:198] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 GRPC call: /csi.v1.Controller/CreateVolume
I0515 15:28:45.164924       1 utils.go:199] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06","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}}]}
I0515 15:28:45.165399       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0515 15:28:45.184218       1 omap.go:80] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0515 15:28:45.199589       1 omap.go:159] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06:e3843186-d88a-4dd3-bc81-3134193c961d])
I0515 15:28:45.207257       1 omap.go:159] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 set omap keys (pool="kube", namespace="", name="csi.volume.e3843186-d88a-4dd3-bc81-3134193c961d"): map[csi.imagename:csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d csi.volname:pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 csi.volume.owner:default])
I0515 15:28:45.207350       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e3843186-d88a-4dd3-bc81-3134193c961d) and image name (csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d) for request name (pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06)
I0515 15:28:45.207568       1 rbd_util.go:423] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 rbd: create kube/csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d size 5120M (features: [layering]) using mon 199.204.45.49
I0515 15:28:45.207660       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 setting image options on kube/csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d
I0515 15:28:46.483614       1 controllerserver.go:763] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 created image kube/csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d backed for request name pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06
I0515 15:28:46.516738       1 omap.go:159] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 set omap keys (pool="kube", namespace="", name="csi.volume.e3843186-d88a-4dd3-bc81-3134193c961d"): map[csi.imageid:37d6f1ea7209])
I0515 15:28:46.606759       1 utils.go:205] ID: 24 Req-ID: pvc-9b40474f-75b5-4d6a-9031-3ce86eeded06 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-e3843186-d88a-4dd3-bc81-3134193c961d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e3843186-d88a-4dd3-bc81-3134193c961d"}}
I0515 15:29:33.268941       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0515 15:29:33.269326       1 utils.go:199] ID: 25 GRPC request: {}
I0515 15:29:33.269518       1 utils.go:205] ID: 25 GRPC response: {}