I0819 09:12:09.615086       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0819 09:12:09.615210       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0819 09:12:09.615223       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0819 09:12:09.615229       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0819 09:12:09.615231       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0819 09:12:09.615235       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0819 09:12:09.615239       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0819 09:12:09.615243       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0819 09:12:09.615247       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0819 09:12:09.615251       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0819 09:12:09.615533       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0819 09:12:09.615584       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0819 09:12:12.447050       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:12.449331       1 utils.go:199] ID: 1 GRPC request: {}
I0819 09:12:12.449390       1 utils.go:205] ID: 1 GRPC response: {}
I0819 09:12:12.451831       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0819 09:12:12.451973       1 utils.go:199] ID: 2 GRPC request: {}
I0819 09:12:12.452034       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0819 09:12:12.452154       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0819 09:12:12.456079       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:12.456125       1 utils.go:199] ID: 3 GRPC request: {}
I0819 09:12:12.456143       1 utils.go:205] ID: 3 GRPC response: {}
I0819 09:12:12.456776       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0819 09:12:12.456885       1 utils.go:199] ID: 4 GRPC request: {}
I0819 09:12:12.457082       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0819 09:12:12.457780       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:12.457843       1 utils.go:199] ID: 5 GRPC request: {}
I0819 09:12:12.457863       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0819 09:12:12.457972       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}}}]}
I0819 09:12:14.728514       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:14.728545       1 utils.go:199] ID: 6 GRPC request: {}
I0819 09:12:14.728558       1 utils.go:205] ID: 6 GRPC response: {}
I0819 09:12:14.729983       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0819 09:12:14.729998       1 utils.go:199] ID: 7 GRPC request: {}
I0819 09:12:14.730004       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0819 09:12:14.730022       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0819 09:12:14.732271       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:14.732295       1 utils.go:199] ID: 8 GRPC request: {}
I0819 09:12:14.732310       1 utils.go:205] ID: 8 GRPC response: {}
I0819 09:12:14.732914       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0819 09:12:14.732975       1 utils.go:199] ID: 9 GRPC request: {}
I0819 09:12:14.733090       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0819 09:12:14.733844       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:14.733883       1 utils.go:199] ID: 10 GRPC request: {}
I0819 09:12:14.733896       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0819 09:12:14.734002       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}}}]}
I0819 09:12:14.734579       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:14.734600       1 utils.go:199] ID: 11 GRPC request: {}
I0819 09:12:14.734607       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0819 09:12:14.734667       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}}}]}
I0819 09:12:14.734945       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:14.734996       1 utils.go:199] ID: 12 GRPC request: {}
I0819 09:12:14.735020       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0819 09:12:14.735121       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}}}]}
I0819 09:12:16.352165       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0819 09:12:16.352217       1 utils.go:199] ID: 13 GRPC request: {}
I0819 09:12:16.352235       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0819 09:12:16.352269       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0819 09:12:16.356991       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:16.357027       1 utils.go:199] ID: 14 GRPC request: {}
I0819 09:12:16.357111       1 utils.go:205] ID: 14 GRPC response: {}
I0819 09:12:16.357741       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:16.357784       1 utils.go:199] ID: 15 GRPC request: {}
I0819 09:12:16.357794       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0819 09:12:16.357910       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}}}]}
I0819 09:12:17.874443       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:17.874496       1 utils.go:199] ID: 16 GRPC request: {}
I0819 09:12:17.874509       1 utils.go:205] ID: 16 GRPC response: {}
I0819 09:12:17.877122       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0819 09:12:17.877201       1 utils.go:199] ID: 17 GRPC request: {}
I0819 09:12:17.877219       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0819 09:12:17.877267       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0819 09:12:17.878736       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0819 09:12:17.878760       1 utils.go:199] ID: 18 GRPC request: {}
I0819 09:12:17.878769       1 utils.go:205] ID: 18 GRPC response: {}
I0819 09:12:17.879663       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0819 09:12:17.879701       1 utils.go:199] ID: 19 GRPC request: {}
I0819 09:12:17.879892       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0819 09:12:17.881177       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0819 09:12:17.881196       1 utils.go:199] ID: 20 GRPC request: {}
I0819 09:12:17.881202       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0819 09:12:17.881290       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}}}]}
I0819 09:13:18.068879       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0819 09:13:18.068932       1 utils.go:199] ID: 21 GRPC request: {}
I0819 09:13:18.068953       1 utils.go:205] ID: 21 GRPC response: {}
I0819 09:14:18.072299       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0819 09:14:18.072363       1 utils.go:199] ID: 22 GRPC request: {}
I0819 09:14:18.072386       1 utils.go:205] ID: 22 GRPC response: {}
I0819 09:15:08.221005       1 utils.go:198] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b GRPC call: /csi.v1.Controller/CreateVolume
I0819 09:15:08.221380       1 utils.go:199] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b","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}}]}
I0819 09:15:08.221680       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0819 09:15:08.237658       1 omap.go:80] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0819 09:15:08.244246       1 omap.go:159] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b:ca364139-7c0f-405b-b911-4a44eecef398])
I0819 09:15:08.247941       1 omap.go:159] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b set omap keys (pool="kube", namespace="", name="csi.volume.ca364139-7c0f-405b-b911-4a44eecef398"): map[csi.imagename:csi-vol-ca364139-7c0f-405b-b911-4a44eecef398 csi.volname:pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b csi.volume.owner:default])
I0819 09:15:08.247974       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ca364139-7c0f-405b-b911-4a44eecef398) and image name (csi-vol-ca364139-7c0f-405b-b911-4a44eecef398) for request name (pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b)
I0819 09:15:08.248128       1 rbd_util.go:423] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b rbd: create kube/csi-vol-ca364139-7c0f-405b-b911-4a44eecef398 size 5120M (features: [layering]) using mon 199.19.213.136
I0819 09:15:08.248232       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b setting image options on kube/csi-vol-ca364139-7c0f-405b-b911-4a44eecef398
I0819 09:15:08.274153       1 controllerserver.go:763] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b created image kube/csi-vol-ca364139-7c0f-405b-b911-4a44eecef398 backed for request name pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b
I0819 09:15:08.311138       1 omap.go:159] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b set omap keys (pool="kube", namespace="", name="csi.volume.ca364139-7c0f-405b-b911-4a44eecef398"): map[csi.imageid:38043ac95343])
I0819 09:15:08.384074       1 utils.go:205] ID: 23 Req-ID: pvc-464bb66d-c277-405e-b1d1-c1f242fcea9b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ca364139-7c0f-405b-b911-4a44eecef398","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ca364139-7c0f-405b-b911-4a44eecef398"}}
I0819 09:15:18.120931       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0819 09:15:18.121016       1 utils.go:199] ID: 24 GRPC request: {}
I0819 09:15:18.121043       1 utils.go:205] ID: 24 GRPC response: {}