I0519 18:28:35.336677       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0519 18:28:35.336835       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0519 18:28:35.336848       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0519 18:28:35.336851       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0519 18:28:35.336854       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0519 18:28:35.336857       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0519 18:28:35.336860       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0519 18:28:35.336865       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0519 18:28:35.336868       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0519 18:28:35.336871       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0519 18:28:35.337162       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0519 18:28:35.337195       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0519 18:28:37.632032       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:37.633269       1 utils.go:199] ID: 1 GRPC request: {}
I0519 18:28:37.633330       1 utils.go:205] ID: 1 GRPC response: {}
I0519 18:28:37.635737       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0519 18:28:37.635894       1 utils.go:199] ID: 2 GRPC request: {}
I0519 18:28:37.635912       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0519 18:28:37.635995       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0519 18:28:37.639204       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:37.639278       1 utils.go:199] ID: 3 GRPC request: {}
I0519 18:28:37.639331       1 utils.go:205] ID: 3 GRPC response: {}
I0519 18:28:37.640036       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0519 18:28:37.640209       1 utils.go:199] ID: 4 GRPC request: {}
I0519 18:28:37.640485       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0519 18:28:37.641832       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:37.642800       1 utils.go:199] ID: 5 GRPC request: {}
I0519 18:28:37.642857       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0519 18:28:37.643138       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}}}]}
I0519 18:28:41.134354       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:41.134402       1 utils.go:199] ID: 6 GRPC request: {}
I0519 18:28:41.134424       1 utils.go:205] ID: 6 GRPC response: {}
I0519 18:28:41.138114       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0519 18:28:41.138147       1 utils.go:199] ID: 7 GRPC request: {}
I0519 18:28:41.138159       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0519 18:28:41.138193       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0519 18:28:41.140663       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:41.140710       1 utils.go:199] ID: 8 GRPC request: {}
I0519 18:28:41.140741       1 utils.go:205] ID: 8 GRPC response: {}
I0519 18:28:41.141262       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0519 18:28:41.141286       1 utils.go:199] ID: 9 GRPC request: {}
I0519 18:28:41.141409       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0519 18:28:41.143009       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:41.143035       1 utils.go:199] ID: 10 GRPC request: {}
I0519 18:28:41.143044       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0519 18:28:41.143112       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}}}]}
I0519 18:28:41.143590       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:41.143614       1 utils.go:199] ID: 11 GRPC request: {}
I0519 18:28:41.143623       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0519 18:28:41.143778       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}}}]}
I0519 18:28:41.144121       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:41.144139       1 utils.go:199] ID: 12 GRPC request: {}
I0519 18:28:41.144145       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0519 18:28:41.144202       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}}}]}
I0519 18:28:43.601870       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0519 18:28:43.601905       1 utils.go:199] ID: 13 GRPC request: {}
I0519 18:28:43.601914       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0519 18:28:43.601937       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0519 18:28:43.604940       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:43.604960       1 utils.go:199] ID: 14 GRPC request: {}
I0519 18:28:43.604980       1 utils.go:205] ID: 14 GRPC response: {}
I0519 18:28:43.605560       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:43.605599       1 utils.go:199] ID: 15 GRPC request: {}
I0519 18:28:43.605608       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0519 18:28:43.605706       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}}}]}
I0519 18:28:45.183974       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:45.184052       1 utils.go:199] ID: 16 GRPC request: {}
I0519 18:28:45.184135       1 utils.go:205] ID: 16 GRPC response: {}
I0519 18:28:45.185987       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0519 18:28:45.186007       1 utils.go:199] ID: 17 GRPC request: {}
I0519 18:28:45.186012       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0519 18:28:45.186039       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0519 18:28:45.187884       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0519 18:28:45.187905       1 utils.go:199] ID: 18 GRPC request: {}
I0519 18:28:45.187987       1 utils.go:205] ID: 18 GRPC response: {}
I0519 18:28:45.188253       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0519 18:28:45.188271       1 utils.go:199] ID: 19 GRPC request: {}
I0519 18:28:45.188462       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0519 18:28:45.189517       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0519 18:28:45.189538       1 utils.go:199] ID: 20 GRPC request: {}
I0519 18:28:45.189545       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0519 18:28:45.189727       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}}}]}
I0519 18:29:45.428322       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0519 18:29:45.428386       1 utils.go:199] ID: 21 GRPC request: {}
I0519 18:29:45.428417       1 utils.go:205] ID: 21 GRPC response: {}
I0519 18:30:45.375059       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0519 18:30:45.375136       1 utils.go:199] ID: 22 GRPC request: {}
I0519 18:30:45.375166       1 utils.go:205] ID: 22 GRPC response: {}
I0519 18:31:44.745788       1 utils.go:198] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 GRPC call: /csi.v1.Controller/CreateVolume
I0519 18:31:44.746427       1 utils.go:199] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680","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}}]}
I0519 18:31:44.746849       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0519 18:31:44.766026       1 omap.go:80] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0519 18:31:44.782093       1 omap.go:159] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680:297dc8df-07c8-451a-98dc-19cc2a11d48e])
I0519 18:31:44.787802       1 omap.go:159] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 set omap keys (pool="kube", namespace="", name="csi.volume.297dc8df-07c8-451a-98dc-19cc2a11d48e"): map[csi.imagename:csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e csi.volname:pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 csi.volume.owner:default])
I0519 18:31:44.787847       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-297dc8df-07c8-451a-98dc-19cc2a11d48e) and image name (csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e) for request name (pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680)
I0519 18:31:44.788145       1 rbd_util.go:423] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 rbd: create kube/csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e size 5120M (features: [layering]) using mon 199.19.213.143
I0519 18:31:44.788274       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 setting image options on kube/csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e
I0519 18:31:45.374051       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0519 18:31:45.374126       1 utils.go:199] ID: 24 GRPC request: {}
I0519 18:31:45.374152       1 utils.go:205] ID: 24 GRPC response: {}
I0519 18:31:46.845982       1 controllerserver.go:763] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 created image kube/csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e backed for request name pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680
I0519 18:31:46.883520       1 omap.go:159] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 set omap keys (pool="kube", namespace="", name="csi.volume.297dc8df-07c8-451a-98dc-19cc2a11d48e"): map[csi.imageid:37d878a468b0])
I0519 18:31:46.977149       1 utils.go:205] ID: 23 Req-ID: pvc-54c50fd9-ebc3-414f-aa29-eb35cd6f7680 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-297dc8df-07c8-451a-98dc-19cc2a11d48e","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-297dc8df-07c8-451a-98dc-19cc2a11d48e"}}