I0204 18:22:59.019318       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0204 18:22:59.019572       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0204 18:22:59.019646       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0204 18:22:59.019688       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0204 18:22:59.019721       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0204 18:22:59.019765       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0204 18:22:59.019806       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0204 18:22:59.019834       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0204 18:22:59.019881       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0204 18:22:59.019918       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0204 18:22:59.020233       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0204 18:22:59.020239       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0204 18:23:07.510602       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:07.512906       1 utils.go:199] ID: 1 GRPC request: {}
I0204 18:23:07.512984       1 utils.go:205] ID: 1 GRPC response: {}
I0204 18:23:07.516524       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 18:23:07.516612       1 utils.go:199] ID: 2 GRPC request: {}
I0204 18:23:07.516644       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0204 18:23:07.516738       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 18:23:07.517909       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:07.517924       1 utils.go:199] ID: 3 GRPC request: {}
I0204 18:23:07.517994       1 utils.go:205] ID: 3 GRPC response: {}
I0204 18:23:07.518244       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 18:23:07.518378       1 utils.go:199] ID: 4 GRPC request: {}
I0204 18:23:07.518564       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 18:23:07.519189       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:07.519279       1 utils.go:199] ID: 5 GRPC request: {}
I0204 18:23:07.519357       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0204 18:23:07.519492       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}}}]}
I0204 18:23:10.997396       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:10.997429       1 utils.go:199] ID: 6 GRPC request: {}
I0204 18:23:10.997445       1 utils.go:205] ID: 6 GRPC response: {}
I0204 18:23:11.002123       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 18:23:11.002144       1 utils.go:199] ID: 7 GRPC request: {}
I0204 18:23:11.002151       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0204 18:23:11.002174       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 18:23:11.004282       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:11.004297       1 utils.go:199] ID: 8 GRPC request: {}
I0204 18:23:11.004309       1 utils.go:205] ID: 8 GRPC response: {}
I0204 18:23:11.005163       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 18:23:11.005180       1 utils.go:199] ID: 9 GRPC request: {}
I0204 18:23:11.005355       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 18:23:11.005740       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:11.005758       1 utils.go:199] ID: 10 GRPC request: {}
I0204 18:23:11.005765       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0204 18:23:11.005867       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}}}]}
I0204 18:23:11.006310       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:11.006345       1 utils.go:199] ID: 11 GRPC request: {}
I0204 18:23:11.006352       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0204 18:23:11.006453       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}}}]}
I0204 18:23:11.006720       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:11.006736       1 utils.go:199] ID: 12 GRPC request: {}
I0204 18:23:11.006741       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0204 18:23:11.006802       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}}}]}
I0204 18:23:18.151143       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 18:23:18.151197       1 utils.go:199] ID: 13 GRPC request: {}
I0204 18:23:18.151219       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0204 18:23:18.151279       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 18:23:18.152670       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:18.152697       1 utils.go:199] ID: 14 GRPC request: {}
I0204 18:23:18.152710       1 utils.go:205] ID: 14 GRPC response: {}
I0204 18:23:18.154072       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:18.154086       1 utils.go:199] ID: 15 GRPC request: {}
I0204 18:23:18.154092       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0204 18:23:18.154190       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}}}]}
I0204 18:23:21.633148       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:21.633245       1 utils.go:199] ID: 16 GRPC request: {}
I0204 18:23:21.633297       1 utils.go:205] ID: 16 GRPC response: {}
I0204 18:23:21.640851       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 18:23:21.640897       1 utils.go:199] ID: 17 GRPC request: {}
I0204 18:23:21.640904       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0204 18:23:21.640926       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 18:23:21.642764       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0204 18:23:21.642834       1 utils.go:199] ID: 18 GRPC request: {}
I0204 18:23:21.642852       1 utils.go:205] ID: 18 GRPC response: {}
I0204 18:23:21.645286       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 18:23:21.645363       1 utils.go:199] ID: 19 GRPC request: {}
I0204 18:23:21.645460       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 18:23:21.652797       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 18:23:21.652851       1 utils.go:199] ID: 20 GRPC request: {}
I0204 18:23:21.652860       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0204 18:23:21.653591       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}}}]}
I0204 18:24:21.934664       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0204 18:24:21.934860       1 utils.go:199] ID: 21 GRPC request: {}
I0204 18:24:21.934959       1 utils.go:205] ID: 21 GRPC response: {}
I0204 18:25:21.879218       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0204 18:25:21.879811       1 utils.go:199] ID: 22 GRPC request: {}
I0204 18:25:21.880393       1 utils.go:205] ID: 22 GRPC response: {}
I0204 18:26:19.029082       1 utils.go:198] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c GRPC call: /csi.v1.Controller/CreateVolume
I0204 18:26:19.029538       1 utils.go:199] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c","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}}]}
I0204 18:26:19.029764       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c setting disableInUseChecks: false image features: [layering] mounter: rbd
E0204 18:26:19.105430       1 omap.go:80] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0204 18:26:19.248637       1 omap.go:159] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c:9997fcd6-fc06-4403-b7b4-1813563704e8])
I0204 18:26:19.257512       1 omap.go:159] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c set omap keys (pool="kube", namespace="", name="csi.volume.9997fcd6-fc06-4403-b7b4-1813563704e8"): map[csi.imagename:csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8 csi.volname:pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c csi.volume.owner:default])
I0204 18:26:19.257655       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9997fcd6-fc06-4403-b7b4-1813563704e8) and image name (csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8) for request name (pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c)
I0204 18:26:19.257737       1 rbd_util.go:423] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c rbd: create kube/csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8 size 5120M (features: [layering]) using mon 162.253.55.74
I0204 18:26:19.257777       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c setting image options on kube/csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8
I0204 18:26:21.310902       1 controllerserver.go:763] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c created image kube/csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8 backed for request name pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c
I0204 18:26:21.340471       1 omap.go:159] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c set omap keys (pool="kube", namespace="", name="csi.volume.9997fcd6-fc06-4403-b7b4-1813563704e8"): map[csi.imageid:37d9aab5c59])
I0204 18:26:21.441623       1 utils.go:205] ID: 23 Req-ID: pvc-d9585e7f-467e-43ef-a60a-196cd28a6d2c GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-9997fcd6-fc06-4403-b7b4-1813563704e8","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9997fcd6-fc06-4403-b7b4-1813563704e8"}}
I0204 18:26:21.875920       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0204 18:26:21.875963       1 utils.go:199] ID: 24 GRPC request: {}
I0204 18:26:21.875999       1 utils.go:205] ID: 24 GRPC response: {}