I0224 13:04:08.155763       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0224 13:04:08.155898       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0224 13:04:08.155910       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0224 13:04:08.155914       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0224 13:04:08.155918       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0224 13:04:08.155922       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0224 13:04:08.155926       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0224 13:04:08.155930       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0224 13:04:08.155933       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0224 13:04:08.155936       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0224 13:04:08.156232       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0224 13:04:08.156291       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0224 13:04:13.745738       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:13.749166       1 utils.go:199] ID: 1 GRPC request: {}
I0224 13:04:13.749262       1 utils.go:205] ID: 1 GRPC response: {}
I0224 13:04:13.751632       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 13:04:13.751822       1 utils.go:199] ID: 2 GRPC request: {}
I0224 13:04:13.751846       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0224 13:04:13.751938       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 13:04:13.753076       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:13.753096       1 utils.go:199] ID: 3 GRPC request: {}
I0224 13:04:13.753109       1 utils.go:205] ID: 3 GRPC response: {}
I0224 13:04:13.753592       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 13:04:13.753656       1 utils.go:199] ID: 4 GRPC request: {}
I0224 13:04:13.753773       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 13:04:13.754579       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:13.754697       1 utils.go:199] ID: 5 GRPC request: {}
I0224 13:04:13.754711       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0224 13:04:13.754867       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}}}]}
I0224 13:04:16.494324       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:16.494403       1 utils.go:199] ID: 6 GRPC request: {}
I0224 13:04:16.494482       1 utils.go:205] ID: 6 GRPC response: {}
I0224 13:04:16.502629       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 13:04:16.502763       1 utils.go:199] ID: 7 GRPC request: {}
I0224 13:04:16.502780       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0224 13:04:16.502812       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 13:04:16.504919       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:16.504942       1 utils.go:199] ID: 8 GRPC request: {}
I0224 13:04:16.504956       1 utils.go:205] ID: 8 GRPC response: {}
I0224 13:04:16.505559       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 13:04:16.505579       1 utils.go:199] ID: 9 GRPC request: {}
I0224 13:04:16.505690       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 13:04:16.506443       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:16.506640       1 utils.go:199] ID: 10 GRPC request: {}
I0224 13:04:16.506655       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0224 13:04:16.507658       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}}}]}
I0224 13:04:16.508400       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:16.508436       1 utils.go:199] ID: 11 GRPC request: {}
I0224 13:04:16.508455       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0224 13:04:16.508568       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}}}]}
I0224 13:04:16.509024       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:16.509049       1 utils.go:199] ID: 12 GRPC request: {}
I0224 13:04:16.509056       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0224 13:04:16.509118       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}}}]}
I0224 13:04:18.657419       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 13:04:18.657473       1 utils.go:199] ID: 13 GRPC request: {}
I0224 13:04:18.657483       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0224 13:04:18.657515       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 13:04:18.659370       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:18.659391       1 utils.go:199] ID: 14 GRPC request: {}
I0224 13:04:18.659405       1 utils.go:205] ID: 14 GRPC response: {}
I0224 13:04:18.659835       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:18.659873       1 utils.go:199] ID: 15 GRPC request: {}
I0224 13:04:18.659882       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0224 13:04:18.659990       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}}}]}
I0224 13:04:20.634307       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:20.634379       1 utils.go:199] ID: 16 GRPC request: {}
I0224 13:04:20.634403       1 utils.go:205] ID: 16 GRPC response: {}
I0224 13:04:20.639160       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 13:04:20.639256       1 utils.go:199] ID: 17 GRPC request: {}
I0224 13:04:20.639285       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0224 13:04:20.639347       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0224 13:04:20.641714       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0224 13:04:20.641816       1 utils.go:199] ID: 18 GRPC request: {}
I0224 13:04:20.641859       1 utils.go:205] ID: 18 GRPC response: {}
I0224 13:04:20.642328       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 13:04:20.642417       1 utils.go:199] ID: 19 GRPC request: {}
I0224 13:04:20.642591       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 13:04:20.643333       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 13:04:20.643410       1 utils.go:199] ID: 20 GRPC request: {}
I0224 13:04:20.643445       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0224 13:04:20.643557       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}}}]}
I0224 13:05:20.813332       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0224 13:05:20.813406       1 utils.go:199] ID: 21 GRPC request: {}
I0224 13:05:20.813425       1 utils.go:205] ID: 21 GRPC response: {}
I0224 13:06:20.816162       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0224 13:06:20.816255       1 utils.go:199] ID: 22 GRPC request: {}
I0224 13:06:20.816307       1 utils.go:205] ID: 22 GRPC response: {}
I0224 13:07:17.012536       1 utils.go:198] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 GRPC call: /csi.v1.Controller/CreateVolume
I0224 13:07:17.013016       1 utils.go:199] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70","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}}]}
I0224 13:07:17.013331       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0224 13:07:17.030936       1 omap.go:80] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0224 13:07:17.050494       1 omap.go:159] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70:8ba20603-be99-441d-bc2a-80fecd150ede])
I0224 13:07:17.056931       1 omap.go:159] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 set omap keys (pool="kube", namespace="", name="csi.volume.8ba20603-be99-441d-bc2a-80fecd150ede"): map[csi.imagename:csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede csi.volname:pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 csi.volume.owner:default])
I0224 13:07:17.057042       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ba20603-be99-441d-bc2a-80fecd150ede) and image name (csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede) for request name (pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70)
I0224 13:07:17.057137       1 rbd_util.go:423] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 rbd: create kube/csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede size 5120M (features: [layering]) using mon 199.19.213.159
I0224 13:07:17.057219       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 setting image options on kube/csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede
I0224 13:07:18.887024       1 controllerserver.go:763] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 created image kube/csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede backed for request name pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70
I0224 13:07:18.935598       1 omap.go:159] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 set omap keys (pool="kube", namespace="", name="csi.volume.8ba20603-be99-441d-bc2a-80fecd150ede"): map[csi.imageid:37d913bc5f9f])
I0224 13:07:19.061242       1 utils.go:205] ID: 23 Req-ID: pvc-25c2dae0-50c1-48cf-b896-95bf7ecd4c70 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8ba20603-be99-441d-bc2a-80fecd150ede","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ba20603-be99-441d-bc2a-80fecd150ede"}}
I0224 13:07:20.812443       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0224 13:07:20.812713       1 utils.go:199] ID: 24 GRPC request: {}
I0224 13:07:20.812868       1 utils.go:205] ID: 24 GRPC response: {}