I0626 03:36:52.007218       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0626 03:36:52.007466       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0626 03:36:52.007487       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0626 03:36:52.007494       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0626 03:36:52.007497       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0626 03:36:52.007502       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0626 03:36:52.007506       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0626 03:36:52.007531       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0626 03:36:52.007541       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0626 03:36:52.007544       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0626 03:36:52.007928       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0626 03:36:52.007958       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0626 03:36:58.580888       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0626 03:36:58.583083       1 utils.go:199] ID: 1 GRPC request: {}
I0626 03:36:58.583157       1 utils.go:205] ID: 1 GRPC response: {}
I0626 03:36:58.588449       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0626 03:36:58.588573       1 utils.go:199] ID: 2 GRPC request: {}
I0626 03:36:58.588597       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0626 03:36:58.588713       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0626 03:36:58.592932       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0626 03:36:58.592986       1 utils.go:199] ID: 3 GRPC request: {}
I0626 03:36:58.593109       1 utils.go:205] ID: 3 GRPC response: {}
I0626 03:36:58.593645       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0626 03:36:58.593780       1 utils.go:199] ID: 4 GRPC request: {}
I0626 03:36:58.594086       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0626 03:36:58.594894       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:36:58.595057       1 utils.go:199] ID: 5 GRPC request: {}
I0626 03:36:58.595075       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0626 03:36:58.595259       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}}}]}
I0626 03:37:02.040687       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0626 03:37:02.040725       1 utils.go:199] ID: 6 GRPC request: {}
I0626 03:37:02.040741       1 utils.go:205] ID: 6 GRPC response: {}
I0626 03:37:02.044504       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0626 03:37:02.044530       1 utils.go:199] ID: 7 GRPC request: {}
I0626 03:37:02.044537       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0626 03:37:02.044560       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0626 03:37:02.047425       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0626 03:37:02.047594       1 utils.go:199] ID: 8 GRPC request: {}
I0626 03:37:02.047733       1 utils.go:205] ID: 8 GRPC response: {}
I0626 03:37:02.048628       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0626 03:37:02.048653       1 utils.go:199] ID: 9 GRPC request: {}
I0626 03:37:02.048770       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0626 03:37:02.049528       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:37:02.049674       1 utils.go:199] ID: 10 GRPC request: {}
I0626 03:37:02.049804       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0626 03:37:02.050055       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}}}]}
I0626 03:37:02.050657       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:37:02.050678       1 utils.go:199] ID: 11 GRPC request: {}
I0626 03:37:02.050685       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0626 03:37:02.050768       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}}}]}
I0626 03:37:02.051148       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:37:02.051178       1 utils.go:199] ID: 12 GRPC request: {}
I0626 03:37:02.051217       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0626 03:37:02.051320       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}}}]}
I0626 03:37:03.790685       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0626 03:37:03.790740       1 utils.go:199] ID: 13 GRPC request: {}
I0626 03:37:03.790752       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0626 03:37:03.790805       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0626 03:37:03.792896       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0626 03:37:03.792915       1 utils.go:199] ID: 14 GRPC request: {}
I0626 03:37:03.792944       1 utils.go:205] ID: 14 GRPC response: {}
I0626 03:37:03.793393       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:37:03.793443       1 utils.go:199] ID: 15 GRPC request: {}
I0626 03:37:03.793461       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0626 03:37:03.793702       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}}}]}
I0626 03:37:05.694425       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0626 03:37:05.694509       1 utils.go:199] ID: 16 GRPC request: {}
I0626 03:37:05.694554       1 utils.go:205] ID: 16 GRPC response: {}
I0626 03:37:05.698512       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0626 03:37:05.698878       1 utils.go:199] ID: 17 GRPC request: {}
I0626 03:37:05.698902       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0626 03:37:05.698942       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0626 03:37:05.701337       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0626 03:37:05.701371       1 utils.go:199] ID: 18 GRPC request: {}
I0626 03:37:05.701450       1 utils.go:205] ID: 18 GRPC response: {}
I0626 03:37:05.702171       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0626 03:37:05.702286       1 utils.go:199] ID: 19 GRPC request: {}
I0626 03:37:05.702537       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0626 03:37:05.703379       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0626 03:37:05.703443       1 utils.go:199] ID: 20 GRPC request: {}
I0626 03:37:05.703557       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0626 03:37:05.703786       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}}}]}
I0626 03:38:05.890182       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0626 03:38:05.890237       1 utils.go:199] ID: 21 GRPC request: {}
I0626 03:38:05.890262       1 utils.go:205] ID: 21 GRPC response: {}
I0626 03:39:05.891775       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0626 03:39:05.891955       1 utils.go:199] ID: 22 GRPC request: {}
I0626 03:39:05.892006       1 utils.go:205] ID: 22 GRPC response: {}
I0626 03:40:05.888467       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0626 03:40:05.888526       1 utils.go:199] ID: 23 GRPC request: {}
I0626 03:40:05.888546       1 utils.go:205] ID: 23 GRPC response: {}
I0626 03:40:46.817365       1 utils.go:198] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 GRPC call: /csi.v1.Controller/CreateVolume
I0626 03:40:46.817887       1 utils.go:199] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453","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}}]}
I0626 03:40:46.818251       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0626 03:40:46.836525       1 omap.go:80] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0626 03:40:46.852357       1 omap.go:159] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453:1ee25ad2-0a4f-4d5a-ae93-fd767356eacf])
I0626 03:40:46.858230       1 omap.go:159] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 set omap keys (pool="kube", namespace="", name="csi.volume.1ee25ad2-0a4f-4d5a-ae93-fd767356eacf"): map[csi.imagename:csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf csi.volname:pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 csi.volume.owner:default])
I0626 03:40:46.858261       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf) and image name (csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf) for request name (pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453)
I0626 03:40:46.858347       1 rbd_util.go:423] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 rbd: create kube/csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf size 5120M (features: [layering]) using mon 199.204.45.78
I0626 03:40:46.858559       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 setting image options on kube/csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf
I0626 03:40:46.889940       1 controllerserver.go:763] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 created image kube/csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf backed for request name pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453
I0626 03:40:46.920506       1 omap.go:159] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 set omap keys (pool="kube", namespace="", name="csi.volume.1ee25ad2-0a4f-4d5a-ae93-fd767356eacf"): map[csi.imageid:37ecca50fa1a])
I0626 03:40:47.010226       1 utils.go:205] ID: 24 Req-ID: pvc-ed4378b7-8ad7-4a8f-81a6-881ae6c2f453 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1ee25ad2-0a4f-4d5a-ae93-fd767356eacf"}}
I0626 03:41:05.902117       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0626 03:41:05.902211       1 utils.go:199] ID: 25 GRPC request: {}
I0626 03:41:05.902267       1 utils.go:205] ID: 25 GRPC response: {}