I0420 11:53:12.925574       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0420 11:53:12.925714       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0420 11:53:12.925728       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0420 11:53:12.925750       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0420 11:53:12.925758       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0420 11:53:12.925761       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0420 11:53:12.925765       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0420 11:53:12.925768       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0420 11:53:12.925771       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0420 11:53:12.925775       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0420 11:53:12.926065       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0420 11:53:12.926081       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0420 11:53:15.109595       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:15.111363       1 utils.go:199] ID: 1 GRPC request: {}
I0420 11:53:15.111426       1 utils.go:205] ID: 1 GRPC response: {}
I0420 11:53:15.115631       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 11:53:15.115667       1 utils.go:199] ID: 2 GRPC request: {}
I0420 11:53:15.115679       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0420 11:53:15.115710       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 11:53:15.117191       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:15.117245       1 utils.go:199] ID: 3 GRPC request: {}
I0420 11:53:15.117268       1 utils.go:205] ID: 3 GRPC response: {}
I0420 11:53:15.117617       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 11:53:15.117671       1 utils.go:199] ID: 4 GRPC request: {}
I0420 11:53:15.117794       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 11:53:15.118487       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:15.118554       1 utils.go:199] ID: 5 GRPC request: {}
I0420 11:53:15.118565       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0420 11:53:15.118715       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}}}]}
I0420 11:53:16.283497       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:16.283552       1 utils.go:199] ID: 6 GRPC request: {}
I0420 11:53:16.283577       1 utils.go:205] ID: 6 GRPC response: {}
I0420 11:53:16.289865       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 11:53:16.289889       1 utils.go:199] ID: 7 GRPC request: {}
I0420 11:53:16.289897       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0420 11:53:16.289920       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 11:53:16.291859       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:16.291976       1 utils.go:199] ID: 8 GRPC request: {}
I0420 11:53:16.292095       1 utils.go:205] ID: 8 GRPC response: {}
I0420 11:53:16.292824       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 11:53:16.292854       1 utils.go:199] ID: 9 GRPC request: {}
I0420 11:53:16.292998       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 11:53:16.294028       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:16.294054       1 utils.go:199] ID: 10 GRPC request: {}
I0420 11:53:16.294064       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0420 11:53:16.294140       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}}}]}
I0420 11:53:16.294522       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:16.294538       1 utils.go:199] ID: 11 GRPC request: {}
I0420 11:53:16.294543       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0420 11:53:16.294599       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}}}]}
I0420 11:53:16.294877       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:16.294897       1 utils.go:199] ID: 12 GRPC request: {}
I0420 11:53:16.294902       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0420 11:53:16.294960       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}}}]}
I0420 11:53:17.745799       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 11:53:17.745971       1 utils.go:199] ID: 13 GRPC request: {}
I0420 11:53:17.746692       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0420 11:53:17.746852       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 11:53:17.750871       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:17.750924       1 utils.go:199] ID: 14 GRPC request: {}
I0420 11:53:17.750956       1 utils.go:205] ID: 14 GRPC response: {}
I0420 11:53:17.751374       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:17.751393       1 utils.go:199] ID: 15 GRPC request: {}
I0420 11:53:17.751402       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0420 11:53:17.751488       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}}}]}
I0420 11:53:21.267019       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:21.267081       1 utils.go:199] ID: 16 GRPC request: {}
I0420 11:53:21.267100       1 utils.go:205] ID: 16 GRPC response: {}
I0420 11:53:21.270571       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 11:53:21.270623       1 utils.go:199] ID: 17 GRPC request: {}
I0420 11:53:21.270632       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0420 11:53:21.270660       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 11:53:21.274113       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0420 11:53:21.274138       1 utils.go:199] ID: 18 GRPC request: {}
I0420 11:53:21.274153       1 utils.go:205] ID: 18 GRPC response: {}
I0420 11:53:21.274498       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 11:53:21.274518       1 utils.go:199] ID: 19 GRPC request: {}
I0420 11:53:21.274618       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 11:53:21.275387       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 11:53:21.275516       1 utils.go:199] ID: 20 GRPC request: {}
I0420 11:53:21.275539       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0420 11:53:21.275628       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}}}]}
I0420 11:54:21.511927       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0420 11:54:21.511996       1 utils.go:199] ID: 21 GRPC request: {}
I0420 11:54:21.512018       1 utils.go:205] ID: 21 GRPC response: {}
I0420 11:55:21.477907       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0420 11:55:21.478014       1 utils.go:199] ID: 22 GRPC request: {}
I0420 11:55:21.478040       1 utils.go:205] ID: 22 GRPC response: {}
I0420 11:56:21.474784       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0420 11:56:21.474838       1 utils.go:199] ID: 23 GRPC request: {}
I0420 11:56:21.474860       1 utils.go:205] ID: 23 GRPC response: {}
I0420 11:56:22.340210       1 utils.go:198] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e GRPC call: /csi.v1.Controller/CreateVolume
I0420 11:56:22.340483       1 utils.go:199] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e","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}}]}
I0420 11:56:22.340769       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e setting disableInUseChecks: false image features: [layering] mounter: rbd
E0420 11:56:22.363269       1 omap.go:80] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0420 11:56:22.381884       1 omap.go:159] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e:2103c438-f29d-4293-80dc-4981845c662c])
I0420 11:56:22.389322       1 omap.go:159] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e set omap keys (pool="kube", namespace="", name="csi.volume.2103c438-f29d-4293-80dc-4981845c662c"): map[csi.imagename:csi-vol-2103c438-f29d-4293-80dc-4981845c662c csi.volname:pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e csi.volume.owner:default])
I0420 11:56:22.389375       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2103c438-f29d-4293-80dc-4981845c662c) and image name (csi-vol-2103c438-f29d-4293-80dc-4981845c662c) for request name (pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e)
I0420 11:56:22.389522       1 rbd_util.go:423] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e rbd: create kube/csi-vol-2103c438-f29d-4293-80dc-4981845c662c size 5120M (features: [layering]) using mon 199.204.45.138
I0420 11:56:22.389586       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e setting image options on kube/csi-vol-2103c438-f29d-4293-80dc-4981845c662c
I0420 11:56:24.437426       1 controllerserver.go:763] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e created image kube/csi-vol-2103c438-f29d-4293-80dc-4981845c662c backed for request name pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e
I0420 11:56:24.472237       1 omap.go:159] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e set omap keys (pool="kube", namespace="", name="csi.volume.2103c438-f29d-4293-80dc-4981845c662c"): map[csi.imageid:37d928198d97])
I0420 11:56:24.573171       1 utils.go:205] ID: 24 Req-ID: pvc-7d4736f2-5c48-4067-87e4-82dc1af5b32e GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-2103c438-f29d-4293-80dc-4981845c662c","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2103c438-f29d-4293-80dc-4981845c662c"}}