I0416 02:39:57.896340       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0416 02:39:57.896451       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0416 02:39:57.896464       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0416 02:39:57.896468       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0416 02:39:57.896470       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0416 02:39:57.896473       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0416 02:39:57.896476       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0416 02:39:57.896479       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0416 02:39:57.896482       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0416 02:39:57.896487       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0416 02:39:57.896786       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0416 02:39:57.896810       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0416 02:40:00.792368       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:00.793755       1 utils.go:199] ID: 1 GRPC request: {}
I0416 02:40:00.793876       1 utils.go:205] ID: 1 GRPC response: {}
I0416 02:40:00.797547       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0416 02:40:00.797759       1 utils.go:199] ID: 2 GRPC request: {}
I0416 02:40:00.797843       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0416 02:40:00.797991       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0416 02:40:00.799479       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:00.799537       1 utils.go:199] ID: 3 GRPC request: {}
I0416 02:40:00.799570       1 utils.go:205] ID: 3 GRPC response: {}
I0416 02:40:00.800023       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0416 02:40:00.800114       1 utils.go:199] ID: 4 GRPC request: {}
I0416 02:40:00.800300       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0416 02:40:00.801003       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:00.801091       1 utils.go:199] ID: 5 GRPC request: {}
I0416 02:40:00.801136       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0416 02:40:00.801312       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}}}]}
I0416 02:40:01.031533       1 utils.go:198] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 GRPC call: /csi.v1.Controller/CreateVolume
I0416 02:40:01.031956       1 utils.go:199] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530","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}}]}
I0416 02:40:01.032299       1 rbd_util.go:1315] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0416 02:40:01.047469       1 omap.go:80] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0416 02:40:01.093552       1 omap.go:159] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530:23ff7cb1-0592-4c6a-9d0b-ec3adb8df590])
I0416 02:40:01.133724       1 omap.go:159] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 set omap keys (pool="kube", namespace="", name="csi.volume.23ff7cb1-0592-4c6a-9d0b-ec3adb8df590"): map[csi.imagename:csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590 csi.volname:pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 csi.volume.owner:default])
I0416 02:40:01.134413       1 rbd_journal.go:491] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590) and image name (csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590) for request name (pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530)
I0416 02:40:01.134610       1 rbd_util.go:423] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 rbd: create kube/csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590 size 5120M (features: [layering]) using mon 199.19.213.107
I0416 02:40:01.134761       1 rbd_util.go:1563] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 setting image options on kube/csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590
I0416 02:40:10.204408       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:10.204447       1 utils.go:199] ID: 7 GRPC request: {}
I0416 02:40:10.204463       1 utils.go:205] ID: 7 GRPC response: {}
I0416 02:40:10.208372       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/GetPluginInfo
I0416 02:40:10.208406       1 utils.go:199] ID: 8 GRPC request: {}
I0416 02:40:10.208420       1 identityserver-default.go:40] ID: 8 Using default GetPluginInfo
I0416 02:40:10.208448       1 utils.go:205] ID: 8 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0416 02:40:10.211742       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:10.211764       1 utils.go:199] ID: 9 GRPC request: {}
I0416 02:40:10.211777       1 utils.go:205] ID: 9 GRPC response: {}
I0416 02:40:10.212463       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0416 02:40:10.212507       1 utils.go:199] ID: 10 GRPC request: {}
I0416 02:40:10.212676       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0416 02:40:10.213770       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:10.213819       1 utils.go:199] ID: 11 GRPC request: {}
I0416 02:40:10.213834       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0416 02:40:10.214019       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}}}]}
I0416 02:40:10.214776       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:10.214812       1 utils.go:199] ID: 12 GRPC request: {}
I0416 02:40:10.214824       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0416 02:40:10.214929       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}}}]}
I0416 02:40:10.215747       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:10.215779       1 utils.go:199] ID: 13 GRPC request: {}
I0416 02:40:10.215790       1 controllerserver-default.go:42] ID: 13 Using default ControllerGetCapabilities
I0416 02:40:10.215948       1 utils.go:205] ID: 13 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0416 02:40:10.222597       1 controllerserver.go:763] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 created image kube/csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590 backed for request name pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530
I0416 02:40:10.264979       1 omap.go:159] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 set omap keys (pool="kube", namespace="", name="csi.volume.23ff7cb1-0592-4c6a-9d0b-ec3adb8df590"): map[csi.imageid:37b5593ad2b3])
I0416 02:40:10.385063       1 utils.go:205] ID: 6 Req-ID: pvc-b594d3f5-c7fb-4955-8c34-764dd4d25530 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-23ff7cb1-0592-4c6a-9d0b-ec3adb8df590"}}
I0416 02:40:12.204726       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo
I0416 02:40:12.204787       1 utils.go:199] ID: 14 GRPC request: {}
I0416 02:40:12.204801       1 identityserver-default.go:40] ID: 14 Using default GetPluginInfo
I0416 02:40:12.204869       1 utils.go:205] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0416 02:40:12.208260       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:12.208284       1 utils.go:199] ID: 15 GRPC request: {}
I0416 02:40:12.208297       1 utils.go:205] ID: 15 GRPC response: {}
I0416 02:40:12.208743       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:12.208778       1 utils.go:199] ID: 16 GRPC request: {}
I0416 02:40:12.208787       1 controllerserver-default.go:42] ID: 16 Using default ControllerGetCapabilities
I0416 02:40:12.208879       1 utils.go:205] ID: 16 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0416 02:40:13.635978       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:13.636043       1 utils.go:199] ID: 17 GRPC request: {}
I0416 02:40:13.636073       1 utils.go:205] ID: 17 GRPC response: {}
I0416 02:40:13.643025       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0416 02:40:13.643070       1 utils.go:199] ID: 18 GRPC request: {}
I0416 02:40:13.643081       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0416 02:40:13.643112       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0416 02:40:13.645160       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0416 02:40:13.645188       1 utils.go:199] ID: 19 GRPC request: {}
I0416 02:40:13.645204       1 utils.go:205] ID: 19 GRPC response: {}
I0416 02:40:13.645670       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0416 02:40:13.645697       1 utils.go:199] ID: 20 GRPC request: {}
I0416 02:40:13.645785       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0416 02:40:13.646670       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0416 02:40:13.646734       1 utils.go:199] ID: 21 GRPC request: {}
I0416 02:40:13.646757       1 controllerserver-default.go:42] ID: 21 Using default ControllerGetCapabilities
I0416 02:40:13.646881       1 utils.go:205] ID: 21 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0416 02:41:13.845460       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0416 02:41:13.845510       1 utils.go:199] ID: 22 GRPC request: {}
I0416 02:41:13.845536       1 utils.go:205] ID: 22 GRPC response: {}