I0201 18:53:51.319676       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0201 18:53:51.319791       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0201 18:53:51.319806       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0201 18:53:51.319916       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0201 18:53:51.319939       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0201 18:53:51.319942       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0201 18:53:51.319946       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0201 18:53:51.319985       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0201 18:53:51.319988       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0201 18:53:51.319991       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0201 18:53:51.320285       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0201 18:53:51.320382       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0201 18:53:54.241024       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0201 18:53:54.242229       1 utils.go:199] ID: 1 GRPC request: {}
I0201 18:53:54.242353       1 utils.go:205] ID: 1 GRPC response: {}
I0201 18:53:54.243866       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0201 18:53:54.244002       1 utils.go:199] ID: 2 GRPC request: {}
I0201 18:53:54.244034       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0201 18:53:54.244099       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0201 18:53:54.246699       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0201 18:53:54.246767       1 utils.go:199] ID: 3 GRPC request: {}
I0201 18:53:54.246792       1 utils.go:205] ID: 3 GRPC response: {}
I0201 18:53:54.247071       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0201 18:53:54.247174       1 utils.go:199] ID: 4 GRPC request: {}
I0201 18:53:54.247335       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0201 18:53:54.247946       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:53:54.248056       1 utils.go:199] ID: 5 GRPC request: {}
I0201 18:53:54.248081       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0201 18:53:54.248215       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}}}]}
I0201 18:53:56.081064       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0201 18:53:56.081104       1 utils.go:199] ID: 6 GRPC request: {}
I0201 18:53:56.081140       1 utils.go:205] ID: 6 GRPC response: {}
I0201 18:53:56.084222       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0201 18:53:56.084251       1 utils.go:199] ID: 7 GRPC request: {}
I0201 18:53:56.084260       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0201 18:53:56.084292       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0201 18:53:56.085853       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0201 18:53:56.085879       1 utils.go:199] ID: 8 GRPC request: {}
I0201 18:53:56.085905       1 utils.go:205] ID: 8 GRPC response: {}
I0201 18:53:56.086182       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0201 18:53:56.086196       1 utils.go:199] ID: 9 GRPC request: {}
I0201 18:53:56.086280       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0201 18:53:56.086757       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:53:56.086772       1 utils.go:199] ID: 10 GRPC request: {}
I0201 18:53:56.086779       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0201 18:53:56.086849       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}}}]}
I0201 18:53:56.087183       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:53:56.087196       1 utils.go:199] ID: 11 GRPC request: {}
I0201 18:53:56.087212       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0201 18:53:56.087307       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}}}]}
I0201 18:53:56.087524       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:53:56.087537       1 utils.go:199] ID: 12 GRPC request: {}
I0201 18:53:56.087541       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0201 18:53:56.087610       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}}}]}
I0201 18:53:58.165291       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0201 18:53:58.165325       1 utils.go:199] ID: 13 GRPC request: {}
I0201 18:53:58.165333       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0201 18:53:58.165391       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0201 18:53:58.169946       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0201 18:53:58.169986       1 utils.go:199] ID: 14 GRPC request: {}
I0201 18:53:58.169999       1 utils.go:205] ID: 14 GRPC response: {}
I0201 18:53:58.170678       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:53:58.170694       1 utils.go:199] ID: 15 GRPC request: {}
I0201 18:53:58.170701       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0201 18:53:58.170788       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}}}]}
I0201 18:54:00.014882       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0201 18:54:00.014994       1 utils.go:199] ID: 16 GRPC request: {}
I0201 18:54:00.015022       1 utils.go:205] ID: 16 GRPC response: {}
I0201 18:54:00.016876       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0201 18:54:00.016910       1 utils.go:199] ID: 17 GRPC request: {}
I0201 18:54:00.016918       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0201 18:54:00.016948       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0201 18:54:00.019312       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0201 18:54:00.019417       1 utils.go:199] ID: 18 GRPC request: {}
I0201 18:54:00.019459       1 utils.go:205] ID: 18 GRPC response: {}
I0201 18:54:00.019733       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0201 18:54:00.019797       1 utils.go:199] ID: 19 GRPC request: {}
I0201 18:54:00.019941       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0201 18:54:00.020611       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0201 18:54:00.021285       1 utils.go:199] ID: 20 GRPC request: {}
I0201 18:54:00.021343       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0201 18:54:00.021434       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}}}]}
I0201 18:55:00.265469       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0201 18:55:00.265530       1 utils.go:199] ID: 21 GRPC request: {}
I0201 18:55:00.265566       1 utils.go:205] ID: 21 GRPC response: {}
I0201 18:56:00.274721       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0201 18:56:00.275137       1 utils.go:199] ID: 22 GRPC request: {}
I0201 18:56:00.275246       1 utils.go:205] ID: 22 GRPC response: {}
I0201 18:57:00.262569       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0201 18:57:00.262612       1 utils.go:199] ID: 23 GRPC request: {}
I0201 18:57:00.262630       1 utils.go:205] ID: 23 GRPC response: {}
I0201 18:57:08.602212       1 utils.go:198] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b GRPC call: /csi.v1.Controller/CreateVolume
I0201 18:57:08.603177       1 utils.go:199] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b","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}}]}
I0201 18:57:08.603467       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0201 18:57:08.646155       1 omap.go:80] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0201 18:57:08.672185       1 omap.go:159] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b:6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3])
I0201 18:57:08.681572       1 omap.go:159] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b set omap keys (pool="kube", namespace="", name="csi.volume.6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3"): map[csi.imagename:csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3 csi.volname:pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b csi.volume.owner:default])
I0201 18:57:08.681602       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3) and image name (csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3) for request name (pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b)
I0201 18:57:08.681710       1 rbd_util.go:423] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b rbd: create kube/csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3 size 5120M (features: [layering]) using mon 199.204.45.33
I0201 18:57:08.681752       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b setting image options on kube/csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3
I0201 18:57:10.561270       1 controllerserver.go:763] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b created image kube/csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3 backed for request name pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b
I0201 18:57:10.609465       1 omap.go:159] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b set omap keys (pool="kube", namespace="", name="csi.volume.6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3"): map[csi.imageid:37d8308648ee])
I0201 18:57:10.697698       1 utils.go:205] ID: 24 Req-ID: pvc-f14e90ca-1137-448a-8665-c0c10e0f9a4b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6bf20f40-09ee-4b64-9229-ccc2fb4aa7d3"}}
I0201 18:58:00.302849       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0201 18:58:00.302891       1 utils.go:199] ID: 25 GRPC request: {}
I0201 18:58:00.302936       1 utils.go:205] ID: 25 GRPC response: {}