I0605 15:58:17.966357       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0605 15:58:17.966513       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0605 15:58:17.966534       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0605 15:58:17.966541       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0605 15:58:17.966547       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0605 15:58:17.966552       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0605 15:58:17.966559       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0605 15:58:17.966565       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0605 15:58:17.966571       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0605 15:58:17.966576       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0605 15:58:17.966996       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0605 15:58:17.967005       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0605 15:58:23.781595       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:23.783465       1 utils.go:199] ID: 1 GRPC request: {}
I0605 15:58:23.783550       1 utils.go:205] ID: 1 GRPC response: {}
I0605 15:58:23.787161       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0605 15:58:23.787278       1 utils.go:199] ID: 2 GRPC request: {}
I0605 15:58:23.787317       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0605 15:58:23.787381       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0605 15:58:23.788919       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:23.788968       1 utils.go:199] ID: 3 GRPC request: {}
I0605 15:58:23.789010       1 utils.go:205] ID: 3 GRPC response: {}
I0605 15:58:23.789616       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0605 15:58:23.789761       1 utils.go:199] ID: 4 GRPC request: {}
I0605 15:58:23.789953       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0605 15:58:23.790973       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:23.791123       1 utils.go:199] ID: 5 GRPC request: {}
I0605 15:58:23.791158       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0605 15:58:23.791310       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}}}]}
I0605 15:58:25.976536       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:25.976588       1 utils.go:199] ID: 6 GRPC request: {}
I0605 15:58:25.976616       1 utils.go:205] ID: 6 GRPC response: {}
I0605 15:58:25.980549       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0605 15:58:25.980583       1 utils.go:199] ID: 7 GRPC request: {}
I0605 15:58:25.980595       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0605 15:58:25.980628       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0605 15:58:25.982534       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:25.982601       1 utils.go:199] ID: 8 GRPC request: {}
I0605 15:58:25.982626       1 utils.go:205] ID: 8 GRPC response: {}
I0605 15:58:25.983925       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0605 15:58:25.983969       1 utils.go:199] ID: 9 GRPC request: {}
I0605 15:58:25.984140       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0605 15:58:25.984784       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:25.984805       1 utils.go:199] ID: 10 GRPC request: {}
I0605 15:58:25.984813       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0605 15:58:25.984881       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}}}]}
I0605 15:58:25.985520       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:25.985556       1 utils.go:199] ID: 11 GRPC request: {}
I0605 15:58:25.985569       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0605 15:58:25.985665       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}}}]}
I0605 15:58:25.985938       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:25.985954       1 utils.go:199] ID: 12 GRPC request: {}
I0605 15:58:25.985959       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0605 15:58:25.986032       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}}}]}
I0605 15:58:27.654021       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0605 15:58:27.654094       1 utils.go:199] ID: 13 GRPC request: {}
I0605 15:58:27.654110       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0605 15:58:27.654173       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0605 15:58:27.657378       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:27.657403       1 utils.go:199] ID: 14 GRPC request: {}
I0605 15:58:27.657443       1 utils.go:205] ID: 14 GRPC response: {}
I0605 15:58:27.657824       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:27.657861       1 utils.go:199] ID: 15 GRPC request: {}
I0605 15:58:27.657897       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0605 15:58:27.658015       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}}}]}
I0605 15:58:29.225141       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:29.225177       1 utils.go:199] ID: 16 GRPC request: {}
I0605 15:58:29.225193       1 utils.go:205] ID: 16 GRPC response: {}
I0605 15:58:29.227356       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0605 15:58:29.227385       1 utils.go:199] ID: 17 GRPC request: {}
I0605 15:58:29.227395       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0605 15:58:29.227432       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0605 15:58:29.229077       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0605 15:58:29.229094       1 utils.go:199] ID: 18 GRPC request: {}
I0605 15:58:29.229104       1 utils.go:205] ID: 18 GRPC response: {}
I0605 15:58:29.229931       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0605 15:58:29.229960       1 utils.go:199] ID: 19 GRPC request: {}
I0605 15:58:29.230151       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0605 15:58:29.230813       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0605 15:58:29.230840       1 utils.go:199] ID: 20 GRPC request: {}
I0605 15:58:29.230851       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0605 15:58:29.230998       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}}}]}
I0605 15:59:29.433449       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0605 15:59:29.433521       1 utils.go:199] ID: 21 GRPC request: {}
I0605 15:59:29.433552       1 utils.go:205] ID: 21 GRPC response: {}
I0605 16:00:29.459517       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0605 16:00:29.459764       1 utils.go:199] ID: 22 GRPC request: {}
I0605 16:00:29.459913       1 utils.go:205] ID: 22 GRPC response: {}
I0605 16:01:29.445647       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0605 16:01:29.445731       1 utils.go:199] ID: 23 GRPC request: {}
I0605 16:01:29.445777       1 utils.go:205] ID: 23 GRPC response: {}
I0605 16:02:04.037665       1 utils.go:198] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 GRPC call: /csi.v1.Controller/CreateVolume
I0605 16:02:04.038313       1 utils.go:199] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7","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}}]}
I0605 16:02:04.039022       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0605 16:02:04.057153       1 omap.go:80] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0605 16:02:04.075911       1 omap.go:159] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7:c5dd9825-33c8-4225-b4ce-0ee02aa31e5f])
I0605 16:02:04.084646       1 omap.go:159] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 set omap keys (pool="kube", namespace="", name="csi.volume.c5dd9825-33c8-4225-b4ce-0ee02aa31e5f"): map[csi.imagename:csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f csi.volname:pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 csi.volume.owner:default])
I0605 16:02:04.084736       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f) and image name (csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f) for request name (pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7)
I0605 16:02:04.084853       1 rbd_util.go:423] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 rbd: create kube/csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f size 5120M (features: [layering]) using mon 199.19.213.67
I0605 16:02:04.084960       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 setting image options on kube/csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f
I0605 16:02:04.114636       1 controllerserver.go:763] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 created image kube/csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f backed for request name pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7
I0605 16:02:04.148720       1 omap.go:159] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 set omap keys (pool="kube", namespace="", name="csi.volume.c5dd9825-33c8-4225-b4ce-0ee02aa31e5f"): map[csi.imageid:37ed7f0e9365])
I0605 16:02:04.242012       1 utils.go:205] ID: 24 Req-ID: pvc-6fc82d9a-44cc-4ade-8340-1efccd6d43d7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c5dd9825-33c8-4225-b4ce-0ee02aa31e5f"}}
I0605 16:02:29.404732       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0605 16:02:29.404793       1 utils.go:199] ID: 25 GRPC request: {}
I0605 16:02:29.404817       1 utils.go:205] ID: 25 GRPC response: {}