I0812 17:44:27.742937       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0812 17:44:27.743056       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0812 17:44:27.743066       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0812 17:44:27.743070       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0812 17:44:27.743073       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0812 17:44:27.743075       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0812 17:44:27.743078       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0812 17:44:27.743081       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0812 17:44:27.743084       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0812 17:44:27.743100       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0812 17:44:27.743343       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0812 17:44:27.743364       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0812 17:44:36.232546       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:36.234591       1 utils.go:199] ID: 1 GRPC request: {}
I0812 17:44:36.234694       1 utils.go:205] ID: 1 GRPC response: {}
I0812 17:44:36.243526       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0812 17:44:36.243581       1 utils.go:199] ID: 2 GRPC request: {}
I0812 17:44:36.243594       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0812 17:44:36.243635       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0812 17:44:36.247282       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:36.247310       1 utils.go:199] ID: 3 GRPC request: {}
I0812 17:44:36.247324       1 utils.go:205] ID: 3 GRPC response: {}
I0812 17:44:36.247717       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0812 17:44:36.247761       1 utils.go:199] ID: 4 GRPC request: {}
I0812 17:44:36.247880       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0812 17:44:36.248812       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:36.248854       1 utils.go:199] ID: 5 GRPC request: {}
I0812 17:44:36.248861       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0812 17:44:36.248964       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}}}]}
I0812 17:44:41.947426       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:41.947478       1 utils.go:199] ID: 6 GRPC request: {}
I0812 17:44:41.947495       1 utils.go:205] ID: 6 GRPC response: {}
I0812 17:44:41.951739       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0812 17:44:41.951765       1 utils.go:199] ID: 7 GRPC request: {}
I0812 17:44:41.951773       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0812 17:44:41.951794       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0812 17:44:41.954692       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:41.954827       1 utils.go:199] ID: 8 GRPC request: {}
I0812 17:44:41.954894       1 utils.go:205] ID: 8 GRPC response: {}
I0812 17:44:41.955528       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0812 17:44:41.955564       1 utils.go:199] ID: 9 GRPC request: {}
I0812 17:44:41.955708       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0812 17:44:41.956367       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:41.956386       1 utils.go:199] ID: 10 GRPC request: {}
I0812 17:44:41.956392       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0812 17:44:41.956441       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}}}]}
I0812 17:44:41.956920       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:41.956938       1 utils.go:199] ID: 11 GRPC request: {}
I0812 17:44:41.956942       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0812 17:44:41.956990       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}}}]}
I0812 17:44:41.957337       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:41.957355       1 utils.go:199] ID: 12 GRPC request: {}
I0812 17:44:41.957362       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0812 17:44:41.957404       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}}}]}
I0812 17:44:43.712566       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0812 17:44:43.712601       1 utils.go:199] ID: 13 GRPC request: {}
I0812 17:44:43.712608       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0812 17:44:43.712630       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0812 17:44:43.716612       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:43.716648       1 utils.go:199] ID: 14 GRPC request: {}
I0812 17:44:43.716665       1 utils.go:205] ID: 14 GRPC response: {}
I0812 17:44:43.717222       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:43.717246       1 utils.go:199] ID: 15 GRPC request: {}
I0812 17:44:43.717253       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0812 17:44:43.717322       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}}}]}
I0812 17:44:45.413844       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:45.414161       1 utils.go:199] ID: 16 GRPC request: {}
I0812 17:44:45.414372       1 utils.go:205] ID: 16 GRPC response: {}
I0812 17:44:45.418926       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0812 17:44:45.418994       1 utils.go:199] ID: 17 GRPC request: {}
I0812 17:44:45.419010       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0812 17:44:45.419057       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0812 17:44:45.421280       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0812 17:44:45.421397       1 utils.go:199] ID: 18 GRPC request: {}
I0812 17:44:45.421470       1 utils.go:205] ID: 18 GRPC response: {}
I0812 17:44:45.422292       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0812 17:44:45.422324       1 utils.go:199] ID: 19 GRPC request: {}
I0812 17:44:45.422542       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0812 17:44:45.423253       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0812 17:44:45.423316       1 utils.go:199] ID: 20 GRPC request: {}
I0812 17:44:45.423347       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0812 17:44:45.423485       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}}}]}
I0812 17:45:45.727132       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0812 17:45:45.727179       1 utils.go:199] ID: 21 GRPC request: {}
I0812 17:45:45.727223       1 utils.go:205] ID: 21 GRPC response: {}
I0812 17:46:45.669811       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0812 17:46:45.669884       1 utils.go:199] ID: 22 GRPC request: {}
I0812 17:46:45.669909       1 utils.go:205] ID: 22 GRPC response: {}
I0812 17:47:29.001501       1 utils.go:198] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 GRPC call: /csi.v1.Controller/CreateVolume
I0812 17:47:29.001977       1 utils.go:199] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070","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}}]}
I0812 17:47:29.002442       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0812 17:47:29.024323       1 omap.go:80] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0812 17:47:29.033635       1 omap.go:159] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070:7f72990c-c82f-4110-96d1-efe5808498d4])
I0812 17:47:29.037341       1 omap.go:159] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 set omap keys (pool="kube", namespace="", name="csi.volume.7f72990c-c82f-4110-96d1-efe5808498d4"): map[csi.imagename:csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4 csi.volname:pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 csi.volume.owner:default])
I0812 17:47:29.037371       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7f72990c-c82f-4110-96d1-efe5808498d4) and image name (csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4) for request name (pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070)
I0812 17:47:29.037443       1 rbd_util.go:423] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 rbd: create kube/csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4 size 5120M (features: [layering]) using mon 199.19.213.176
I0812 17:47:29.037488       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 setting image options on kube/csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4
I0812 17:47:29.058202       1 controllerserver.go:763] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 created image kube/csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4 backed for request name pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070
I0812 17:47:29.078622       1 omap.go:159] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 set omap keys (pool="kube", namespace="", name="csi.volume.7f72990c-c82f-4110-96d1-efe5808498d4"): map[csi.imageid:380343a7d5ee])
I0812 17:47:29.146859       1 utils.go:205] ID: 23 Req-ID: pvc-ca3bacae-c6c0-498e-ad61-7d323b71b070 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-7f72990c-c82f-4110-96d1-efe5808498d4","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7f72990c-c82f-4110-96d1-efe5808498d4"}}
I0812 17:47:45.668561       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0812 17:47:45.668636       1 utils.go:199] ID: 24 GRPC request: {}
I0812 17:47:45.668869       1 utils.go:205] ID: 24 GRPC response: {}