I0413 20:41:40.949300       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0413 20:41:40.949436       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0413 20:41:40.949621       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0413 20:41:40.949712       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0413 20:41:40.949723       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0413 20:41:40.949726       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0413 20:41:40.949730       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0413 20:41:40.949748       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0413 20:41:40.949752       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0413 20:41:40.949769       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0413 20:41:40.950144       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0413 20:41:40.950194       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0413 20:41:44.188671       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:44.190229       1 utils.go:199] ID: 1 GRPC request: {}
I0413 20:41:44.190331       1 utils.go:205] ID: 1 GRPC response: {}
I0413 20:41:44.194059       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 20:41:44.194232       1 utils.go:199] ID: 2 GRPC request: {}
I0413 20:41:44.194253       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0413 20:41:44.194562       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 20:41:44.196540       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:44.196584       1 utils.go:199] ID: 3 GRPC request: {}
I0413 20:41:44.196611       1 utils.go:205] ID: 3 GRPC response: {}
I0413 20:41:44.196950       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 20:41:44.197046       1 utils.go:199] ID: 4 GRPC request: {}
I0413 20:41:44.197210       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 20:41:44.197927       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:44.198003       1 utils.go:199] ID: 5 GRPC request: {}
I0413 20:41:44.198028       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0413 20:41:44.198143       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}}}]}
I0413 20:41:45.803356       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:45.803400       1 utils.go:199] ID: 6 GRPC request: {}
I0413 20:41:45.803421       1 utils.go:205] ID: 6 GRPC response: {}
I0413 20:41:45.804917       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 20:41:45.804939       1 utils.go:199] ID: 7 GRPC request: {}
I0413 20:41:45.804945       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0413 20:41:45.804964       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 20:41:45.808635       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:45.808688       1 utils.go:199] ID: 8 GRPC request: {}
I0413 20:41:45.808711       1 utils.go:205] ID: 8 GRPC response: {}
I0413 20:41:45.809706       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 20:41:45.809830       1 utils.go:199] ID: 9 GRPC request: {}
I0413 20:41:45.810208       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 20:41:45.811193       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:45.811264       1 utils.go:199] ID: 10 GRPC request: {}
I0413 20:41:45.811308       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0413 20:41:45.811460       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}}}]}
I0413 20:41:45.812003       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:45.812029       1 utils.go:199] ID: 11 GRPC request: {}
I0413 20:41:45.812041       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0413 20:41:45.812185       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}}}]}
I0413 20:41:45.812556       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:45.812570       1 utils.go:199] ID: 12 GRPC request: {}
I0413 20:41:45.812575       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0413 20:41:45.812677       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}}}]}
I0413 20:41:47.005566       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 20:41:47.005601       1 utils.go:199] ID: 13 GRPC request: {}
I0413 20:41:47.005610       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0413 20:41:47.005632       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 20:41:47.011700       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:47.011729       1 utils.go:199] ID: 14 GRPC request: {}
I0413 20:41:47.011743       1 utils.go:205] ID: 14 GRPC response: {}
I0413 20:41:47.012247       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:47.012276       1 utils.go:199] ID: 15 GRPC request: {}
I0413 20:41:47.012286       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0413 20:41:47.012397       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}}}]}
I0413 20:41:48.222780       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:48.222812       1 utils.go:199] ID: 16 GRPC request: {}
I0413 20:41:48.222825       1 utils.go:205] ID: 16 GRPC response: {}
I0413 20:41:48.224502       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 20:41:48.224545       1 utils.go:199] ID: 17 GRPC request: {}
I0413 20:41:48.224556       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0413 20:41:48.224592       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 20:41:48.228001       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0413 20:41:48.228045       1 utils.go:199] ID: 18 GRPC request: {}
I0413 20:41:48.228069       1 utils.go:205] ID: 18 GRPC response: {}
I0413 20:41:48.228612       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 20:41:48.228664       1 utils.go:199] ID: 19 GRPC request: {}
I0413 20:41:48.228804       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 20:41:48.229952       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 20:41:48.230002       1 utils.go:199] ID: 20 GRPC request: {}
I0413 20:41:48.230014       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0413 20:41:48.230201       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}}}]}
I0413 20:42:48.422708       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0413 20:42:48.422757       1 utils.go:199] ID: 21 GRPC request: {}
I0413 20:42:48.422778       1 utils.go:205] ID: 21 GRPC response: {}
I0413 20:43:48.426313       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0413 20:43:48.426387       1 utils.go:199] ID: 22 GRPC request: {}
I0413 20:43:48.426427       1 utils.go:205] ID: 22 GRPC response: {}
I0413 20:44:48.422609       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0413 20:44:48.422670       1 utils.go:199] ID: 23 GRPC request: {}
I0413 20:44:48.422689       1 utils.go:205] ID: 23 GRPC response: {}
I0413 20:44:57.293529       1 utils.go:198] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 GRPC call: /csi.v1.Controller/CreateVolume
I0413 20:44:57.294330       1 utils.go:199] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-0080fd23-5801-47b7-876e-27d45cc71737","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-0080fd23-5801-47b7-876e-27d45cc71737","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}}]}
I0413 20:44:57.294944       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0413 20:44:57.313199       1 omap.go:80] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0413 20:44:57.330751       1 omap.go:159] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-0080fd23-5801-47b7-876e-27d45cc71737:b3205cb5-3b4c-40c1-a065-e886ff626ff2])
I0413 20:44:57.339678       1 omap.go:159] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 set omap keys (pool="kube", namespace="", name="csi.volume.b3205cb5-3b4c-40c1-a065-e886ff626ff2"): map[csi.imagename:csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2 csi.volname:pvc-0080fd23-5801-47b7-876e-27d45cc71737 csi.volume.owner:default])
I0413 20:44:57.339748       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b3205cb5-3b4c-40c1-a065-e886ff626ff2) and image name (csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2) for request name (pvc-0080fd23-5801-47b7-876e-27d45cc71737)
I0413 20:44:57.340064       1 rbd_util.go:423] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 rbd: create kube/csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2 size 5120M (features: [layering]) using mon 199.19.213.156
I0413 20:44:57.340227       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 setting image options on kube/csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2
I0413 20:44:58.822761       1 controllerserver.go:763] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 created image kube/csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2 backed for request name pvc-0080fd23-5801-47b7-876e-27d45cc71737
I0413 20:44:58.864530       1 omap.go:159] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 set omap keys (pool="kube", namespace="", name="csi.volume.b3205cb5-3b4c-40c1-a065-e886ff626ff2"): map[csi.imageid:37d92c7a181])
I0413 20:44:58.963772       1 utils.go:205] ID: 24 Req-ID: pvc-0080fd23-5801-47b7-876e-27d45cc71737 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-b3205cb5-3b4c-40c1-a065-e886ff626ff2","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b3205cb5-3b4c-40c1-a065-e886ff626ff2"}}
I0413 20:45:48.435880       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0413 20:45:48.436122       1 utils.go:199] ID: 25 GRPC request: {}
I0413 20:45:48.436194       1 utils.go:205] ID: 25 GRPC response: {}