I0217 19:57:38.940735       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0217 19:57:38.940984       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0217 19:57:38.941046       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0217 19:57:38.941087       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0217 19:57:38.941126       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0217 19:57:38.941181       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0217 19:57:38.941249       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0217 19:57:38.941289       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0217 19:57:38.941333       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0217 19:57:38.941360       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0217 19:57:38.941656       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0217 19:57:38.941737       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0217 19:57:43.633768       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:43.636392       1 utils.go:199] ID: 1 GRPC request: {}
I0217 19:57:43.636583       1 utils.go:205] ID: 1 GRPC response: {}
I0217 19:57:43.638612       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 19:57:43.638716       1 utils.go:199] ID: 2 GRPC request: {}
I0217 19:57:43.638751       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0217 19:57:43.638856       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 19:57:43.640155       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:43.640170       1 utils.go:199] ID: 3 GRPC request: {}
I0217 19:57:43.640240       1 utils.go:205] ID: 3 GRPC response: {}
I0217 19:57:43.640528       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 19:57:43.640624       1 utils.go:199] ID: 4 GRPC request: {}
I0217 19:57:43.640793       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 19:57:43.641404       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:43.641499       1 utils.go:199] ID: 5 GRPC request: {}
I0217 19:57:43.641558       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0217 19:57:43.641696       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}}}]}
I0217 19:57:45.936767       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:45.936795       1 utils.go:199] ID: 6 GRPC request: {}
I0217 19:57:45.936808       1 utils.go:205] ID: 6 GRPC response: {}
I0217 19:57:45.940447       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 19:57:45.940462       1 utils.go:199] ID: 7 GRPC request: {}
I0217 19:57:45.940469       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0217 19:57:45.940486       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 19:57:45.941488       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:45.941501       1 utils.go:199] ID: 8 GRPC request: {}
I0217 19:57:45.941533       1 utils.go:205] ID: 8 GRPC response: {}
I0217 19:57:45.941906       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 19:57:45.941919       1 utils.go:199] ID: 9 GRPC request: {}
I0217 19:57:45.941993       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 19:57:45.942386       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:45.942400       1 utils.go:199] ID: 10 GRPC request: {}
I0217 19:57:45.942421       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0217 19:57:45.942474       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}}}]}
I0217 19:57:45.942776       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:45.942811       1 utils.go:199] ID: 11 GRPC request: {}
I0217 19:57:45.942818       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0217 19:57:45.942854       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}}}]}
I0217 19:57:45.943082       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:45.943094       1 utils.go:199] ID: 12 GRPC request: {}
I0217 19:57:45.943109       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0217 19:57:45.943160       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}}}]}
I0217 19:57:49.179125       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 19:57:49.179165       1 utils.go:199] ID: 13 GRPC request: {}
I0217 19:57:49.179175       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0217 19:57:49.179193       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 19:57:49.182127       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:49.182152       1 utils.go:199] ID: 14 GRPC request: {}
I0217 19:57:49.182172       1 utils.go:205] ID: 14 GRPC response: {}
I0217 19:57:49.182613       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:49.182641       1 utils.go:199] ID: 15 GRPC request: {}
I0217 19:57:49.182647       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0217 19:57:49.182722       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}}}]}
I0217 19:57:51.587350       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:51.587377       1 utils.go:199] ID: 16 GRPC request: {}
I0217 19:57:51.587390       1 utils.go:205] ID: 16 GRPC response: {}
I0217 19:57:51.590254       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 19:57:51.590360       1 utils.go:199] ID: 17 GRPC request: {}
I0217 19:57:51.590443       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0217 19:57:51.590567       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 19:57:51.596333       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0217 19:57:51.596694       1 utils.go:199] ID: 18 GRPC request: {}
I0217 19:57:51.596751       1 utils.go:205] ID: 18 GRPC response: {}
I0217 19:57:51.597439       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 19:57:51.597465       1 utils.go:199] ID: 19 GRPC request: {}
I0217 19:57:51.597622       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 19:57:51.600151       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 19:57:51.600217       1 utils.go:199] ID: 20 GRPC request: {}
I0217 19:57:51.600228       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0217 19:57:51.600461       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}}}]}
I0217 19:58:51.801631       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0217 19:58:51.801702       1 utils.go:199] ID: 21 GRPC request: {}
I0217 19:58:51.801727       1 utils.go:205] ID: 21 GRPC response: {}
I0217 19:59:51.802200       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0217 19:59:51.802280       1 utils.go:199] ID: 22 GRPC request: {}
I0217 19:59:51.802304       1 utils.go:205] ID: 22 GRPC response: {}
I0217 20:00:49.164581       1 utils.go:198] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb GRPC call: /csi.v1.Controller/CreateVolume
I0217 20:00:49.165088       1 utils.go:199] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-80e5440b-45c9-41af-8ea8-a852692feddb","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-80e5440b-45c9-41af-8ea8-a852692feddb","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}}]}
I0217 20:00:49.165382       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb setting disableInUseChecks: false image features: [layering] mounter: rbd
E0217 20:00:49.207653       1 omap.go:80] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0217 20:00:49.223060       1 omap.go:159] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-80e5440b-45c9-41af-8ea8-a852692feddb:181b5b76-cef1-4a54-a025-36228a14a06d])
I0217 20:00:49.228659       1 omap.go:159] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb set omap keys (pool="kube", namespace="", name="csi.volume.181b5b76-cef1-4a54-a025-36228a14a06d"): map[csi.imagename:csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d csi.volname:pvc-80e5440b-45c9-41af-8ea8-a852692feddb csi.volume.owner:default])
I0217 20:00:49.228698       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-181b5b76-cef1-4a54-a025-36228a14a06d) and image name (csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d) for request name (pvc-80e5440b-45c9-41af-8ea8-a852692feddb)
I0217 20:00:49.228788       1 rbd_util.go:423] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb rbd: create kube/csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d size 5120M (features: [layering]) using mon 199.204.45.57
I0217 20:00:49.228855       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb setting image options on kube/csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d
I0217 20:00:51.269075       1 controllerserver.go:763] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb created image kube/csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d backed for request name pvc-80e5440b-45c9-41af-8ea8-a852692feddb
I0217 20:00:51.309235       1 omap.go:159] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb set omap keys (pool="kube", namespace="", name="csi.volume.181b5b76-cef1-4a54-a025-36228a14a06d"): map[csi.imageid:37d94ee7ca68])
I0217 20:00:51.397214       1 utils.go:205] ID: 23 Req-ID: pvc-80e5440b-45c9-41af-8ea8-a852692feddb GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-181b5b76-cef1-4a54-a025-36228a14a06d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-181b5b76-cef1-4a54-a025-36228a14a06d"}}
I0217 20:00:51.800767       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0217 20:00:51.800853       1 utils.go:199] ID: 24 GRPC request: {}
I0217 20:00:51.800884       1 utils.go:205] ID: 24 GRPC response: {}