I0522 00:53:05.414274       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0522 00:53:05.414530       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0522 00:53:05.414627       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0522 00:53:05.414719       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0522 00:53:05.414747       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0522 00:53:05.414779       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0522 00:53:05.414792       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0522 00:53:05.414799       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0522 00:53:05.414840       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0522 00:53:05.414852       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0522 00:53:05.415423       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0522 00:53:05.415469       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0522 00:53:07.465422       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:07.468453       1 utils.go:199] ID: 1 GRPC request: {}
I0522 00:53:07.468599       1 utils.go:205] ID: 1 GRPC response: {}
I0522 00:53:07.473187       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0522 00:53:07.473238       1 utils.go:199] ID: 2 GRPC request: {}
I0522 00:53:07.473252       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0522 00:53:07.473293       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0522 00:53:07.475095       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:07.475127       1 utils.go:199] ID: 3 GRPC request: {}
I0522 00:53:07.475154       1 utils.go:205] ID: 3 GRPC response: {}
I0522 00:53:07.475736       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0522 00:53:07.475826       1 utils.go:199] ID: 4 GRPC request: {}
I0522 00:53:07.476099       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0522 00:53:07.476960       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:07.477012       1 utils.go:199] ID: 5 GRPC request: {}
I0522 00:53:07.477022       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0522 00:53:07.477171       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}}}]}
I0522 00:53:08.810536       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:08.810599       1 utils.go:199] ID: 6 GRPC request: {}
I0522 00:53:08.810644       1 utils.go:205] ID: 6 GRPC response: {}
I0522 00:53:08.813750       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0522 00:53:08.813783       1 utils.go:199] ID: 7 GRPC request: {}
I0522 00:53:08.813800       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0522 00:53:08.813836       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0522 00:53:08.815951       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:08.816045       1 utils.go:199] ID: 8 GRPC request: {}
I0522 00:53:08.816076       1 utils.go:205] ID: 8 GRPC response: {}
I0522 00:53:08.816939       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0522 00:53:08.817031       1 utils.go:199] ID: 9 GRPC request: {}
I0522 00:53:08.817306       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0522 00:53:08.818775       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:08.818797       1 utils.go:199] ID: 10 GRPC request: {}
I0522 00:53:08.818808       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0522 00:53:08.818887       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}}}]}
I0522 00:53:08.821774       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:08.821794       1 utils.go:199] ID: 11 GRPC request: {}
I0522 00:53:08.821803       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0522 00:53:08.821878       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}}}]}
I0522 00:53:08.822826       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:08.822844       1 utils.go:199] ID: 12 GRPC request: {}
I0522 00:53:08.822849       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0522 00:53:08.822925       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}}}]}
I0522 00:53:12.377845       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0522 00:53:12.377911       1 utils.go:199] ID: 13 GRPC request: {}
I0522 00:53:12.377931       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0522 00:53:12.377977       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0522 00:53:12.382201       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:12.382217       1 utils.go:199] ID: 14 GRPC request: {}
I0522 00:53:12.382231       1 utils.go:205] ID: 14 GRPC response: {}
I0522 00:53:12.382871       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:12.382928       1 utils.go:199] ID: 15 GRPC request: {}
I0522 00:53:12.382941       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0522 00:53:12.383058       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}}}]}
I0522 00:53:14.321506       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:14.321556       1 utils.go:199] ID: 16 GRPC request: {}
I0522 00:53:14.321590       1 utils.go:205] ID: 16 GRPC response: {}
I0522 00:53:14.326497       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0522 00:53:14.326518       1 utils.go:199] ID: 17 GRPC request: {}
I0522 00:53:14.326526       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0522 00:53:14.326567       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0522 00:53:14.328738       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0522 00:53:14.328755       1 utils.go:199] ID: 18 GRPC request: {}
I0522 00:53:14.328766       1 utils.go:205] ID: 18 GRPC response: {}
I0522 00:53:14.332466       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0522 00:53:14.332483       1 utils.go:199] ID: 19 GRPC request: {}
I0522 00:53:14.332587       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0522 00:53:14.334749       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0522 00:53:14.334803       1 utils.go:199] ID: 20 GRPC request: {}
I0522 00:53:14.334813       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0522 00:53:14.334919       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}}}]}
I0522 00:54:14.557378       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0522 00:54:14.557423       1 utils.go:199] ID: 21 GRPC request: {}
I0522 00:54:14.557444       1 utils.go:205] ID: 21 GRPC response: {}
I0522 00:55:14.519958       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0522 00:55:14.520058       1 utils.go:199] ID: 22 GRPC request: {}
I0522 00:55:14.520091       1 utils.go:205] ID: 22 GRPC response: {}
I0522 00:56:14.517607       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0522 00:56:14.517644       1 utils.go:199] ID: 23 GRPC request: {}
I0522 00:56:14.517660       1 utils.go:205] ID: 23 GRPC response: {}
I0522 00:56:51.468517       1 utils.go:198] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e GRPC call: /csi.v1.Controller/CreateVolume
I0522 00:56:51.468942       1 utils.go:199] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-dd88a753-f35d-4e0e-be93-9049e572391e","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-dd88a753-f35d-4e0e-be93-9049e572391e","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}}]}
I0522 00:56:51.469269       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e setting disableInUseChecks: false image features: [layering] mounter: rbd
E0522 00:56:51.486133       1 omap.go:80] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0522 00:56:51.502535       1 omap.go:159] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-dd88a753-f35d-4e0e-be93-9049e572391e:aeee783a-526f-4c61-b0ac-9c7a8972dcf0])
I0522 00:56:51.510182       1 omap.go:159] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e set omap keys (pool="kube", namespace="", name="csi.volume.aeee783a-526f-4c61-b0ac-9c7a8972dcf0"): map[csi.imagename:csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0 csi.volname:pvc-dd88a753-f35d-4e0e-be93-9049e572391e csi.volume.owner:default])
I0522 00:56:51.510286       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aeee783a-526f-4c61-b0ac-9c7a8972dcf0) and image name (csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0) for request name (pvc-dd88a753-f35d-4e0e-be93-9049e572391e)
I0522 00:56:51.510409       1 rbd_util.go:423] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e rbd: create kube/csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0 size 5120M (features: [layering]) using mon 199.204.45.116
I0522 00:56:51.510768       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e setting image options on kube/csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0
I0522 00:56:51.545882       1 controllerserver.go:763] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e created image kube/csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0 backed for request name pvc-dd88a753-f35d-4e0e-be93-9049e572391e
I0522 00:56:51.575023       1 omap.go:159] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e set omap keys (pool="kube", namespace="", name="csi.volume.aeee783a-526f-4c61-b0ac-9c7a8972dcf0"): map[csi.imageid:37ebe6f620c])
I0522 00:56:51.668901       1 utils.go:205] ID: 24 Req-ID: pvc-dd88a753-f35d-4e0e-be93-9049e572391e GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-aeee783a-526f-4c61-b0ac-9c7a8972dcf0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aeee783a-526f-4c61-b0ac-9c7a8972dcf0"}}
I0522 00:57:14.536425       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0522 00:57:14.536497       1 utils.go:199] ID: 25 GRPC request: {}
I0522 00:57:14.536526       1 utils.go:205] ID: 25 GRPC response: {}