I0331 11:00:42.273584       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0331 11:00:42.273755       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0331 11:00:42.273770       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0331 11:00:42.273782       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0331 11:00:42.273785       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0331 11:00:42.273788       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0331 11:00:42.273793       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0331 11:00:42.273796       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0331 11:00:42.273798       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0331 11:00:42.273801       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0331 11:00:42.274215       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0331 11:00:42.274237       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0331 11:00:44.613656       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:44.615761       1 utils.go:199] ID: 1 GRPC request: {}
I0331 11:00:44.615927       1 utils.go:205] ID: 1 GRPC response: {}
I0331 11:00:44.618083       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0331 11:00:44.618170       1 utils.go:199] ID: 2 GRPC request: {}
I0331 11:00:44.618191       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0331 11:00:44.618416       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0331 11:00:44.620594       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:44.620627       1 utils.go:199] ID: 3 GRPC request: {}
I0331 11:00:44.620780       1 utils.go:205] ID: 3 GRPC response: {}
I0331 11:00:44.621445       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0331 11:00:44.621547       1 utils.go:199] ID: 4 GRPC request: {}
I0331 11:00:44.621825       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0331 11:00:44.622837       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:44.622902       1 utils.go:199] ID: 5 GRPC request: {}
I0331 11:00:44.622916       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0331 11:00:44.623020       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}}}]}
I0331 11:00:46.629253       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:46.629317       1 utils.go:199] ID: 6 GRPC request: {}
I0331 11:00:46.629350       1 utils.go:205] ID: 6 GRPC response: {}
I0331 11:00:46.632808       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0331 11:00:46.632840       1 utils.go:199] ID: 7 GRPC request: {}
I0331 11:00:46.632852       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0331 11:00:46.632905       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0331 11:00:46.634929       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:46.634961       1 utils.go:199] ID: 8 GRPC request: {}
I0331 11:00:46.634994       1 utils.go:205] ID: 8 GRPC response: {}
I0331 11:00:46.635639       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0331 11:00:46.635701       1 utils.go:199] ID: 9 GRPC request: {}
I0331 11:00:46.635837       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0331 11:00:46.636535       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:46.636569       1 utils.go:199] ID: 10 GRPC request: {}
I0331 11:00:46.636585       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0331 11:00:46.636743       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}}}]}
I0331 11:00:46.637381       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:46.637427       1 utils.go:199] ID: 11 GRPC request: {}
I0331 11:00:46.637451       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0331 11:00:46.637623       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}}}]}
I0331 11:00:46.638268       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:46.638300       1 utils.go:199] ID: 12 GRPC request: {}
I0331 11:00:46.638314       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0331 11:00:46.638422       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}}}]}
I0331 11:00:47.796332       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0331 11:00:47.796386       1 utils.go:199] ID: 13 GRPC request: {}
I0331 11:00:47.796398       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0331 11:00:47.796435       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0331 11:00:47.800980       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:47.801103       1 utils.go:199] ID: 14 GRPC request: {}
I0331 11:00:47.801146       1 utils.go:205] ID: 14 GRPC response: {}
I0331 11:00:47.801587       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:47.801651       1 utils.go:199] ID: 15 GRPC request: {}
I0331 11:00:47.801676       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0331 11:00:47.801813       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}}}]}
I0331 11:00:49.052285       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:49.052331       1 utils.go:199] ID: 16 GRPC request: {}
I0331 11:00:49.052357       1 utils.go:205] ID: 16 GRPC response: {}
I0331 11:00:49.057103       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0331 11:00:49.057129       1 utils.go:199] ID: 17 GRPC request: {}
I0331 11:00:49.057138       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0331 11:00:49.057161       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0331 11:00:49.060149       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0331 11:00:49.060171       1 utils.go:199] ID: 18 GRPC request: {}
I0331 11:00:49.060183       1 utils.go:205] ID: 18 GRPC response: {}
I0331 11:00:49.060610       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0331 11:00:49.060629       1 utils.go:199] ID: 19 GRPC request: {}
I0331 11:00:49.060727       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0331 11:00:49.061602       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0331 11:00:49.061658       1 utils.go:199] ID: 20 GRPC request: {}
I0331 11:00:49.061674       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0331 11:00:49.061811       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}}}]}
I0331 11:01:49.304717       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0331 11:01:49.304781       1 utils.go:199] ID: 21 GRPC request: {}
I0331 11:01:49.304807       1 utils.go:205] ID: 21 GRPC response: {}
I0331 11:02:49.249258       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0331 11:02:49.249363       1 utils.go:199] ID: 22 GRPC request: {}
I0331 11:02:49.249393       1 utils.go:205] ID: 22 GRPC response: {}
I0331 11:03:49.248270       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0331 11:03:49.248379       1 utils.go:199] ID: 23 GRPC request: {}
I0331 11:03:49.248405       1 utils.go:205] ID: 23 GRPC response: {}
I0331 11:04:08.053007       1 utils.go:198] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 GRPC call: /csi.v1.Controller/CreateVolume
I0331 11:04:08.053333       1 utils.go:199] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9","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}}]}
I0331 11:04:08.053623       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0331 11:04:08.074492       1 omap.go:80] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0331 11:04:08.093561       1 omap.go:159] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9:d2b5f72d-e33a-47a4-8118-fa04930b755c])
I0331 11:04:08.105082       1 omap.go:159] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 set omap keys (pool="kube", namespace="", name="csi.volume.d2b5f72d-e33a-47a4-8118-fa04930b755c"): map[csi.imagename:csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c csi.volname:pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 csi.volume.owner:default])
I0331 11:04:08.105122       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d2b5f72d-e33a-47a4-8118-fa04930b755c) and image name (csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c) for request name (pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9)
I0331 11:04:08.105214       1 rbd_util.go:423] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 rbd: create kube/csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c size 5120M (features: [layering]) using mon 199.204.45.109
I0331 11:04:08.105304       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 setting image options on kube/csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c
I0331 11:04:09.437272       1 controllerserver.go:763] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 created image kube/csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c backed for request name pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9
I0331 11:04:09.487775       1 omap.go:159] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 set omap keys (pool="kube", namespace="", name="csi.volume.d2b5f72d-e33a-47a4-8118-fa04930b755c"): map[csi.imageid:37d940d9ef66])
I0331 11:04:09.581792       1 utils.go:205] ID: 24 Req-ID: pvc-fd6c0daf-467a-4e42-a84e-c8d1bfb00ed9 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d2b5f72d-e33a-47a4-8118-fa04930b755c","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d2b5f72d-e33a-47a4-8118-fa04930b755c"}}
I0331 11:04:49.262726       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0331 11:04:49.262800       1 utils.go:199] ID: 25 GRPC request: {}
I0331 11:04:49.262826       1 utils.go:205] ID: 25 GRPC response: {}