I0205 05:28:39.847462       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0205 05:28:39.847788       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0205 05:28:39.847855       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0205 05:28:39.847902       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0205 05:28:39.847943       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0205 05:28:39.847987       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0205 05:28:39.848024       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0205 05:28:39.848067       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0205 05:28:39.848104       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0205 05:28:39.848145       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0205 05:28:39.848446       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0205 05:28:39.848527       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0205 05:28:42.532905       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:42.533831       1 utils.go:199] ID: 1 GRPC request: {}
I0205 05:28:42.533874       1 utils.go:205] ID: 1 GRPC response: {}
I0205 05:28:42.535968       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 05:28:42.536009       1 utils.go:199] ID: 2 GRPC request: {}
I0205 05:28:42.536025       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0205 05:28:42.536064       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 05:28:42.537831       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:42.537910       1 utils.go:199] ID: 3 GRPC request: {}
I0205 05:28:42.537963       1 utils.go:205] ID: 3 GRPC response: {}
I0205 05:28:42.539286       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 05:28:42.539359       1 utils.go:199] ID: 4 GRPC request: {}
I0205 05:28:42.539467       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 05:28:42.539922       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:42.539952       1 utils.go:199] ID: 5 GRPC request: {}
I0205 05:28:42.539958       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0205 05:28:42.540032       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}}}]}
I0205 05:28:44.275465       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:44.275559       1 utils.go:199] ID: 6 GRPC request: {}
I0205 05:28:44.275690       1 utils.go:205] ID: 6 GRPC response: {}
I0205 05:28:44.277025       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 05:28:44.277097       1 utils.go:199] ID: 7 GRPC request: {}
I0205 05:28:44.277165       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0205 05:28:44.277219       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 05:28:44.278366       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:44.278448       1 utils.go:199] ID: 8 GRPC request: {}
I0205 05:28:44.278489       1 utils.go:205] ID: 8 GRPC response: {}
I0205 05:28:44.278834       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 05:28:44.278912       1 utils.go:199] ID: 9 GRPC request: {}
I0205 05:28:44.279092       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 05:28:44.279492       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:44.279570       1 utils.go:199] ID: 10 GRPC request: {}
I0205 05:28:44.279625       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0205 05:28:44.279730       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}}}]}
I0205 05:28:44.280070       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:44.280150       1 utils.go:199] ID: 11 GRPC request: {}
I0205 05:28:44.280206       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0205 05:28:44.280299       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}}}]}
I0205 05:28:44.280550       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:44.280594       1 utils.go:199] ID: 12 GRPC request: {}
I0205 05:28:44.280622       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0205 05:28:44.280730       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}}}]}
I0205 05:28:45.905659       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 05:28:45.905753       1 utils.go:199] ID: 13 GRPC request: {}
I0205 05:28:45.905824       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0205 05:28:45.905883       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 05:28:45.907938       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:45.907977       1 utils.go:199] ID: 14 GRPC request: {}
I0205 05:28:45.908006       1 utils.go:205] ID: 14 GRPC response: {}
I0205 05:28:45.908411       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:45.908426       1 utils.go:199] ID: 15 GRPC request: {}
I0205 05:28:45.908509       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0205 05:28:45.908658       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}}}]}
I0205 05:28:47.517769       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:47.517828       1 utils.go:199] ID: 16 GRPC request: {}
I0205 05:28:47.517846       1 utils.go:205] ID: 16 GRPC response: {}
I0205 05:28:47.527310       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 05:28:47.527344       1 utils.go:199] ID: 17 GRPC request: {}
I0205 05:28:47.527351       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0205 05:28:47.527371       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 05:28:47.528886       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0205 05:28:47.528899       1 utils.go:199] ID: 18 GRPC request: {}
I0205 05:28:47.528909       1 utils.go:205] ID: 18 GRPC response: {}
I0205 05:28:47.529169       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 05:28:47.529244       1 utils.go:199] ID: 19 GRPC request: {}
I0205 05:28:47.529333       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 05:28:47.531096       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 05:28:47.531175       1 utils.go:199] ID: 20 GRPC request: {}
I0205 05:28:47.531187       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0205 05:28:47.531281       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}}}]}
I0205 05:29:47.750769       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0205 05:29:47.751105       1 utils.go:199] ID: 21 GRPC request: {}
I0205 05:29:47.751262       1 utils.go:205] ID: 21 GRPC response: {}
I0205 05:30:47.769181       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0205 05:30:47.769212       1 utils.go:199] ID: 22 GRPC request: {}
I0205 05:30:47.769226       1 utils.go:205] ID: 22 GRPC response: {}
I0205 05:31:45.067985       1 utils.go:198] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 GRPC call: /csi.v1.Controller/CreateVolume
I0205 05:31:45.068793       1 utils.go:199] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-61d88677-19d2-4059-8516-160fc7af73a6","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-61d88677-19d2-4059-8516-160fc7af73a6","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}}]}
I0205 05:31:45.069254       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0205 05:31:45.104027       1 omap.go:80] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0205 05:31:45.120710       1 omap.go:159] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-61d88677-19d2-4059-8516-160fc7af73a6:1d034665-67d5-47b3-b002-61a21ef37756])
I0205 05:31:45.131176       1 omap.go:159] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 set omap keys (pool="kube", namespace="", name="csi.volume.1d034665-67d5-47b3-b002-61a21ef37756"): map[csi.imagename:csi-vol-1d034665-67d5-47b3-b002-61a21ef37756 csi.volname:pvc-61d88677-19d2-4059-8516-160fc7af73a6 csi.volume.owner:default])
I0205 05:31:45.131212       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1d034665-67d5-47b3-b002-61a21ef37756) and image name (csi-vol-1d034665-67d5-47b3-b002-61a21ef37756) for request name (pvc-61d88677-19d2-4059-8516-160fc7af73a6)
I0205 05:31:45.131279       1 rbd_util.go:423] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 rbd: create kube/csi-vol-1d034665-67d5-47b3-b002-61a21ef37756 size 5120M (features: [layering]) using mon 199.204.45.72
I0205 05:31:45.131311       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 setting image options on kube/csi-vol-1d034665-67d5-47b3-b002-61a21ef37756
I0205 05:31:46.911950       1 controllerserver.go:763] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 created image kube/csi-vol-1d034665-67d5-47b3-b002-61a21ef37756 backed for request name pvc-61d88677-19d2-4059-8516-160fc7af73a6
I0205 05:31:46.943766       1 omap.go:159] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 set omap keys (pool="kube", namespace="", name="csi.volume.1d034665-67d5-47b3-b002-61a21ef37756"): map[csi.imageid:37d9efa129b9])
I0205 05:31:47.028149       1 utils.go:205] ID: 23 Req-ID: pvc-61d88677-19d2-4059-8516-160fc7af73a6 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1d034665-67d5-47b3-b002-61a21ef37756","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1d034665-67d5-47b3-b002-61a21ef37756"}}
I0205 05:31:47.809002       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0205 05:31:47.809051       1 utils.go:199] ID: 24 GRPC request: {}
I0205 05:31:47.809077       1 utils.go:205] ID: 24 GRPC response: {}