I0508 18:23:36.800828       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0508 18:23:36.800971       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0508 18:23:36.800984       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0508 18:23:36.800987       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0508 18:23:36.800990       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0508 18:23:36.800993       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0508 18:23:36.800997       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0508 18:23:36.801000       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0508 18:23:36.801003       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0508 18:23:36.801006       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0508 18:23:36.801306       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0508 18:23:36.801331       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0508 18:23:39.454834       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:39.456274       1 utils.go:199] ID: 1 GRPC request: {}
I0508 18:23:39.456341       1 utils.go:205] ID: 1 GRPC response: {}
I0508 18:23:39.460755       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0508 18:23:39.460860       1 utils.go:199] ID: 2 GRPC request: {}
I0508 18:23:39.461014       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0508 18:23:39.461115       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0508 18:23:39.463146       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:39.463172       1 utils.go:199] ID: 3 GRPC request: {}
I0508 18:23:39.463189       1 utils.go:205] ID: 3 GRPC response: {}
I0508 18:23:39.463963       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0508 18:23:39.464053       1 utils.go:199] ID: 4 GRPC request: {}
I0508 18:23:39.464302       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0508 18:23:39.465140       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:39.465249       1 utils.go:199] ID: 5 GRPC request: {}
I0508 18:23:39.465267       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0508 18:23:39.465469       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}}}]}
I0508 18:23:41.545365       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:41.545461       1 utils.go:199] ID: 6 GRPC request: {}
I0508 18:23:41.545522       1 utils.go:205] ID: 6 GRPC response: {}
I0508 18:23:41.550398       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0508 18:23:41.550542       1 utils.go:199] ID: 7 GRPC request: {}
I0508 18:23:41.550576       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0508 18:23:41.550650       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0508 18:23:41.553119       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:41.553179       1 utils.go:199] ID: 8 GRPC request: {}
I0508 18:23:41.553221       1 utils.go:205] ID: 8 GRPC response: {}
I0508 18:23:41.554068       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0508 18:23:41.554120       1 utils.go:199] ID: 9 GRPC request: {}
I0508 18:23:41.554292       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0508 18:23:41.555286       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:41.555359       1 utils.go:199] ID: 10 GRPC request: {}
I0508 18:23:41.555387       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0508 18:23:41.555540       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}}}]}
I0508 18:23:41.556334       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:41.556378       1 utils.go:199] ID: 11 GRPC request: {}
I0508 18:23:41.556464       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0508 18:23:41.556576       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}}}]}
I0508 18:23:41.556965       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:41.557006       1 utils.go:199] ID: 12 GRPC request: {}
I0508 18:23:41.557090       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0508 18:23:41.557200       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}}}]}
I0508 18:23:42.732420       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0508 18:23:42.732481       1 utils.go:199] ID: 13 GRPC request: {}
I0508 18:23:42.732490       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0508 18:23:42.732534       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0508 18:23:42.734967       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:42.735012       1 utils.go:199] ID: 14 GRPC request: {}
I0508 18:23:42.735034       1 utils.go:205] ID: 14 GRPC response: {}
I0508 18:23:42.736131       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:42.736153       1 utils.go:199] ID: 15 GRPC request: {}
I0508 18:23:42.736161       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0508 18:23:42.736268       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}}}]}
I0508 18:23:44.279859       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:44.280580       1 utils.go:199] ID: 16 GRPC request: {}
I0508 18:23:44.280614       1 utils.go:205] ID: 16 GRPC response: {}
I0508 18:23:44.286029       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0508 18:23:44.286048       1 utils.go:199] ID: 17 GRPC request: {}
I0508 18:23:44.286056       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0508 18:23:44.286184       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0508 18:23:44.288996       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0508 18:23:44.289018       1 utils.go:199] ID: 18 GRPC request: {}
I0508 18:23:44.289030       1 utils.go:205] ID: 18 GRPC response: {}
I0508 18:23:44.289859       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0508 18:23:44.289885       1 utils.go:199] ID: 19 GRPC request: {}
I0508 18:23:44.290003       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0508 18:23:44.290926       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0508 18:23:44.290948       1 utils.go:199] ID: 20 GRPC request: {}
I0508 18:23:44.290957       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0508 18:23:44.291074       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}}}]}
I0508 18:24:44.486542       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0508 18:24:44.486742       1 utils.go:199] ID: 21 GRPC request: {}
I0508 18:24:44.486822       1 utils.go:205] ID: 21 GRPC response: {}
I0508 18:25:44.496329       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0508 18:25:44.496602       1 utils.go:199] ID: 22 GRPC request: {}
I0508 18:25:44.496640       1 utils.go:205] ID: 22 GRPC response: {}
I0508 18:26:44.484589       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0508 18:26:44.484871       1 utils.go:199] ID: 23 GRPC request: {}
I0508 18:26:44.484979       1 utils.go:205] ID: 23 GRPC response: {}
I0508 18:26:57.756076       1 utils.go:198] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab GRPC call: /csi.v1.Controller/CreateVolume
I0508 18:26:57.756641       1 utils.go:199] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab","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}}]}
I0508 18:26:57.756895       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab setting disableInUseChecks: false image features: [layering] mounter: rbd
E0508 18:26:57.777130       1 omap.go:80] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0508 18:26:57.790678       1 omap.go:159] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab:127f9b43-706e-4e6a-ac3b-1241dc20b853])
I0508 18:26:57.796959       1 omap.go:159] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab set omap keys (pool="kube", namespace="", name="csi.volume.127f9b43-706e-4e6a-ac3b-1241dc20b853"): map[csi.imagename:csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853 csi.volname:pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab csi.volume.owner:default])
I0508 18:26:57.797000       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-127f9b43-706e-4e6a-ac3b-1241dc20b853) and image name (csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853) for request name (pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab)
I0508 18:26:57.797076       1 rbd_util.go:423] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab rbd: create kube/csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853 size 5120M (features: [layering]) using mon 199.19.213.171
I0508 18:26:57.797168       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab setting image options on kube/csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853
I0508 18:26:58.980970       1 controllerserver.go:763] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab created image kube/csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853 backed for request name pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab
I0508 18:26:59.011348       1 omap.go:159] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab set omap keys (pool="kube", namespace="", name="csi.volume.127f9b43-706e-4e6a-ac3b-1241dc20b853"): map[csi.imageid:37d9227c321f])
I0508 18:26:59.100487       1 utils.go:205] ID: 24 Req-ID: pvc-720ae84e-7595-4ffa-98f3-2f742a6679ab GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-127f9b43-706e-4e6a-ac3b-1241dc20b853","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-127f9b43-706e-4e6a-ac3b-1241dc20b853"}}
I0508 18:27:44.508452       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0508 18:27:44.508529       1 utils.go:199] ID: 25 GRPC request: {}
I0508 18:27:44.508549       1 utils.go:205] ID: 25 GRPC response: {}