I0217 16:08:20.407009       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0217 16:08:20.407311       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0217 16:08:20.407354       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0217 16:08:20.407376       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0217 16:08:20.407394       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0217 16:08:20.407423       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0217 16:08:20.407444       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0217 16:08:20.407461       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0217 16:08:20.407478       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0217 16:08:20.407514       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0217 16:08:20.407777       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0217 16:08:20.407846       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0217 16:08:31.523906       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:31.524836       1 utils.go:199] ID: 1 GRPC request: {}
I0217 16:08:31.524900       1 utils.go:205] ID: 1 GRPC response: {}
I0217 16:08:31.526140       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 16:08:31.526224       1 utils.go:199] ID: 2 GRPC request: {}
I0217 16:08:31.526264       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0217 16:08:31.526311       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 16:08:31.527071       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:31.527111       1 utils.go:199] ID: 3 GRPC request: {}
I0217 16:08:31.527138       1 utils.go:205] ID: 3 GRPC response: {}
I0217 16:08:31.527366       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 16:08:31.527422       1 utils.go:199] ID: 4 GRPC request: {}
I0217 16:08:31.527539       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 16:08:31.527999       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:31.528050       1 utils.go:199] ID: 5 GRPC request: {}
I0217 16:08:31.528067       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0217 16:08:31.528153       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}}}]}
I0217 16:08:33.712227       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:33.712265       1 utils.go:199] ID: 6 GRPC request: {}
I0217 16:08:33.712390       1 utils.go:205] ID: 6 GRPC response: {}
I0217 16:08:33.714177       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 16:08:33.714190       1 utils.go:199] ID: 7 GRPC request: {}
I0217 16:08:33.714199       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0217 16:08:33.714239       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 16:08:33.715516       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:33.715558       1 utils.go:199] ID: 8 GRPC request: {}
I0217 16:08:33.715578       1 utils.go:205] ID: 8 GRPC response: {}
I0217 16:08:33.715882       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 16:08:33.715920       1 utils.go:199] ID: 9 GRPC request: {}
I0217 16:08:33.716022       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 16:08:33.716426       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:33.716463       1 utils.go:199] ID: 10 GRPC request: {}
I0217 16:08:33.716479       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0217 16:08:33.716559       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}}}]}
I0217 16:08:33.716872       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:33.716909       1 utils.go:199] ID: 11 GRPC request: {}
I0217 16:08:33.716923       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0217 16:08:33.716992       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}}}]}
I0217 16:08:33.717208       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:33.717242       1 utils.go:199] ID: 12 GRPC request: {}
I0217 16:08:33.717290       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0217 16:08:33.717373       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}}}]}
I0217 16:08:36.106511       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 16:08:36.106603       1 utils.go:199] ID: 13 GRPC request: {}
I0217 16:08:36.106647       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0217 16:08:36.106706       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 16:08:36.109909       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:36.109967       1 utils.go:199] ID: 14 GRPC request: {}
I0217 16:08:36.110041       1 utils.go:205] ID: 14 GRPC response: {}
I0217 16:08:36.110726       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:36.110779       1 utils.go:199] ID: 15 GRPC request: {}
I0217 16:08:36.110809       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0217 16:08:36.110910       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}}}]}
I0217 16:08:40.450754       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:40.450804       1 utils.go:199] ID: 16 GRPC request: {}
I0217 16:08:40.450823       1 utils.go:205] ID: 16 GRPC response: {}
I0217 16:08:40.453753       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0217 16:08:40.453780       1 utils.go:199] ID: 17 GRPC request: {}
I0217 16:08:40.453789       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0217 16:08:40.453806       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0217 16:08:40.455634       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0217 16:08:40.455644       1 utils.go:199] ID: 18 GRPC request: {}
I0217 16:08:40.455652       1 utils.go:205] ID: 18 GRPC response: {}
I0217 16:08:40.455887       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0217 16:08:40.455897       1 utils.go:199] ID: 19 GRPC request: {}
I0217 16:08:40.455980       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0217 16:08:40.457097       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0217 16:08:40.457112       1 utils.go:199] ID: 20 GRPC request: {}
I0217 16:08:40.457118       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0217 16:08:40.457179       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}}}]}
I0217 16:09:40.700667       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0217 16:09:40.700856       1 utils.go:199] ID: 21 GRPC request: {}
I0217 16:09:40.700923       1 utils.go:205] ID: 21 GRPC response: {}
I0217 16:10:40.710156       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0217 16:10:40.710409       1 utils.go:199] ID: 22 GRPC request: {}
I0217 16:10:40.711397       1 utils.go:205] ID: 22 GRPC response: {}
I0217 16:11:31.407053       1 utils.go:198] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 GRPC call: /csi.v1.Controller/CreateVolume
I0217 16:11:31.408182       1 utils.go:199] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d271c8be-220e-4e71-bf25-a6311b7c0511","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-d271c8be-220e-4e71-bf25-a6311b7c0511","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}}]}
I0217 16:11:31.408345       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0217 16:11:31.435930       1 omap.go:80] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0217 16:11:31.458041       1 omap.go:159] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-d271c8be-220e-4e71-bf25-a6311b7c0511:cf6de589-33c2-4163-a0b8-857f56c80bd6])
I0217 16:11:31.466517       1 omap.go:159] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 set omap keys (pool="kube", namespace="", name="csi.volume.cf6de589-33c2-4163-a0b8-857f56c80bd6"): map[csi.imagename:csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6 csi.volname:pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 csi.volume.owner:default])
I0217 16:11:31.466547       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-cf6de589-33c2-4163-a0b8-857f56c80bd6) and image name (csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6) for request name (pvc-d271c8be-220e-4e71-bf25-a6311b7c0511)
I0217 16:11:31.466616       1 rbd_util.go:423] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 rbd: create kube/csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6 size 5120M (features: [layering]) using mon 199.204.45.113
I0217 16:11:31.466649       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 setting image options on kube/csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6
I0217 16:11:33.488556       1 controllerserver.go:763] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 created image kube/csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6 backed for request name pvc-d271c8be-220e-4e71-bf25-a6311b7c0511
I0217 16:11:33.517767       1 omap.go:159] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 set omap keys (pool="kube", namespace="", name="csi.volume.cf6de589-33c2-4163-a0b8-857f56c80bd6"): map[csi.imageid:37d8958c3ef6])
I0217 16:11:33.611979       1 utils.go:205] ID: 23 Req-ID: pvc-d271c8be-220e-4e71-bf25-a6311b7c0511 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-cf6de589-33c2-4163-a0b8-857f56c80bd6","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-cf6de589-33c2-4163-a0b8-857f56c80bd6"}}
I0217 16:11:40.754344       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0217 16:11:40.754389       1 utils.go:199] ID: 24 GRPC request: {}
I0217 16:11:40.754629       1 utils.go:205] ID: 24 GRPC response: {}