I0214 05:00:45.058545       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0214 05:00:45.058825       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0214 05:00:45.058901       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0214 05:00:45.058944       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0214 05:00:45.058978       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0214 05:00:45.059021       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0214 05:00:45.059058       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0214 05:00:45.059091       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0214 05:00:45.059219       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0214 05:00:45.059273       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0214 05:00:45.059597       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0214 05:00:45.059625       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0214 05:00:48.512455       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:48.517826       1 utils.go:199] ID: 1 GRPC request: {}
I0214 05:00:48.518457       1 utils.go:205] ID: 1 GRPC response: {}
I0214 05:00:48.520311       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0214 05:00:48.520375       1 utils.go:199] ID: 2 GRPC request: {}
I0214 05:00:48.520389       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0214 05:00:48.520424       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0214 05:00:48.521792       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:48.521875       1 utils.go:199] ID: 3 GRPC request: {}
I0214 05:00:48.521901       1 utils.go:205] ID: 3 GRPC response: {}
I0214 05:00:48.522216       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0214 05:00:48.522289       1 utils.go:199] ID: 4 GRPC request: {}
I0214 05:00:48.522482       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0214 05:00:48.523521       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:48.523605       1 utils.go:199] ID: 5 GRPC request: {}
I0214 05:00:48.523616       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0214 05:00:48.523768       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}}}]}
I0214 05:00:51.122492       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:51.122522       1 utils.go:199] ID: 6 GRPC request: {}
I0214 05:00:51.122535       1 utils.go:205] ID: 6 GRPC response: {}
I0214 05:00:51.143794       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0214 05:00:51.144801       1 utils.go:199] ID: 7 GRPC request: {}
I0214 05:00:51.144823       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0214 05:00:51.144962       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0214 05:00:51.152983       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:51.153789       1 utils.go:199] ID: 8 GRPC request: {}
I0214 05:00:51.153807       1 utils.go:205] ID: 8 GRPC response: {}
I0214 05:00:51.155256       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0214 05:00:51.155271       1 utils.go:199] ID: 9 GRPC request: {}
I0214 05:00:51.155368       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0214 05:00:51.155886       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:51.155897       1 utils.go:199] ID: 10 GRPC request: {}
I0214 05:00:51.155903       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0214 05:00:51.155969       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}}}]}
I0214 05:00:51.156388       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:51.156427       1 utils.go:199] ID: 11 GRPC request: {}
I0214 05:00:51.156432       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0214 05:00:51.156470       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}}}]}
I0214 05:00:51.156711       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:51.156743       1 utils.go:199] ID: 12 GRPC request: {}
I0214 05:00:51.156747       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0214 05:00:51.156785       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}}}]}
I0214 05:00:53.763687       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0214 05:00:53.763798       1 utils.go:199] ID: 13 GRPC request: {}
I0214 05:00:53.763841       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0214 05:00:53.763968       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0214 05:00:53.768872       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:53.768916       1 utils.go:199] ID: 14 GRPC request: {}
I0214 05:00:53.768978       1 utils.go:205] ID: 14 GRPC response: {}
I0214 05:00:53.769471       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:53.769554       1 utils.go:199] ID: 15 GRPC request: {}
I0214 05:00:53.769588       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0214 05:00:53.769849       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}}}]}
I0214 05:00:55.974671       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:55.974709       1 utils.go:199] ID: 16 GRPC request: {}
I0214 05:00:55.974726       1 utils.go:205] ID: 16 GRPC response: {}
I0214 05:00:55.978711       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0214 05:00:55.978727       1 utils.go:199] ID: 17 GRPC request: {}
I0214 05:00:55.978733       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0214 05:00:55.978749       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0214 05:00:55.980533       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0214 05:00:55.980552       1 utils.go:199] ID: 18 GRPC request: {}
I0214 05:00:55.980644       1 utils.go:205] ID: 18 GRPC response: {}
I0214 05:00:55.981140       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0214 05:00:55.981157       1 utils.go:199] ID: 19 GRPC request: {}
I0214 05:00:55.981336       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0214 05:00:55.982299       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0214 05:00:55.982488       1 utils.go:199] ID: 20 GRPC request: {}
I0214 05:00:55.982496       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0214 05:00:55.985971       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}}}]}
I0214 05:01:56.228402       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0214 05:01:56.228475       1 utils.go:199] ID: 21 GRPC request: {}
I0214 05:01:56.228536       1 utils.go:205] ID: 21 GRPC response: {}
I0214 05:02:56.167198       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0214 05:02:56.167232       1 utils.go:199] ID: 22 GRPC request: {}
I0214 05:02:56.167258       1 utils.go:205] ID: 22 GRPC response: {}
I0214 05:03:56.226109       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0214 05:03:56.226148       1 utils.go:199] ID: 23 GRPC request: {}
I0214 05:03:56.226166       1 utils.go:205] ID: 23 GRPC response: {}
I0214 05:04:01.283159       1 utils.go:198] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 GRPC call: /csi.v1.Controller/CreateVolume
I0214 05:04:01.283820       1 utils.go:199] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-6812c3b2-e298-4265-95f9-52ced4965ce6","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-6812c3b2-e298-4265-95f9-52ced4965ce6","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}}]}
I0214 05:04:01.284326       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0214 05:04:01.306358       1 omap.go:80] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0214 05:04:01.496744       1 omap.go:159] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-6812c3b2-e298-4265-95f9-52ced4965ce6:7d370dd8-69ed-460c-a1d5-b4c904f383ce])
I0214 05:04:01.582806       1 omap.go:159] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 set omap keys (pool="kube", namespace="", name="csi.volume.7d370dd8-69ed-460c-a1d5-b4c904f383ce"): map[csi.imagename:csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce csi.volname:pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 csi.volume.owner:default])
I0214 05:04:01.582836       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7d370dd8-69ed-460c-a1d5-b4c904f383ce) and image name (csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce) for request name (pvc-6812c3b2-e298-4265-95f9-52ced4965ce6)
I0214 05:04:01.582890       1 rbd_util.go:423] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 rbd: create kube/csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce size 5120M (features: [layering]) using mon 199.204.45.157
I0214 05:04:01.582914       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 setting image options on kube/csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce
I0214 05:04:03.481791       1 controllerserver.go:763] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 created image kube/csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce backed for request name pvc-6812c3b2-e298-4265-95f9-52ced4965ce6
I0214 05:04:03.614216       1 omap.go:159] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 set omap keys (pool="kube", namespace="", name="csi.volume.7d370dd8-69ed-460c-a1d5-b4c904f383ce"): map[csi.imageid:37d9cf3429d6])
I0214 05:04:03.689233       1 utils.go:205] ID: 24 Req-ID: pvc-6812c3b2-e298-4265-95f9-52ced4965ce6 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-7d370dd8-69ed-460c-a1d5-b4c904f383ce","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7d370dd8-69ed-460c-a1d5-b4c904f383ce"}}
I0214 05:04:56.168326       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0214 05:04:56.168524       1 utils.go:199] ID: 25 GRPC request: {}
I0214 05:04:56.168632       1 utils.go:205] ID: 25 GRPC response: {}