I0127 19:50:58.848862       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0127 19:50:58.849295       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0127 19:50:58.849343       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0127 19:50:58.849396       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0127 19:50:58.849417       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0127 19:50:58.849429       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0127 19:50:58.849443       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0127 19:50:58.849485       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0127 19:50:58.849510       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0127 19:50:58.849527       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0127 19:50:58.851696       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0127 19:50:58.851818       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0127 19:51:02.121219       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:02.124788       1 utils.go:199] ID: 1 GRPC request: {}
I0127 19:51:02.125053       1 utils.go:205] ID: 1 GRPC response: {}
I0127 19:51:02.136929       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0127 19:51:02.136973       1 utils.go:199] ID: 2 GRPC request: {}
I0127 19:51:02.136979       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0127 19:51:02.137026       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0127 19:51:02.149335       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:02.149364       1 utils.go:199] ID: 3 GRPC request: {}
I0127 19:51:02.149499       1 utils.go:205] ID: 3 GRPC response: {}
I0127 19:51:02.154058       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0127 19:51:02.154311       1 utils.go:199] ID: 4 GRPC request: {}
I0127 19:51:02.154617       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0127 19:51:02.159009       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:02.159126       1 utils.go:199] ID: 5 GRPC request: {}
I0127 19:51:02.159138       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0127 19:51:02.159306       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}}}]}
I0127 19:51:19.350000       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:19.350147       1 utils.go:199] ID: 6 GRPC request: {}
I0127 19:51:19.350229       1 utils.go:205] ID: 6 GRPC response: {}
I0127 19:51:19.356849       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0127 19:51:19.356938       1 utils.go:199] ID: 7 GRPC request: {}
I0127 19:51:19.356998       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0127 19:51:19.357068       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0127 19:51:19.358401       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:19.358485       1 utils.go:199] ID: 8 GRPC request: {}
I0127 19:51:19.358563       1 utils.go:205] ID: 8 GRPC response: {}
I0127 19:51:19.358898       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0127 19:51:19.358989       1 utils.go:199] ID: 9 GRPC request: {}
I0127 19:51:19.359122       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0127 19:51:19.359604       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:19.359679       1 utils.go:199] ID: 10 GRPC request: {}
I0127 19:51:19.359735       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0127 19:51:19.359831       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}}}]}
I0127 19:51:19.360263       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:19.360395       1 utils.go:199] ID: 11 GRPC request: {}
I0127 19:51:19.360504       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0127 19:51:19.360624       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}}}]}
I0127 19:51:19.360932       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:19.361054       1 utils.go:199] ID: 12 GRPC request: {}
I0127 19:51:19.361127       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0127 19:51:19.361245       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}}}]}
I0127 19:51:22.235850       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0127 19:51:22.236011       1 utils.go:199] ID: 13 GRPC request: {}
I0127 19:51:22.236030       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0127 19:51:22.236213       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0127 19:51:22.240509       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:22.240532       1 utils.go:199] ID: 14 GRPC request: {}
I0127 19:51:22.240545       1 utils.go:205] ID: 14 GRPC response: {}
I0127 19:51:22.241139       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:22.241161       1 utils.go:199] ID: 15 GRPC request: {}
I0127 19:51:22.241170       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0127 19:51:22.241362       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}}}]}
I0127 19:51:25.623241       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:25.623293       1 utils.go:199] ID: 16 GRPC request: {}
I0127 19:51:25.623309       1 utils.go:205] ID: 16 GRPC response: {}
I0127 19:51:25.625238       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0127 19:51:25.625252       1 utils.go:199] ID: 17 GRPC request: {}
I0127 19:51:25.625257       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0127 19:51:25.625274       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0127 19:51:25.630592       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0127 19:51:25.630605       1 utils.go:199] ID: 18 GRPC request: {}
I0127 19:51:25.630613       1 utils.go:205] ID: 18 GRPC response: {}
I0127 19:51:25.631096       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0127 19:51:25.631109       1 utils.go:199] ID: 19 GRPC request: {}
I0127 19:51:25.631190       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0127 19:51:25.632023       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0127 19:51:25.632040       1 utils.go:199] ID: 20 GRPC request: {}
I0127 19:51:25.632048       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0127 19:51:25.632138       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}}}]}
I0127 19:52:25.981506       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0127 19:52:25.981557       1 utils.go:199] ID: 21 GRPC request: {}
I0127 19:52:25.981569       1 utils.go:205] ID: 21 GRPC response: {}
I0127 19:53:25.922837       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0127 19:53:25.923809       1 utils.go:199] ID: 22 GRPC request: {}
I0127 19:53:25.923942       1 utils.go:205] ID: 22 GRPC response: {}
I0127 19:54:03.422741       1 utils.go:198] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 GRPC call: /csi.v1.Controller/CreateVolume
I0127 19:54:03.423064       1 utils.go:199] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9660174e-af8e-4289-a388-e020987fbce1","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9660174e-af8e-4289-a388-e020987fbce1","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}}]}
I0127 19:54:03.423271       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0127 19:54:03.442833       1 omap.go:80] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0127 19:54:03.456155       1 omap.go:159] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9660174e-af8e-4289-a388-e020987fbce1:3e429940-4620-4dc4-9709-d7c02cc1bfb4])
I0127 19:54:03.461241       1 omap.go:159] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 set omap keys (pool="kube", namespace="", name="csi.volume.3e429940-4620-4dc4-9709-d7c02cc1bfb4"): map[csi.imagename:csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4 csi.volname:pvc-9660174e-af8e-4289-a388-e020987fbce1 csi.volume.owner:default])
I0127 19:54:03.461295       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3e429940-4620-4dc4-9709-d7c02cc1bfb4) and image name (csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4) for request name (pvc-9660174e-af8e-4289-a388-e020987fbce1)
I0127 19:54:03.461442       1 rbd_util.go:423] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 rbd: create kube/csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4 size 5120M (features: [layering]) using mon 199.204.45.49
I0127 19:54:03.461517       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 setting image options on kube/csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4
I0127 19:54:05.296955       1 controllerserver.go:763] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 created image kube/csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4 backed for request name pvc-9660174e-af8e-4289-a388-e020987fbce1
I0127 19:54:05.326986       1 omap.go:159] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 set omap keys (pool="kube", namespace="", name="csi.volume.3e429940-4620-4dc4-9709-d7c02cc1bfb4"): map[csi.imageid:37d9e39a989b])
I0127 19:54:05.418942       1 utils.go:205] ID: 23 Req-ID: pvc-9660174e-af8e-4289-a388-e020987fbce1 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-3e429940-4620-4dc4-9709-d7c02cc1bfb4","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3e429940-4620-4dc4-9709-d7c02cc1bfb4"}}
I0127 19:54:25.980316       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0127 19:54:25.980436       1 utils.go:199] ID: 24 GRPC request: {}
I0127 19:54:25.980472       1 utils.go:205] ID: 24 GRPC response: {}