I0224 04:34:41.044990       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0224 04:34:41.045186       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0224 04:34:41.045211       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0224 04:34:41.045218       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0224 04:34:41.045221       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0224 04:34:41.045225       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0224 04:34:41.045231       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0224 04:34:41.045254       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0224 04:34:41.045261       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0224 04:34:41.045264       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0224 04:34:41.045663       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0224 04:34:41.045682       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0224 04:34:43.602573       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0224 04:34:43.603895       1 utils.go:199] ID: 1 GRPC request: {}
I0224 04:34:43.603990       1 utils.go:205] ID: 1 GRPC response: {}
I0224 04:34:43.610712       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 04:34:43.610802       1 utils.go:199] ID: 2 GRPC request: {}
I0224 04:34:43.610824       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0224 04:34:43.610880       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 04:34:43.612384       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0224 04:34:43.612480       1 utils.go:199] ID: 3 GRPC request: {}
I0224 04:34:43.612526       1 utils.go:205] ID: 3 GRPC response: {}
I0224 04:34:43.612778       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 04:34:43.612878       1 utils.go:199] ID: 4 GRPC request: {}
I0224 04:34:43.613031       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 04:34:43.617300       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:34:43.617371       1 utils.go:199] ID: 5 GRPC request: {}
I0224 04:34:43.617389       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0224 04:34:43.617766       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}}}]}
I0224 04:34:53.375924       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0224 04:34:53.375985       1 utils.go:199] ID: 6 GRPC request: {}
I0224 04:34:53.376004       1 utils.go:205] ID: 6 GRPC response: {}
I0224 04:34:53.380783       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 04:34:53.380800       1 utils.go:199] ID: 7 GRPC request: {}
I0224 04:34:53.380807       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0224 04:34:53.380834       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 04:34:53.383801       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0224 04:34:53.383893       1 utils.go:199] ID: 8 GRPC request: {}
I0224 04:34:53.383982       1 utils.go:205] ID: 8 GRPC response: {}
I0224 04:34:53.384751       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 04:34:53.384775       1 utils.go:199] ID: 9 GRPC request: {}
I0224 04:34:53.384893       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 04:34:53.385738       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:34:53.385757       1 utils.go:199] ID: 10 GRPC request: {}
I0224 04:34:53.385763       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0224 04:34:53.385906       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}}}]}
I0224 04:34:53.386552       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:34:53.386566       1 utils.go:199] ID: 11 GRPC request: {}
I0224 04:34:53.386570       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0224 04:34:53.386689       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}}}]}
I0224 04:34:53.387490       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:34:53.387519       1 utils.go:199] ID: 12 GRPC request: {}
I0224 04:34:53.387529       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0224 04:34:53.387740       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}}}]}
I0224 04:34:59.593104       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 04:34:59.593167       1 utils.go:199] ID: 13 GRPC request: {}
I0224 04:34:59.593179       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0224 04:34:59.593255       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 04:34:59.596481       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0224 04:34:59.596502       1 utils.go:199] ID: 14 GRPC request: {}
I0224 04:34:59.596518       1 utils.go:205] ID: 14 GRPC response: {}
I0224 04:34:59.597283       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:34:59.597304       1 utils.go:199] ID: 15 GRPC request: {}
I0224 04:34:59.597314       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0224 04:34:59.597463       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}}}]}
I0224 04:35:01.750322       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0224 04:35:01.750401       1 utils.go:199] ID: 16 GRPC request: {}
I0224 04:35:01.750446       1 utils.go:205] ID: 16 GRPC response: {}
I0224 04:35:01.754640       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 04:35:01.755281       1 utils.go:199] ID: 17 GRPC request: {}
I0224 04:35:01.756788       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0224 04:35:01.757888       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 04:35:01.761028       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0224 04:35:01.761096       1 utils.go:199] ID: 18 GRPC request: {}
I0224 04:35:01.761131       1 utils.go:205] ID: 18 GRPC response: {}
I0224 04:35:01.761787       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 04:35:01.761819       1 utils.go:199] ID: 19 GRPC request: {}
I0224 04:35:01.761998       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 04:35:01.763406       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:35:01.763447       1 utils.go:199] ID: 20 GRPC request: {}
I0224 04:35:01.763457       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0224 04:35:01.763681       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}}}]}
I0224 04:36:02.023887       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0224 04:36:02.023971       1 utils.go:199] ID: 21 GRPC request: {}
I0224 04:36:02.023993       1 utils.go:205] ID: 21 GRPC response: {}
I0224 04:37:01.962929       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0224 04:37:01.963032       1 utils.go:199] ID: 22 GRPC request: {}
I0224 04:37:01.963164       1 utils.go:205] ID: 22 GRPC response: {}
I0224 04:37:58.189944       1 utils.go:198] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c GRPC call: /csi.v1.Controller/CreateVolume
I0224 04:37:58.190464       1 utils.go:199] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c","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}}]}
I0224 04:37:58.190798       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c setting disableInUseChecks: false image features: [layering] mounter: rbd
E0224 04:37:58.211682       1 omap.go:80] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0224 04:37:58.228806       1 omap.go:159] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c:d749264b-9a7f-42f3-93a9-0a31b02d413a])
I0224 04:37:58.235600       1 omap.go:159] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c set omap keys (pool="kube", namespace="", name="csi.volume.d749264b-9a7f-42f3-93a9-0a31b02d413a"): map[csi.imagename:csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a csi.volname:pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c csi.volume.owner:default])
I0224 04:37:58.235641       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d749264b-9a7f-42f3-93a9-0a31b02d413a) and image name (csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a) for request name (pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c)
I0224 04:37:58.235722       1 rbd_util.go:423] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c rbd: create kube/csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a size 5120M (features: [layering]) using mon 162.253.55.43
I0224 04:37:58.235791       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c setting image options on kube/csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a
I0224 04:38:00.088406       1 controllerserver.go:763] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c created image kube/csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a backed for request name pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c
I0224 04:38:00.123435       1 omap.go:159] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c set omap keys (pool="kube", namespace="", name="csi.volume.d749264b-9a7f-42f3-93a9-0a31b02d413a"): map[csi.imageid:37d6c4f65e72])
I0224 04:38:00.234812       1 utils.go:205] ID: 23 Req-ID: pvc-173befbd-86c1-4d6c-ac62-1cb9372b2b1c GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d749264b-9a7f-42f3-93a9-0a31b02d413a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d749264b-9a7f-42f3-93a9-0a31b02d413a"}}
I0224 04:38:01.962487       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0224 04:38:01.962653       1 utils.go:199] ID: 24 GRPC request: {}
I0224 04:38:01.962708       1 utils.go:205] ID: 24 GRPC response: {}