I0225 06:11:27.499940       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0225 06:11:27.500042       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0225 06:11:27.500054       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0225 06:11:27.500061       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0225 06:11:27.500064       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0225 06:11:27.500067       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0225 06:11:27.500071       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0225 06:11:27.500074       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0225 06:11:27.500077       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0225 06:11:27.500081       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0225 06:11:27.500345       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0225 06:11:27.500410       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0225 06:11:36.412304       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:36.415602       1 utils.go:199] ID: 1 GRPC request: {}
I0225 06:11:36.415700       1 utils.go:205] ID: 1 GRPC response: {}
I0225 06:11:36.418879       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 06:11:36.419268       1 utils.go:199] ID: 2 GRPC request: {}
I0225 06:11:36.419306       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0225 06:11:36.419456       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 06:11:36.421186       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:36.421215       1 utils.go:199] ID: 3 GRPC request: {}
I0225 06:11:36.421226       1 utils.go:205] ID: 3 GRPC response: {}
I0225 06:11:36.421554       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 06:11:36.421704       1 utils.go:199] ID: 4 GRPC request: {}
I0225 06:11:36.421957       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 06:11:36.422839       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:36.422935       1 utils.go:199] ID: 5 GRPC request: {}
I0225 06:11:36.422954       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0225 06:11:36.423152       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}}}]}
I0225 06:11:38.907496       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:38.907546       1 utils.go:199] ID: 6 GRPC request: {}
I0225 06:11:38.907562       1 utils.go:205] ID: 6 GRPC response: {}
I0225 06:11:38.909819       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 06:11:38.909840       1 utils.go:199] ID: 7 GRPC request: {}
I0225 06:11:38.909848       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0225 06:11:38.909870       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 06:11:38.912978       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:38.913007       1 utils.go:199] ID: 8 GRPC request: {}
I0225 06:11:38.913018       1 utils.go:205] ID: 8 GRPC response: {}
I0225 06:11:38.913603       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 06:11:38.913619       1 utils.go:199] ID: 9 GRPC request: {}
I0225 06:11:38.913706       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 06:11:38.915025       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:38.915088       1 utils.go:199] ID: 10 GRPC request: {}
I0225 06:11:38.915116       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0225 06:11:38.915214       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}}}]}
I0225 06:11:38.917454       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:38.917491       1 utils.go:199] ID: 11 GRPC request: {}
I0225 06:11:38.917516       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0225 06:11:38.917731       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}}}]}
I0225 06:11:38.918443       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:38.918482       1 utils.go:199] ID: 12 GRPC request: {}
I0225 06:11:38.918497       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0225 06:11:38.918584       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}}}]}
I0225 06:11:40.934509       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 06:11:40.934589       1 utils.go:199] ID: 13 GRPC request: {}
I0225 06:11:40.934606       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0225 06:11:40.934733       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 06:11:40.937077       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:40.937109       1 utils.go:199] ID: 14 GRPC request: {}
I0225 06:11:40.937151       1 utils.go:205] ID: 14 GRPC response: {}
I0225 06:11:40.937484       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:40.937504       1 utils.go:199] ID: 15 GRPC request: {}
I0225 06:11:40.937512       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0225 06:11:40.937662       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}}}]}
I0225 06:11:46.420836       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:46.420875       1 utils.go:199] ID: 16 GRPC request: {}
I0225 06:11:46.420926       1 utils.go:205] ID: 16 GRPC response: {}
I0225 06:11:46.425328       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 06:11:46.425355       1 utils.go:199] ID: 17 GRPC request: {}
I0225 06:11:46.425362       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0225 06:11:46.425382       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 06:11:46.427888       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0225 06:11:46.427919       1 utils.go:199] ID: 18 GRPC request: {}
I0225 06:11:46.427930       1 utils.go:205] ID: 18 GRPC response: {}
I0225 06:11:46.428244       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 06:11:46.428265       1 utils.go:199] ID: 19 GRPC request: {}
I0225 06:11:46.428485       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 06:11:46.429395       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 06:11:46.429416       1 utils.go:199] ID: 20 GRPC request: {}
I0225 06:11:46.429432       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0225 06:11:46.429518       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}}}]}
I0225 06:12:46.882584       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0225 06:12:46.882714       1 utils.go:199] ID: 21 GRPC request: {}
I0225 06:12:46.882904       1 utils.go:205] ID: 21 GRPC response: {}
I0225 06:13:46.827923       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0225 06:13:46.828050       1 utils.go:199] ID: 22 GRPC request: {}
I0225 06:13:46.828128       1 utils.go:205] ID: 22 GRPC response: {}
I0225 06:14:22.356955       1 utils.go:198] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 GRPC call: /csi.v1.Controller/CreateVolume
I0225 06:14:22.357877       1 utils.go:199] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2","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}}]}
I0225 06:14:22.358230       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0225 06:14:22.377462       1 omap.go:80] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0225 06:14:22.434607       1 omap.go:159] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2:689bfe97-7a48-4cea-b123-baaa940c2a5f])
I0225 06:14:22.451884       1 omap.go:159] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 set omap keys (pool="kube", namespace="", name="csi.volume.689bfe97-7a48-4cea-b123-baaa940c2a5f"): map[csi.imagename:csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f csi.volname:pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 csi.volume.owner:default])
I0225 06:14:22.451919       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-689bfe97-7a48-4cea-b123-baaa940c2a5f) and image name (csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f) for request name (pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2)
I0225 06:14:22.452064       1 rbd_util.go:423] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 rbd: create kube/csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f size 5120M (features: [layering]) using mon 199.204.45.74
I0225 06:14:22.452156       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 setting image options on kube/csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f
I0225 06:14:24.420585       1 controllerserver.go:763] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 created image kube/csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f backed for request name pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2
I0225 06:14:24.463592       1 omap.go:159] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 set omap keys (pool="kube", namespace="", name="csi.volume.689bfe97-7a48-4cea-b123-baaa940c2a5f"): map[csi.imageid:37d92a3cb790])
I0225 06:14:24.549381       1 utils.go:205] ID: 23 Req-ID: pvc-d04c074e-bf5e-4aa8-b93e-10741a5600d2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-689bfe97-7a48-4cea-b123-baaa940c2a5f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-689bfe97-7a48-4cea-b123-baaa940c2a5f"}}
I0225 06:14:46.825465       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0225 06:14:46.825516       1 utils.go:199] ID: 24 GRPC request: {}
I0225 06:14:46.825539       1 utils.go:205] ID: 24 GRPC response: {}