I0120 13:48:26.085696       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0120 13:48:26.086255       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0120 13:48:26.086283       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0120 13:48:26.086287       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0120 13:48:26.086289       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0120 13:48:26.086292       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0120 13:48:26.086299       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0120 13:48:26.086302       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0120 13:48:26.086304       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0120 13:48:26.086307       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0120 13:48:26.090030       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0120 13:48:26.090057       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0120 13:48:30.641445       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:30.645315       1 utils.go:199] ID: 1 GRPC request: {}
I0120 13:48:30.645479       1 utils.go:205] ID: 1 GRPC response: {}
I0120 13:48:30.648786       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0120 13:48:30.648957       1 utils.go:199] ID: 2 GRPC request: {}
I0120 13:48:30.649019       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0120 13:48:30.649104       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0120 13:48:30.653954       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:30.654034       1 utils.go:199] ID: 3 GRPC request: {}
I0120 13:48:30.654107       1 utils.go:205] ID: 3 GRPC response: {}
I0120 13:48:30.654546       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0120 13:48:30.654662       1 utils.go:199] ID: 4 GRPC request: {}
I0120 13:48:30.654856       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0120 13:48:30.655464       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:30.655574       1 utils.go:199] ID: 5 GRPC request: {}
I0120 13:48:30.655631       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0120 13:48:30.655785       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}}}]}
I0120 13:48:33.015454       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:33.015575       1 utils.go:199] ID: 6 GRPC request: {}
I0120 13:48:33.015660       1 utils.go:205] ID: 6 GRPC response: {}
I0120 13:48:33.022679       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0120 13:48:33.022764       1 utils.go:199] ID: 7 GRPC request: {}
I0120 13:48:33.022828       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0120 13:48:33.022928       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0120 13:48:33.024530       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:33.024661       1 utils.go:199] ID: 8 GRPC request: {}
I0120 13:48:33.024748       1 utils.go:205] ID: 8 GRPC response: {}
I0120 13:48:33.025259       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0120 13:48:33.025357       1 utils.go:199] ID: 9 GRPC request: {}
I0120 13:48:33.025546       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0120 13:48:33.026283       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:33.026394       1 utils.go:199] ID: 10 GRPC request: {}
I0120 13:48:33.026508       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0120 13:48:33.026653       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}}}]}
I0120 13:48:33.027244       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:33.027340       1 utils.go:199] ID: 11 GRPC request: {}
I0120 13:48:33.027401       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0120 13:48:33.027512       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}}}]}
I0120 13:48:33.027969       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:33.028063       1 utils.go:199] ID: 12 GRPC request: {}
I0120 13:48:33.028125       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0120 13:48:33.028245       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}}}]}
I0120 13:48:35.325269       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0120 13:48:35.325351       1 utils.go:199] ID: 13 GRPC request: {}
I0120 13:48:35.325369       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0120 13:48:35.325429       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0120 13:48:35.327009       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:35.327033       1 utils.go:199] ID: 14 GRPC request: {}
I0120 13:48:35.327066       1 utils.go:205] ID: 14 GRPC response: {}
I0120 13:48:35.327410       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:35.327429       1 utils.go:199] ID: 15 GRPC request: {}
I0120 13:48:35.327445       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0120 13:48:35.327610       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}}}]}
I0120 13:48:37.693365       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:37.693486       1 utils.go:199] ID: 16 GRPC request: {}
I0120 13:48:37.693544       1 utils.go:205] ID: 16 GRPC response: {}
I0120 13:48:37.707681       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0120 13:48:37.707724       1 utils.go:199] ID: 17 GRPC request: {}
I0120 13:48:37.707734       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0120 13:48:37.707763       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0120 13:48:37.711589       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0120 13:48:37.711607       1 utils.go:199] ID: 18 GRPC request: {}
I0120 13:48:37.711618       1 utils.go:205] ID: 18 GRPC response: {}
I0120 13:48:37.714717       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0120 13:48:37.714857       1 utils.go:199] ID: 19 GRPC request: {}
I0120 13:48:37.715006       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0120 13:48:37.719961       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0120 13:48:37.719998       1 utils.go:199] ID: 20 GRPC request: {}
I0120 13:48:37.720008       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0120 13:48:37.720116       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}}}]}
I0120 13:49:37.952613       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0120 13:49:37.952822       1 utils.go:199] ID: 21 GRPC request: {}
I0120 13:49:37.953048       1 utils.go:205] ID: 21 GRPC response: {}
I0120 13:50:37.893294       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0120 13:50:37.893361       1 utils.go:199] ID: 22 GRPC request: {}
I0120 13:50:37.893461       1 utils.go:205] ID: 22 GRPC response: {}
I0120 13:51:29.706088       1 utils.go:198] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 GRPC call: /csi.v1.Controller/CreateVolume
I0120 13:51:29.706583       1 utils.go:199] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61","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}}]}
I0120 13:51:29.706848       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0120 13:51:29.726242       1 omap.go:80] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0120 13:51:29.739111       1 omap.go:159] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61:69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0])
I0120 13:51:29.744175       1 omap.go:159] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 set omap keys (pool="kube", namespace="", name="csi.volume.69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0"): map[csi.imagename:csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0 csi.volname:pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 csi.volume.owner:default])
I0120 13:51:29.744203       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0) and image name (csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0) for request name (pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61)
I0120 13:51:29.744311       1 rbd_util.go:423] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 rbd: create kube/csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0 size 5120M (features: [layering]) using mon 162.253.55.62
I0120 13:51:29.744383       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 setting image options on kube/csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0
I0120 13:51:31.732105       1 controllerserver.go:763] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 created image kube/csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0 backed for request name pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61
I0120 13:51:31.759891       1 omap.go:159] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 set omap keys (pool="kube", namespace="", name="csi.volume.69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0"): map[csi.imageid:37d9baa014c1])
I0120 13:51:31.835255       1 utils.go:205] ID: 23 Req-ID: pvc-6bd6ec34-5dc3-45e0-8df1-05684cdacd61 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-69cc0cc2-6999-45da-a5ed-0ff4ae13d6f0"}}
I0120 13:51:37.951802       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0120 13:51:37.951861       1 utils.go:199] ID: 24 GRPC request: {}
I0120 13:51:37.951884       1 utils.go:205] ID: 24 GRPC response: {}