I0210 18:53:21.099514       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0210 18:53:21.099853       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0210 18:53:21.099921       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0210 18:53:21.099939       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0210 18:53:21.099962       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0210 18:53:21.100001       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0210 18:53:21.100029       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0210 18:53:21.100053       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0210 18:53:21.100111       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0210 18:53:21.100178       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0210 18:53:21.100443       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0210 18:53:21.100563       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0210 18:53:27.926779       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:27.935975       1 utils.go:199] ID: 1 GRPC request: {}
I0210 18:53:27.936132       1 utils.go:205] ID: 1 GRPC response: {}
I0210 18:53:27.938240       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0210 18:53:27.938413       1 utils.go:199] ID: 2 GRPC request: {}
I0210 18:53:27.938479       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0210 18:53:27.938571       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0210 18:53:27.940113       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:27.940228       1 utils.go:199] ID: 3 GRPC request: {}
I0210 18:53:27.940309       1 utils.go:205] ID: 3 GRPC response: {}
I0210 18:53:27.947670       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0210 18:53:27.947810       1 utils.go:199] ID: 4 GRPC request: {}
I0210 18:53:27.947994       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0210 18:53:27.951867       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:27.952016       1 utils.go:199] ID: 5 GRPC request: {}
I0210 18:53:27.952078       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0210 18:53:27.952229       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}}}]}
I0210 18:53:31.908606       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:31.908719       1 utils.go:199] ID: 6 GRPC request: {}
I0210 18:53:31.908778       1 utils.go:205] ID: 6 GRPC response: {}
I0210 18:53:31.914651       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0210 18:53:31.914733       1 utils.go:199] ID: 7 GRPC request: {}
I0210 18:53:31.914787       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0210 18:53:31.914896       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0210 18:53:31.917326       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:31.917445       1 utils.go:199] ID: 8 GRPC request: {}
I0210 18:53:31.917574       1 utils.go:205] ID: 8 GRPC response: {}
I0210 18:53:31.917915       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0210 18:53:31.917989       1 utils.go:199] ID: 9 GRPC request: {}
I0210 18:53:31.918127       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0210 18:53:31.918785       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:31.918861       1 utils.go:199] ID: 10 GRPC request: {}
I0210 18:53:31.918967       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0210 18:53:31.919121       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}}}]}
I0210 18:53:31.919476       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:31.919547       1 utils.go:199] ID: 11 GRPC request: {}
I0210 18:53:31.919591       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0210 18:53:31.919712       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}}}]}
I0210 18:53:31.919987       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:31.920068       1 utils.go:199] ID: 12 GRPC request: {}
I0210 18:53:31.920125       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0210 18:53:31.920238       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}}}]}
I0210 18:53:33.902951       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0210 18:53:33.903055       1 utils.go:199] ID: 13 GRPC request: {}
I0210 18:53:33.903102       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0210 18:53:33.903169       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0210 18:53:33.906958       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:33.907066       1 utils.go:199] ID: 14 GRPC request: {}
I0210 18:53:33.907087       1 utils.go:205] ID: 14 GRPC response: {}
I0210 18:53:33.907556       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:33.907643       1 utils.go:199] ID: 15 GRPC request: {}
I0210 18:53:33.907711       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0210 18:53:33.907886       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}}}]}
I0210 18:53:36.656986       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:36.657117       1 utils.go:199] ID: 16 GRPC request: {}
I0210 18:53:36.657166       1 utils.go:205] ID: 16 GRPC response: {}
I0210 18:53:36.669738       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0210 18:53:36.669832       1 utils.go:199] ID: 17 GRPC request: {}
I0210 18:53:36.669850       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0210 18:53:36.669908       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0210 18:53:36.671670       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0210 18:53:36.671778       1 utils.go:199] ID: 18 GRPC request: {}
I0210 18:53:36.671801       1 utils.go:205] ID: 18 GRPC response: {}
I0210 18:53:36.672204       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0210 18:53:36.672235       1 utils.go:199] ID: 19 GRPC request: {}
I0210 18:53:36.672304       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0210 18:53:36.672734       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0210 18:53:36.672823       1 utils.go:199] ID: 20 GRPC request: {}
I0210 18:53:36.672874       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0210 18:53:36.673034       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}}}]}
I0210 18:54:37.062868       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0210 18:54:37.063067       1 utils.go:199] ID: 21 GRPC request: {}
I0210 18:54:37.063247       1 utils.go:205] ID: 21 GRPC response: {}
I0210 18:55:37.062504       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0210 18:55:37.062606       1 utils.go:199] ID: 22 GRPC request: {}
I0210 18:55:37.062635       1 utils.go:205] ID: 22 GRPC response: {}
I0210 18:56:31.914224       1 utils.go:198] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 GRPC call: /csi.v1.Controller/CreateVolume
I0210 18:56:31.914603       1 utils.go:199] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148","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}}]}
I0210 18:56:31.914892       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0210 18:56:31.935311       1 omap.go:80] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0210 18:56:31.951003       1 omap.go:159] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148:7f84e771-6d05-46a6-b67d-c7d6c21aa733])
I0210 18:56:31.956554       1 omap.go:159] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 set omap keys (pool="kube", namespace="", name="csi.volume.7f84e771-6d05-46a6-b67d-c7d6c21aa733"): map[csi.imagename:csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733 csi.volname:pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 csi.volume.owner:default])
I0210 18:56:31.956574       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7f84e771-6d05-46a6-b67d-c7d6c21aa733) and image name (csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733) for request name (pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148)
I0210 18:56:31.956633       1 rbd_util.go:423] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 rbd: create kube/csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733 size 5120M (features: [layering]) using mon 199.204.45.222
I0210 18:56:31.956653       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 setting image options on kube/csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733
I0210 18:56:33.654882       1 controllerserver.go:763] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 created image kube/csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733 backed for request name pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148
I0210 18:56:33.689179       1 omap.go:159] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 set omap keys (pool="kube", namespace="", name="csi.volume.7f84e771-6d05-46a6-b67d-c7d6c21aa733"): map[csi.imageid:37d920b5ac0b])
I0210 18:56:33.770503       1 utils.go:205] ID: 23 Req-ID: pvc-e4922f42-4aa4-4b6e-b568-4cfb81634148 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-7f84e771-6d05-46a6-b67d-c7d6c21aa733","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7f84e771-6d05-46a6-b67d-c7d6c21aa733"}}
I0210 18:56:37.062294       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0210 18:56:37.062333       1 utils.go:199] ID: 24 GRPC request: {}
I0210 18:56:37.062349       1 utils.go:205] ID: 24 GRPC response: {}