I0630 18:05:25.245637       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0630 18:05:25.245808       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0630 18:05:25.245832       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0630 18:05:25.245846       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0630 18:05:25.245865       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0630 18:05:25.245878       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0630 18:05:25.245923       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0630 18:05:25.245947       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0630 18:05:25.245963       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0630 18:05:25.245977       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0630 18:05:25.246251       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0630 18:05:25.246539       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0630 18:05:30.757013       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:30.758431       1 utils.go:199] ID: 1 GRPC request: {}
I0630 18:05:30.758494       1 utils.go:205] ID: 1 GRPC response: {}
I0630 18:05:30.768991       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0630 18:05:30.769106       1 utils.go:199] ID: 2 GRPC request: {}
I0630 18:05:30.769138       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0630 18:05:30.769207       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0630 18:05:30.770540       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:30.770649       1 utils.go:199] ID: 3 GRPC request: {}
I0630 18:05:30.770676       1 utils.go:205] ID: 3 GRPC response: {}
I0630 18:05:30.771165       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0630 18:05:30.771279       1 utils.go:199] ID: 4 GRPC request: {}
I0630 18:05:30.771443       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0630 18:05:30.772151       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:30.772278       1 utils.go:199] ID: 5 GRPC request: {}
I0630 18:05:30.772294       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0630 18:05:30.772548       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}}}]}
I0630 18:05:32.530055       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:32.530109       1 utils.go:199] ID: 6 GRPC request: {}
I0630 18:05:32.530129       1 utils.go:205] ID: 6 GRPC response: {}
I0630 18:05:32.534943       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0630 18:05:32.534990       1 utils.go:199] ID: 7 GRPC request: {}
I0630 18:05:32.535003       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0630 18:05:32.535104       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0630 18:05:32.539409       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:32.539443       1 utils.go:199] ID: 8 GRPC request: {}
I0630 18:05:32.539462       1 utils.go:205] ID: 8 GRPC response: {}
I0630 18:05:32.539906       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0630 18:05:32.539953       1 utils.go:199] ID: 9 GRPC request: {}
I0630 18:05:32.540118       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0630 18:05:32.540939       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:32.540972       1 utils.go:199] ID: 10 GRPC request: {}
I0630 18:05:32.540983       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0630 18:05:32.541128       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}}}]}
I0630 18:05:32.541566       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:32.541581       1 utils.go:199] ID: 11 GRPC request: {}
I0630 18:05:32.541588       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0630 18:05:32.541685       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}}}]}
I0630 18:05:32.541974       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:32.542011       1 utils.go:199] ID: 12 GRPC request: {}
I0630 18:05:32.542021       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0630 18:05:32.542139       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}}}]}
I0630 18:05:34.326030       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0630 18:05:34.326068       1 utils.go:199] ID: 13 GRPC request: {}
I0630 18:05:34.326077       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0630 18:05:34.326102       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0630 18:05:34.329925       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:34.329948       1 utils.go:199] ID: 14 GRPC request: {}
I0630 18:05:34.329959       1 utils.go:205] ID: 14 GRPC response: {}
I0630 18:05:34.330372       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:34.330388       1 utils.go:199] ID: 15 GRPC request: {}
I0630 18:05:34.330395       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0630 18:05:34.330468       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}}}]}
I0630 18:05:36.022237       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:36.022285       1 utils.go:199] ID: 16 GRPC request: {}
I0630 18:05:36.022399       1 utils.go:205] ID: 16 GRPC response: {}
I0630 18:05:36.026269       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0630 18:05:36.026312       1 utils.go:199] ID: 17 GRPC request: {}
I0630 18:05:36.026323       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0630 18:05:36.026353       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0630 18:05:36.031646       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0630 18:05:36.031704       1 utils.go:199] ID: 18 GRPC request: {}
I0630 18:05:36.031734       1 utils.go:205] ID: 18 GRPC response: {}
I0630 18:05:36.032565       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0630 18:05:36.032609       1 utils.go:199] ID: 19 GRPC request: {}
I0630 18:05:36.032758       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0630 18:05:36.034868       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0630 18:05:36.034908       1 utils.go:199] ID: 20 GRPC request: {}
I0630 18:05:36.034917       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0630 18:05:36.035002       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}}}]}
I0630 18:06:36.171023       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0630 18:06:36.171095       1 utils.go:199] ID: 21 GRPC request: {}
I0630 18:06:36.171117       1 utils.go:205] ID: 21 GRPC response: {}
I0630 18:07:36.170766       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0630 18:07:36.170913       1 utils.go:199] ID: 22 GRPC request: {}
I0630 18:07:36.170983       1 utils.go:205] ID: 22 GRPC response: {}
I0630 18:08:36.222448       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0630 18:08:36.222510       1 utils.go:199] ID: 23 GRPC request: {}
I0630 18:08:36.222533       1 utils.go:205] ID: 23 GRPC response: {}
I0630 18:09:11.503301       1 utils.go:198] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b GRPC call: /csi.v1.Controller/CreateVolume
I0630 18:09:11.503856       1 utils.go:199] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b","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}}]}
I0630 18:09:11.504348       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0630 18:09:11.524324       1 omap.go:80] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0630 18:09:11.540012       1 omap.go:159] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b:ff7144f8-f409-44bd-9aee-19dcad41db28])
I0630 18:09:11.545228       1 omap.go:159] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b set omap keys (pool="kube", namespace="", name="csi.volume.ff7144f8-f409-44bd-9aee-19dcad41db28"): map[csi.imagename:csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28 csi.volname:pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b csi.volume.owner:default])
I0630 18:09:11.545263       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ff7144f8-f409-44bd-9aee-19dcad41db28) and image name (csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28) for request name (pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b)
I0630 18:09:11.545428       1 rbd_util.go:423] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b rbd: create kube/csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28 size 5120M (features: [layering]) using mon 199.204.45.162
I0630 18:09:11.545515       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b setting image options on kube/csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28
I0630 18:09:11.573549       1 controllerserver.go:763] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b created image kube/csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28 backed for request name pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b
I0630 18:09:11.603380       1 omap.go:159] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b set omap keys (pool="kube", namespace="", name="csi.volume.ff7144f8-f409-44bd-9aee-19dcad41db28"): map[csi.imageid:37ed8eb2b0c6])
I0630 18:09:11.693813       1 utils.go:205] ID: 24 Req-ID: pvc-c2e73e93-3945-4d3f-a04c-e4eb7d30c04b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ff7144f8-f409-44bd-9aee-19dcad41db28","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ff7144f8-f409-44bd-9aee-19dcad41db28"}}
I0630 18:09:36.183417       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0630 18:09:36.183477       1 utils.go:199] ID: 25 GRPC request: {}
I0630 18:09:36.183502       1 utils.go:205] ID: 25 GRPC response: {}