I0306 22:02:18.471084       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0306 22:02:18.471245       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0306 22:02:18.471257       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0306 22:02:18.471260       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0306 22:02:18.471262       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0306 22:02:18.471269       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0306 22:02:18.471273       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0306 22:02:18.471277       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0306 22:02:18.471280       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0306 22:02:18.471282       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0306 22:02:18.471722       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0306 22:02:18.471745       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0306 22:02:27.095273       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:27.096707       1 utils.go:199] ID: 1 GRPC request: {}
I0306 22:02:27.096779       1 utils.go:205] ID: 1 GRPC response: {}
I0306 22:02:27.101320       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0306 22:02:27.101401       1 utils.go:199] ID: 2 GRPC request: {}
I0306 22:02:27.101412       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0306 22:02:27.101446       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0306 22:02:27.102752       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:27.102931       1 utils.go:199] ID: 3 GRPC request: {}
I0306 22:02:27.102998       1 utils.go:205] ID: 3 GRPC response: {}
I0306 22:02:27.103395       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0306 22:02:27.103485       1 utils.go:199] ID: 4 GRPC request: {}
I0306 22:02:27.103735       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0306 22:02:27.104900       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:27.105044       1 utils.go:199] ID: 5 GRPC request: {}
I0306 22:02:27.105063       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0306 22:02:27.105345       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}}}]}
I0306 22:02:35.160601       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:35.160676       1 utils.go:199] ID: 6 GRPC request: {}
I0306 22:02:35.160708       1 utils.go:205] ID: 6 GRPC response: {}
I0306 22:02:35.167384       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0306 22:02:35.167427       1 utils.go:199] ID: 7 GRPC request: {}
I0306 22:02:35.167438       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0306 22:02:35.167476       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0306 22:02:35.170383       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:35.170432       1 utils.go:199] ID: 8 GRPC request: {}
I0306 22:02:35.170457       1 utils.go:205] ID: 8 GRPC response: {}
I0306 22:02:35.170907       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0306 22:02:35.170929       1 utils.go:199] ID: 9 GRPC request: {}
I0306 22:02:35.171026       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0306 22:02:35.171657       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:35.171686       1 utils.go:199] ID: 10 GRPC request: {}
I0306 22:02:35.171698       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0306 22:02:35.171827       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}}}]}
I0306 22:02:35.172353       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:35.172378       1 utils.go:199] ID: 11 GRPC request: {}
I0306 22:02:35.172388       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0306 22:02:35.172476       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}}}]}
I0306 22:02:35.172968       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:35.172987       1 utils.go:199] ID: 12 GRPC request: {}
I0306 22:02:35.172992       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0306 22:02:35.173045       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}}}]}
I0306 22:02:37.159580       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0306 22:02:37.159621       1 utils.go:199] ID: 13 GRPC request: {}
I0306 22:02:37.159630       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0306 22:02:37.159753       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0306 22:02:37.164937       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:37.164972       1 utils.go:199] ID: 14 GRPC request: {}
I0306 22:02:37.165117       1 utils.go:205] ID: 14 GRPC response: {}
I0306 22:02:37.165908       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:37.165967       1 utils.go:199] ID: 15 GRPC request: {}
I0306 22:02:37.165984       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0306 22:02:37.166130       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}}}]}
I0306 22:02:39.748392       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:39.748440       1 utils.go:199] ID: 16 GRPC request: {}
I0306 22:02:39.748463       1 utils.go:205] ID: 16 GRPC response: {}
I0306 22:02:39.755774       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0306 22:02:39.755836       1 utils.go:199] ID: 17 GRPC request: {}
I0306 22:02:39.755855       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0306 22:02:39.755947       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0306 22:02:39.758969       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0306 22:02:39.759074       1 utils.go:199] ID: 18 GRPC request: {}
I0306 22:02:39.759155       1 utils.go:205] ID: 18 GRPC response: {}
I0306 22:02:39.759759       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0306 22:02:39.759777       1 utils.go:199] ID: 19 GRPC request: {}
I0306 22:02:39.759980       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0306 22:02:39.760668       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0306 22:02:39.760686       1 utils.go:199] ID: 20 GRPC request: {}
I0306 22:02:39.760693       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0306 22:02:39.760792       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}}}]}
I0306 22:03:39.963206       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0306 22:03:39.963269       1 utils.go:199] ID: 21 GRPC request: {}
I0306 22:03:39.963321       1 utils.go:205] ID: 21 GRPC response: {}
I0306 22:04:39.965890       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0306 22:04:39.965963       1 utils.go:199] ID: 22 GRPC request: {}
I0306 22:04:39.965990       1 utils.go:205] ID: 22 GRPC response: {}
I0306 22:05:35.459857       1 utils.go:198] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 GRPC call: /csi.v1.Controller/CreateVolume
I0306 22:05:35.460208       1 utils.go:199] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-801c30de-40b8-4e92-a04d-d052f5df7c76","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-801c30de-40b8-4e92-a04d-d052f5df7c76","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}}]}
I0306 22:05:35.460458       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0306 22:05:35.480998       1 omap.go:80] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0306 22:05:35.496898       1 omap.go:159] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-801c30de-40b8-4e92-a04d-d052f5df7c76:6a65bf15-4f16-4d96-ad72-e549102ba180])
I0306 22:05:35.505096       1 omap.go:159] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 set omap keys (pool="kube", namespace="", name="csi.volume.6a65bf15-4f16-4d96-ad72-e549102ba180"): map[csi.imagename:csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180 csi.volname:pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 csi.volume.owner:default])
I0306 22:05:35.505136       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6a65bf15-4f16-4d96-ad72-e549102ba180) and image name (csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180) for request name (pvc-801c30de-40b8-4e92-a04d-d052f5df7c76)
I0306 22:05:35.505215       1 rbd_util.go:423] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 rbd: create kube/csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180 size 5120M (features: [layering]) using mon 199.204.45.227
I0306 22:05:35.505281       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 setting image options on kube/csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180
I0306 22:05:37.546943       1 controllerserver.go:763] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 created image kube/csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180 backed for request name pvc-801c30de-40b8-4e92-a04d-d052f5df7c76
I0306 22:05:37.586014       1 omap.go:159] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 set omap keys (pool="kube", namespace="", name="csi.volume.6a65bf15-4f16-4d96-ad72-e549102ba180"): map[csi.imageid:37d9e33854be])
I0306 22:05:37.691478       1 utils.go:205] ID: 23 Req-ID: pvc-801c30de-40b8-4e92-a04d-d052f5df7c76 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6a65bf15-4f16-4d96-ad72-e549102ba180","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6a65bf15-4f16-4d96-ad72-e549102ba180"}}
I0306 22:05:40.015548       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0306 22:05:40.015599       1 utils.go:199] ID: 24 GRPC request: {}
I0306 22:05:40.015624       1 utils.go:205] ID: 24 GRPC response: {}