I0510 04:03:45.427389       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0510 04:03:45.427576       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0510 04:03:45.427618       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0510 04:03:45.427626       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0510 04:03:45.427630       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0510 04:03:45.427651       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0510 04:03:45.427660       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0510 04:03:45.427679       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0510 04:03:45.427688       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0510 04:03:45.427693       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0510 04:03:45.428168       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0510 04:03:45.428167       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0510 04:03:54.128495       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:54.130467       1 utils.go:199] ID: 1 GRPC request: {}
I0510 04:03:54.130545       1 utils.go:205] ID: 1 GRPC response: {}
I0510 04:03:54.136310       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0510 04:03:54.136358       1 utils.go:199] ID: 2 GRPC request: {}
I0510 04:03:54.136370       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0510 04:03:54.136420       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0510 04:03:54.137880       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:54.137972       1 utils.go:199] ID: 3 GRPC request: {}
I0510 04:03:54.138039       1 utils.go:205] ID: 3 GRPC response: {}
I0510 04:03:54.138590       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0510 04:03:54.138662       1 utils.go:199] ID: 4 GRPC request: {}
I0510 04:03:54.138787       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0510 04:03:54.139443       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:54.139472       1 utils.go:199] ID: 5 GRPC request: {}
I0510 04:03:54.139479       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0510 04:03:54.139574       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}}}]}
I0510 04:03:55.282795       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:55.282829       1 utils.go:199] ID: 6 GRPC request: {}
I0510 04:03:55.282853       1 utils.go:205] ID: 6 GRPC response: {}
I0510 04:03:55.286889       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0510 04:03:55.286914       1 utils.go:199] ID: 7 GRPC request: {}
I0510 04:03:55.286920       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0510 04:03:55.286938       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0510 04:03:55.289229       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:55.289252       1 utils.go:199] ID: 8 GRPC request: {}
I0510 04:03:55.289263       1 utils.go:205] ID: 8 GRPC response: {}
I0510 04:03:55.289821       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0510 04:03:55.289849       1 utils.go:199] ID: 9 GRPC request: {}
I0510 04:03:55.289945       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0510 04:03:55.290675       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:55.290695       1 utils.go:199] ID: 10 GRPC request: {}
I0510 04:03:55.290703       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0510 04:03:55.290865       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}}}]}
I0510 04:03:55.291545       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:55.291560       1 utils.go:199] ID: 11 GRPC request: {}
I0510 04:03:55.291564       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0510 04:03:55.291635       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}}}]}
I0510 04:03:55.291983       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:55.291995       1 utils.go:199] ID: 12 GRPC request: {}
I0510 04:03:55.291999       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0510 04:03:55.292073       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}}}]}
I0510 04:03:56.472335       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0510 04:03:56.472378       1 utils.go:199] ID: 13 GRPC request: {}
I0510 04:03:56.472388       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0510 04:03:56.472414       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0510 04:03:56.474574       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:56.474594       1 utils.go:199] ID: 14 GRPC request: {}
I0510 04:03:56.474607       1 utils.go:205] ID: 14 GRPC response: {}
I0510 04:03:56.474961       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:56.474980       1 utils.go:199] ID: 15 GRPC request: {}
I0510 04:03:56.474989       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0510 04:03:56.475091       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}}}]}
I0510 04:03:57.671553       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:57.671601       1 utils.go:199] ID: 16 GRPC request: {}
I0510 04:03:57.671618       1 utils.go:205] ID: 16 GRPC response: {}
I0510 04:03:57.678118       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0510 04:03:57.678142       1 utils.go:199] ID: 17 GRPC request: {}
I0510 04:03:57.678155       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0510 04:03:57.678179       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0510 04:03:57.680498       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0510 04:03:57.680520       1 utils.go:199] ID: 18 GRPC request: {}
I0510 04:03:57.680531       1 utils.go:205] ID: 18 GRPC response: {}
I0510 04:03:57.681078       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0510 04:03:57.681115       1 utils.go:199] ID: 19 GRPC request: {}
I0510 04:03:57.681202       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0510 04:03:57.682028       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0510 04:03:57.682061       1 utils.go:199] ID: 20 GRPC request: {}
I0510 04:03:57.682070       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0510 04:03:57.682159       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}}}]}
I0510 04:04:57.912836       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0510 04:04:57.913028       1 utils.go:199] ID: 21 GRPC request: {}
I0510 04:04:57.913262       1 utils.go:205] ID: 21 GRPC response: {}
I0510 04:05:57.857734       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0510 04:05:57.857944       1 utils.go:199] ID: 22 GRPC request: {}
I0510 04:05:57.858137       1 utils.go:205] ID: 22 GRPC response: {}
I0510 04:06:55.899953       1 utils.go:198] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded GRPC call: /csi.v1.Controller/CreateVolume
I0510 04:06:55.900737       1 utils.go:199] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded","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}}]}
I0510 04:06:55.901169       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded setting disableInUseChecks: false image features: [layering] mounter: rbd
E0510 04:06:55.922312       1 omap.go:80] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0510 04:06:55.937921       1 omap.go:159] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded:47941a37-be02-4568-b8ae-404371d44eaa])
I0510 04:06:55.945982       1 omap.go:159] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded set omap keys (pool="kube", namespace="", name="csi.volume.47941a37-be02-4568-b8ae-404371d44eaa"): map[csi.imagename:csi-vol-47941a37-be02-4568-b8ae-404371d44eaa csi.volname:pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded csi.volume.owner:default])
I0510 04:06:55.946032       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-47941a37-be02-4568-b8ae-404371d44eaa) and image name (csi-vol-47941a37-be02-4568-b8ae-404371d44eaa) for request name (pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded)
I0510 04:06:55.946118       1 rbd_util.go:423] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded rbd: create kube/csi-vol-47941a37-be02-4568-b8ae-404371d44eaa size 5120M (features: [layering]) using mon 199.204.45.162
I0510 04:06:55.946180       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded setting image options on kube/csi-vol-47941a37-be02-4568-b8ae-404371d44eaa
I0510 04:06:57.393882       1 controllerserver.go:763] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded created image kube/csi-vol-47941a37-be02-4568-b8ae-404371d44eaa backed for request name pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded
I0510 04:06:57.427063       1 omap.go:159] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded set omap keys (pool="kube", namespace="", name="csi.volume.47941a37-be02-4568-b8ae-404371d44eaa"): map[csi.imageid:37d98902adb3])
I0510 04:06:57.523536       1 utils.go:205] ID: 23 Req-ID: pvc-3af9e14d-9d41-4abf-b6d7-3ae85df03ded GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-47941a37-be02-4568-b8ae-404371d44eaa","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-47941a37-be02-4568-b8ae-404371d44eaa"}}
I0510 04:06:57.853596       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0510 04:06:57.853659       1 utils.go:199] ID: 24 GRPC request: {}
I0510 04:06:57.853773       1 utils.go:205] ID: 24 GRPC response: {}