I0225 15:11:03.936751       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0225 15:11:03.936908       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0225 15:11:03.936923       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0225 15:11:03.936927       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0225 15:11:03.936931       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0225 15:11:03.936935       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0225 15:11:03.936940       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0225 15:11:03.936943       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0225 15:11:03.936947       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0225 15:11:03.936950       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0225 15:11:03.937358       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0225 15:11:03.937423       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0225 15:11:06.918192       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:06.919792       1 utils.go:199] ID: 1 GRPC request: {}
I0225 15:11:06.919866       1 utils.go:205] ID: 1 GRPC response: {}
I0225 15:11:06.923055       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:11:06.923143       1 utils.go:199] ID: 2 GRPC request: {}
I0225 15:11:06.923159       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0225 15:11:06.923202       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:11:06.924911       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:06.924970       1 utils.go:199] ID: 3 GRPC request: {}
I0225 15:11:06.925006       1 utils.go:205] ID: 3 GRPC response: {}
I0225 15:11:06.927057       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 15:11:06.927174       1 utils.go:199] ID: 4 GRPC request: {}
I0225 15:11:06.927420       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 15:11:06.928380       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:06.928456       1 utils.go:199] ID: 5 GRPC request: {}
I0225 15:11:06.928475       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0225 15:11:06.928645       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}}}]}
I0225 15:11:10.599974       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:10.600069       1 utils.go:199] ID: 6 GRPC request: {}
I0225 15:11:10.600126       1 utils.go:205] ID: 6 GRPC response: {}
I0225 15:11:10.602656       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:11:10.602707       1 utils.go:199] ID: 7 GRPC request: {}
I0225 15:11:10.602717       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0225 15:11:10.602769       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:11:10.604616       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:10.604647       1 utils.go:199] ID: 8 GRPC request: {}
I0225 15:11:10.604667       1 utils.go:205] ID: 8 GRPC response: {}
I0225 15:11:10.605460       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 15:11:10.605484       1 utils.go:199] ID: 9 GRPC request: {}
I0225 15:11:10.605582       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 15:11:10.606624       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:10.606665       1 utils.go:199] ID: 10 GRPC request: {}
I0225 15:11:10.606675       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0225 15:11:10.606761       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}}}]}
I0225 15:11:10.607742       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:10.607770       1 utils.go:199] ID: 11 GRPC request: {}
I0225 15:11:10.607780       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0225 15:11:10.607865       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}}}]}
I0225 15:11:10.608730       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:10.608748       1 utils.go:199] ID: 12 GRPC request: {}
I0225 15:11:10.608754       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0225 15:11:10.608812       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}}}]}
I0225 15:11:12.738531       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:11:12.738572       1 utils.go:199] ID: 13 GRPC request: {}
I0225 15:11:12.738580       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0225 15:11:12.738609       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:11:12.742197       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:12.742243       1 utils.go:199] ID: 14 GRPC request: {}
I0225 15:11:12.742268       1 utils.go:205] ID: 14 GRPC response: {}
I0225 15:11:12.742902       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:12.742966       1 utils.go:199] ID: 15 GRPC request: {}
I0225 15:11:12.742983       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0225 15:11:12.743170       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}}}]}
I0225 15:11:14.906908       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:14.907006       1 utils.go:199] ID: 16 GRPC request: {}
I0225 15:11:14.907051       1 utils.go:205] ID: 16 GRPC response: {}
I0225 15:11:14.908819       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:11:14.908860       1 utils.go:199] ID: 17 GRPC request: {}
I0225 15:11:14.908875       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0225 15:11:14.908913       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:11:14.912782       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0225 15:11:14.912807       1 utils.go:199] ID: 18 GRPC request: {}
I0225 15:11:14.912824       1 utils.go:205] ID: 18 GRPC response: {}
I0225 15:11:14.913153       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 15:11:14.913174       1 utils.go:199] ID: 19 GRPC request: {}
I0225 15:11:14.913842       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 15:11:14.914709       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:11:14.914725       1 utils.go:199] ID: 20 GRPC request: {}
I0225 15:11:14.914734       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0225 15:11:14.914801       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}}}]}
I0225 15:12:15.058407       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0225 15:12:15.058462       1 utils.go:199] ID: 21 GRPC request: {}
I0225 15:12:15.058517       1 utils.go:205] ID: 21 GRPC response: {}
I0225 15:13:15.061625       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0225 15:13:15.061741       1 utils.go:199] ID: 22 GRPC request: {}
I0225 15:13:15.061773       1 utils.go:205] ID: 22 GRPC response: {}
I0225 15:14:15.056973       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0225 15:14:15.057011       1 utils.go:199] ID: 23 GRPC request: {}
I0225 15:14:15.057029       1 utils.go:205] ID: 23 GRPC response: {}
I0225 15:14:43.949384       1 utils.go:198] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 GRPC call: /csi.v1.Controller/CreateVolume
I0225 15:14:43.949648       1 utils.go:199] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7a8b0d04-9133-48b6-a709-a41edebab166","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7a8b0d04-9133-48b6-a709-a41edebab166","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}}]}
I0225 15:14:43.949869       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0225 15:14:43.966192       1 omap.go:80] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0225 15:14:44.931780       1 omap.go:159] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7a8b0d04-9133-48b6-a709-a41edebab166:dfaa42c1-25bb-49f9-984b-97063ff9de45])
I0225 15:14:45.083863       1 omap.go:159] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 set omap keys (pool="kube", namespace="", name="csi.volume.dfaa42c1-25bb-49f9-984b-97063ff9de45"): map[csi.imagename:csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45 csi.volname:pvc-7a8b0d04-9133-48b6-a709-a41edebab166 csi.volume.owner:default])
I0225 15:14:45.083899       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dfaa42c1-25bb-49f9-984b-97063ff9de45) and image name (csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45) for request name (pvc-7a8b0d04-9133-48b6-a709-a41edebab166)
I0225 15:14:45.083989       1 rbd_util.go:423] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 rbd: create kube/csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45 size 5120M (features: [layering]) using mon 199.204.45.99
I0225 15:14:45.084031       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 setting image options on kube/csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45
I0225 15:14:51.229402       1 controllerserver.go:763] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 created image kube/csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45 backed for request name pvc-7a8b0d04-9133-48b6-a709-a41edebab166
I0225 15:14:52.679013       1 omap.go:159] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 set omap keys (pool="kube", namespace="", name="csi.volume.dfaa42c1-25bb-49f9-984b-97063ff9de45"): map[csi.imageid:37d9563a6407])
I0225 15:14:57.064288       1 utils.go:205] ID: 24 Req-ID: pvc-7a8b0d04-9133-48b6-a709-a41edebab166 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-dfaa42c1-25bb-49f9-984b-97063ff9de45","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dfaa42c1-25bb-49f9-984b-97063ff9de45"}}
I0225 15:15:15.068627       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:15.068787       1 utils.go:199] ID: 25 GRPC request: {}
I0225 15:15:15.068813       1 utils.go:205] ID: 25 GRPC response: {}
I0225 15:15:56.585292       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:56.585344       1 utils.go:199] ID: 26 GRPC request: {}
I0225 15:15:56.585368       1 utils.go:205] ID: 26 GRPC response: {}
I0225 15:15:56.592141       1 utils.go:198] ID: 27 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:15:56.592203       1 utils.go:199] ID: 27 GRPC request: {}
I0225 15:15:56.592226       1 identityserver-default.go:40] ID: 27 Using default GetPluginInfo
I0225 15:15:56.592267       1 utils.go:205] ID: 27 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:15:56.594791       1 utils.go:198] ID: 28 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:56.594832       1 utils.go:199] ID: 28 GRPC request: {}
I0225 15:15:56.594870       1 utils.go:205] ID: 28 GRPC response: {}
I0225 15:15:56.595462       1 utils.go:198] ID: 29 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 15:15:56.595483       1 utils.go:199] ID: 29 GRPC request: {}
I0225 15:15:56.595646       1 utils.go:205] ID: 29 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 15:15:56.596384       1 utils.go:198] ID: 30 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:15:56.596429       1 utils.go:199] ID: 30 GRPC request: {}
I0225 15:15:56.596440       1 controllerserver-default.go:42] ID: 30 Using default ControllerGetCapabilities
I0225 15:15:56.596562       1 utils.go:205] ID: 30 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0225 15:15:56.597454       1 utils.go:198] ID: 31 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:15:56.597494       1 utils.go:199] ID: 31 GRPC request: {}
I0225 15:15:56.597504       1 controllerserver-default.go:42] ID: 31 Using default ControllerGetCapabilities
I0225 15:15:56.597602       1 utils.go:205] ID: 31 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0225 15:15:56.598049       1 utils.go:198] ID: 32 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:15:56.598076       1 utils.go:199] ID: 32 GRPC request: {}
I0225 15:15:56.598082       1 controllerserver-default.go:42] ID: 32 Using default ControllerGetCapabilities
I0225 15:15:56.598143       1 utils.go:205] ID: 32 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0225 15:15:56.657614       1 utils.go:198] ID: 33 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:15:56.657700       1 utils.go:199] ID: 33 GRPC request: {}
I0225 15:15:56.657713       1 identityserver-default.go:40] ID: 33 Using default GetPluginInfo
I0225 15:15:56.657771       1 utils.go:205] ID: 33 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:15:56.662059       1 utils.go:198] ID: 34 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:56.662120       1 utils.go:199] ID: 34 GRPC request: {}
I0225 15:15:56.662154       1 utils.go:205] ID: 34 GRPC response: {}
I0225 15:15:56.662682       1 utils.go:198] ID: 35 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:15:56.662719       1 utils.go:199] ID: 35 GRPC request: {}
I0225 15:15:56.662732       1 controllerserver-default.go:42] ID: 35 Using default ControllerGetCapabilities
I0225 15:15:56.662859       1 utils.go:205] ID: 35 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0225 15:15:56.730836       1 utils.go:198] ID: 36 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:56.730892       1 utils.go:199] ID: 36 GRPC request: {}
I0225 15:15:56.730910       1 utils.go:205] ID: 36 GRPC response: {}
I0225 15:15:56.733129       1 utils.go:198] ID: 37 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 15:15:56.733219       1 utils.go:199] ID: 37 GRPC request: {}
I0225 15:15:56.733228       1 identityserver-default.go:40] ID: 37 Using default GetPluginInfo
I0225 15:15:56.733259       1 utils.go:205] ID: 37 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 15:15:56.737427       1 utils.go:198] ID: 38 GRPC call: /csi.v1.Identity/Probe
I0225 15:15:56.737459       1 utils.go:199] ID: 38 GRPC request: {}
I0225 15:15:56.737472       1 utils.go:205] ID: 38 GRPC response: {}
I0225 15:15:56.737893       1 utils.go:198] ID: 39 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 15:15:56.737909       1 utils.go:199] ID: 39 GRPC request: {}
I0225 15:15:56.738161       1 utils.go:205] ID: 39 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 15:15:56.738726       1 utils.go:198] ID: 40 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 15:15:56.738776       1 utils.go:199] ID: 40 GRPC request: {}
I0225 15:15:56.738798       1 controllerserver-default.go:42] ID: 40 Using default ControllerGetCapabilities
I0225 15:15:56.738878       1 utils.go:205] ID: 40 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0225 15:16:15.056940       1 utils.go:198] ID: 41 GRPC call: /csi.v1.Identity/Probe
I0225 15:16:15.056990       1 utils.go:199] ID: 41 GRPC request: {}
I0225 15:16:15.057011       1 utils.go:205] ID: 41 GRPC response: {}