I0423 13:46:29.584578       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0423 13:46:29.584693       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0423 13:46:29.584710       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0423 13:46:29.584713       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0423 13:46:29.584717       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0423 13:46:29.584720       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0423 13:46:29.584724       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0423 13:46:29.584727       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0423 13:46:29.584730       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0423 13:46:29.584749       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0423 13:46:29.585193       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0423 13:46:29.585213       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0423 13:46:45.197907       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0423 13:46:45.199501       1 utils.go:199] ID: 1 GRPC request: {}
I0423 13:46:45.199580       1 utils.go:205] ID: 1 GRPC response: {}
I0423 13:46:45.201859       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0423 13:46:45.201959       1 utils.go:199] ID: 2 GRPC request: {}
I0423 13:46:45.201977       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0423 13:46:45.202061       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0423 13:46:45.203502       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0423 13:46:45.203533       1 utils.go:199] ID: 3 GRPC request: {}
I0423 13:46:45.203576       1 utils.go:205] ID: 3 GRPC response: {}
I0423 13:46:45.203984       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0423 13:46:45.204055       1 utils.go:199] ID: 4 GRPC request: {}
I0423 13:46:45.204816       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0423 13:46:45.205666       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:46:45.205803       1 utils.go:199] ID: 5 GRPC request: {}
I0423 13:46:45.205846       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0423 13:46:45.206052       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}}}]}
I0423 13:46:47.217207       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0423 13:46:47.217240       1 utils.go:199] ID: 6 GRPC request: {}
I0423 13:46:47.217257       1 utils.go:205] ID: 6 GRPC response: {}
I0423 13:46:47.219884       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0423 13:46:47.219939       1 utils.go:199] ID: 7 GRPC request: {}
I0423 13:46:47.219951       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0423 13:46:47.219995       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0423 13:46:47.223435       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0423 13:46:47.223469       1 utils.go:199] ID: 8 GRPC request: {}
I0423 13:46:47.223487       1 utils.go:205] ID: 8 GRPC response: {}
I0423 13:46:47.224710       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0423 13:46:47.224755       1 utils.go:199] ID: 9 GRPC request: {}
I0423 13:46:47.224844       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0423 13:46:47.225522       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:46:47.225568       1 utils.go:199] ID: 10 GRPC request: {}
I0423 13:46:47.225580       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0423 13:46:47.225716       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}}}]}
I0423 13:46:47.226259       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:46:47.226279       1 utils.go:199] ID: 11 GRPC request: {}
I0423 13:46:47.226287       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0423 13:46:47.226357       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}}}]}
I0423 13:46:47.226740       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:46:47.226817       1 utils.go:199] ID: 12 GRPC request: {}
I0423 13:46:47.226827       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0423 13:46:47.226895       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}}}]}
I0423 13:46:48.916788       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0423 13:46:48.916841       1 utils.go:199] ID: 13 GRPC request: {}
I0423 13:46:48.916854       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0423 13:46:48.916899       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0423 13:46:48.920928       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0423 13:46:48.920948       1 utils.go:199] ID: 14 GRPC request: {}
I0423 13:46:48.920963       1 utils.go:205] ID: 14 GRPC response: {}
I0423 13:46:48.921439       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:46:48.921492       1 utils.go:199] ID: 15 GRPC request: {}
I0423 13:46:48.921507       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0423 13:46:48.921602       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}}}]}
I0423 13:47:15.759553       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0423 13:47:15.759632       1 utils.go:199] ID: 16 GRPC request: {}
I0423 13:47:15.759673       1 utils.go:205] ID: 16 GRPC response: {}
I0423 13:47:15.762095       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0423 13:47:15.762133       1 utils.go:199] ID: 17 GRPC request: {}
I0423 13:47:15.762143       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0423 13:47:15.762194       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0423 13:47:15.766782       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0423 13:47:15.766823       1 utils.go:199] ID: 18 GRPC request: {}
I0423 13:47:15.766851       1 utils.go:205] ID: 18 GRPC response: {}
I0423 13:47:15.767238       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0423 13:47:15.767272       1 utils.go:199] ID: 19 GRPC request: {}
I0423 13:47:15.767428       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0423 13:47:15.768080       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0423 13:47:15.768118       1 utils.go:199] ID: 20 GRPC request: {}
I0423 13:47:15.768136       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0423 13:47:15.768230       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}}}]}
I0423 13:48:15.918857       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0423 13:48:15.918957       1 utils.go:199] ID: 21 GRPC request: {}
I0423 13:48:15.919015       1 utils.go:205] ID: 21 GRPC response: {}
I0423 13:49:15.919848       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0423 13:49:15.919918       1 utils.go:199] ID: 22 GRPC request: {}
I0423 13:49:15.920077       1 utils.go:205] ID: 22 GRPC response: {}
I0423 13:49:40.903545       1 utils.go:198] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 GRPC call: /csi.v1.Controller/CreateVolume
I0423 13:49:40.903996       1 utils.go:199] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9","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}}]}
I0423 13:49:40.904247       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0423 13:49:40.920953       1 omap.go:80] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0423 13:49:40.936783       1 omap.go:159] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9:4730678a-ac8f-4897-8373-00da183a0119])
I0423 13:49:40.944501       1 omap.go:159] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 set omap keys (pool="kube", namespace="", name="csi.volume.4730678a-ac8f-4897-8373-00da183a0119"): map[csi.imagename:csi-vol-4730678a-ac8f-4897-8373-00da183a0119 csi.volname:pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 csi.volume.owner:default])
I0423 13:49:40.944681       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4730678a-ac8f-4897-8373-00da183a0119) and image name (csi-vol-4730678a-ac8f-4897-8373-00da183a0119) for request name (pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9)
I0423 13:49:40.944918       1 rbd_util.go:423] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 rbd: create kube/csi-vol-4730678a-ac8f-4897-8373-00da183a0119 size 5120M (features: [layering]) using mon 199.204.45.250
I0423 13:49:40.945063       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 setting image options on kube/csi-vol-4730678a-ac8f-4897-8373-00da183a0119
I0423 13:49:42.791815       1 controllerserver.go:763] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 created image kube/csi-vol-4730678a-ac8f-4897-8373-00da183a0119 backed for request name pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9
I0423 13:49:42.819330       1 omap.go:159] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 set omap keys (pool="kube", namespace="", name="csi.volume.4730678a-ac8f-4897-8373-00da183a0119"): map[csi.imageid:37d91e8ecb9e])
I0423 13:49:42.915760       1 utils.go:205] ID: 23 Req-ID: pvc-74ffc66a-5164-4462-b3ae-da7c65cfccc9 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-4730678a-ac8f-4897-8373-00da183a0119","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4730678a-ac8f-4897-8373-00da183a0119"}}
I0423 13:50:15.918357       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0423 13:50:15.918423       1 utils.go:199] ID: 24 GRPC request: {}
I0423 13:50:15.918453       1 utils.go:205] ID: 24 GRPC response: {}