I0512 16:34:48.810279       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0512 16:34:48.810415       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0512 16:34:48.810429       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0512 16:34:48.810432       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0512 16:34:48.810435       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0512 16:34:48.810438       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0512 16:34:48.810442       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0512 16:34:48.810444       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0512 16:34:48.810447       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0512 16:34:48.810450       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0512 16:34:48.811026       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0512 16:34:48.811161       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0512 16:34:50.927744       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:50.928903       1 utils.go:199] ID: 1 GRPC request: {}
I0512 16:34:50.928950       1 utils.go:205] ID: 1 GRPC response: {}
I0512 16:34:50.931859       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 16:34:50.931933       1 utils.go:199] ID: 2 GRPC request: {}
I0512 16:34:50.931949       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0512 16:34:50.931994       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 16:34:50.933451       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:50.933487       1 utils.go:199] ID: 3 GRPC request: {}
I0512 16:34:50.933497       1 utils.go:205] ID: 3 GRPC response: {}
I0512 16:34:50.933897       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 16:34:50.933934       1 utils.go:199] ID: 4 GRPC request: {}
I0512 16:34:50.934032       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 16:34:50.934921       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:50.934957       1 utils.go:199] ID: 5 GRPC request: {}
I0512 16:34:50.934966       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0512 16:34:50.935062       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}}}]}
I0512 16:34:52.086153       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:52.086182       1 utils.go:199] ID: 6 GRPC request: {}
I0512 16:34:52.086197       1 utils.go:205] ID: 6 GRPC response: {}
I0512 16:34:52.089122       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 16:34:52.089138       1 utils.go:199] ID: 7 GRPC request: {}
I0512 16:34:52.089144       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0512 16:34:52.089243       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 16:34:52.090484       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:52.090628       1 utils.go:199] ID: 8 GRPC request: {}
I0512 16:34:52.090688       1 utils.go:205] ID: 8 GRPC response: {}
I0512 16:34:52.091193       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 16:34:52.091214       1 utils.go:199] ID: 9 GRPC request: {}
I0512 16:34:52.091332       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 16:34:52.091879       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:52.091896       1 utils.go:199] ID: 10 GRPC request: {}
I0512 16:34:52.091903       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0512 16:34:52.092042       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}}}]}
I0512 16:34:52.092761       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:52.092819       1 utils.go:199] ID: 11 GRPC request: {}
I0512 16:34:52.092837       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0512 16:34:52.093039       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}}}]}
I0512 16:34:52.093425       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:52.093445       1 utils.go:199] ID: 12 GRPC request: {}
I0512 16:34:52.093451       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0512 16:34:52.093584       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}}}]}
I0512 16:34:53.636255       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 16:34:53.636315       1 utils.go:199] ID: 13 GRPC request: {}
I0512 16:34:53.636333       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0512 16:34:53.636367       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 16:34:53.640251       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:53.640283       1 utils.go:199] ID: 14 GRPC request: {}
I0512 16:34:53.640305       1 utils.go:205] ID: 14 GRPC response: {}
I0512 16:34:53.640785       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:53.640841       1 utils.go:199] ID: 15 GRPC request: {}
I0512 16:34:53.640854       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0512 16:34:53.641085       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}}}]}
I0512 16:34:55.378153       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:55.378190       1 utils.go:199] ID: 16 GRPC request: {}
I0512 16:34:55.378206       1 utils.go:205] ID: 16 GRPC response: {}
I0512 16:34:55.380725       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 16:34:55.380773       1 utils.go:199] ID: 17 GRPC request: {}
I0512 16:34:55.380788       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0512 16:34:55.380824       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 16:34:55.384895       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0512 16:34:55.384918       1 utils.go:199] ID: 18 GRPC request: {}
I0512 16:34:55.384934       1 utils.go:205] ID: 18 GRPC response: {}
I0512 16:34:55.385814       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 16:34:55.385845       1 utils.go:199] ID: 19 GRPC request: {}
I0512 16:34:55.385949       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 16:34:55.386526       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 16:34:55.386551       1 utils.go:199] ID: 20 GRPC request: {}
I0512 16:34:55.386563       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0512 16:34:55.386677       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}}}]}
I0512 16:35:55.581880       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0512 16:35:55.582035       1 utils.go:199] ID: 21 GRPC request: {}
I0512 16:35:55.582107       1 utils.go:205] ID: 21 GRPC response: {}
I0512 16:36:55.543162       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0512 16:36:55.543271       1 utils.go:199] ID: 22 GRPC request: {}
I0512 16:36:55.543315       1 utils.go:205] ID: 22 GRPC response: {}
I0512 16:37:55.538286       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0512 16:37:55.538443       1 utils.go:199] ID: 23 GRPC request: {}
I0512 16:37:55.538534       1 utils.go:205] ID: 23 GRPC response: {}
I0512 16:37:55.618596       1 utils.go:198] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 GRPC call: /csi.v1.Controller/CreateVolume
I0512 16:37:55.619861       1 utils.go:199] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3","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}}]}
I0512 16:37:55.620586       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0512 16:37:55.641411       1 omap.go:80] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0512 16:37:55.655885       1 omap.go:159] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3:87615145-7f76-4f98-b9f3-a55ad8ce3cec])
I0512 16:37:55.661918       1 omap.go:159] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 set omap keys (pool="kube", namespace="", name="csi.volume.87615145-7f76-4f98-b9f3-a55ad8ce3cec"): map[csi.imagename:csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec csi.volname:pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 csi.volume.owner:default])
I0512 16:37:55.661951       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-87615145-7f76-4f98-b9f3-a55ad8ce3cec) and image name (csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec) for request name (pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3)
I0512 16:37:55.662015       1 rbd_util.go:423] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 rbd: create kube/csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec size 5120M (features: [layering]) using mon 199.19.213.163
I0512 16:37:55.662175       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 setting image options on kube/csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec
I0512 16:37:57.352043       1 controllerserver.go:763] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 created image kube/csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec backed for request name pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3
I0512 16:37:57.390048       1 omap.go:159] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 set omap keys (pool="kube", namespace="", name="csi.volume.87615145-7f76-4f98-b9f3-a55ad8ce3cec"): map[csi.imageid:37d96743acf9])
I0512 16:37:57.492049       1 utils.go:205] ID: 24 Req-ID: pvc-059839f4-5c8a-4a14-9bab-42ab4eb9a0d3 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-87615145-7f76-4f98-b9f3-a55ad8ce3cec","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-87615145-7f76-4f98-b9f3-a55ad8ce3cec"}}