I0219 13:23:10.221074       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0219 13:23:10.221219       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0219 13:23:10.221235       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0219 13:23:10.221239       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0219 13:23:10.221243       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0219 13:23:10.221247       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0219 13:23:10.221252       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0219 13:23:10.221256       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0219 13:23:10.221262       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0219 13:23:10.221266       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0219 13:23:10.221563       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0219 13:23:10.221571       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0219 13:23:15.518651       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:15.520760       1 utils.go:199] ID: 1 GRPC request: {}
I0219 13:23:15.520967       1 utils.go:205] ID: 1 GRPC response: {}
I0219 13:23:15.525524       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 13:23:15.525695       1 utils.go:199] ID: 2 GRPC request: {}
I0219 13:23:15.525756       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0219 13:23:15.525847       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 13:23:15.527691       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:15.527755       1 utils.go:199] ID: 3 GRPC request: {}
I0219 13:23:15.527791       1 utils.go:205] ID: 3 GRPC response: {}
I0219 13:23:15.528215       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 13:23:15.528280       1 utils.go:199] ID: 4 GRPC request: {}
I0219 13:23:15.528416       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 13:23:15.529317       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:15.529506       1 utils.go:199] ID: 5 GRPC request: {}
I0219 13:23:15.529524       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0219 13:23:15.529771       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}}}]}
I0219 13:23:20.115410       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:20.115456       1 utils.go:199] ID: 6 GRPC request: {}
I0219 13:23:20.115475       1 utils.go:205] ID: 6 GRPC response: {}
I0219 13:23:20.120526       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 13:23:20.120605       1 utils.go:199] ID: 7 GRPC request: {}
I0219 13:23:20.120699       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0219 13:23:20.120791       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 13:23:20.123715       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:20.123740       1 utils.go:199] ID: 8 GRPC request: {}
I0219 13:23:20.123752       1 utils.go:205] ID: 8 GRPC response: {}
I0219 13:23:20.124239       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 13:23:20.124272       1 utils.go:199] ID: 9 GRPC request: {}
I0219 13:23:20.124414       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 13:23:20.125527       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:20.125561       1 utils.go:199] ID: 10 GRPC request: {}
I0219 13:23:20.125574       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0219 13:23:20.125696       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}}}]}
I0219 13:23:20.126357       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:20.126382       1 utils.go:199] ID: 11 GRPC request: {}
I0219 13:23:20.126390       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0219 13:23:20.126462       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}}}]}
I0219 13:23:20.126850       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:20.126868       1 utils.go:199] ID: 12 GRPC request: {}
I0219 13:23:20.126873       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0219 13:23:20.126927       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}}}]}
I0219 13:23:22.754215       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 13:23:22.754273       1 utils.go:199] ID: 13 GRPC request: {}
I0219 13:23:22.754286       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0219 13:23:22.754325       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 13:23:22.758459       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:22.758552       1 utils.go:199] ID: 14 GRPC request: {}
I0219 13:23:22.758622       1 utils.go:205] ID: 14 GRPC response: {}
I0219 13:23:22.759460       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:22.759551       1 utils.go:199] ID: 15 GRPC request: {}
I0219 13:23:22.759577       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0219 13:23:22.759816       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}}}]}
I0219 13:23:25.347744       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:25.347785       1 utils.go:199] ID: 16 GRPC request: {}
I0219 13:23:25.347823       1 utils.go:205] ID: 16 GRPC response: {}
I0219 13:23:25.352291       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 13:23:25.352326       1 utils.go:199] ID: 17 GRPC request: {}
I0219 13:23:25.352335       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0219 13:23:25.352369       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 13:23:25.354835       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0219 13:23:25.354877       1 utils.go:199] ID: 18 GRPC request: {}
I0219 13:23:25.354902       1 utils.go:205] ID: 18 GRPC response: {}
I0219 13:23:25.355331       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 13:23:25.355373       1 utils.go:199] ID: 19 GRPC request: {}
I0219 13:23:25.355456       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 13:23:25.356579       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 13:23:25.356611       1 utils.go:199] ID: 20 GRPC request: {}
I0219 13:23:25.356623       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0219 13:23:25.356867       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}}}]}
I0219 13:24:25.592897       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0219 13:24:25.592997       1 utils.go:199] ID: 21 GRPC request: {}
I0219 13:24:25.593278       1 utils.go:205] ID: 21 GRPC response: {}
I0219 13:25:25.564788       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0219 13:25:25.564868       1 utils.go:199] ID: 22 GRPC request: {}
I0219 13:25:25.564897       1 utils.go:205] ID: 22 GRPC response: {}
I0219 13:26:21.900676       1 utils.go:198] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 GRPC call: /csi.v1.Controller/CreateVolume
I0219 13:26:21.901008       1 utils.go:199] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42","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}}]}
I0219 13:26:21.901253       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0219 13:26:21.918995       1 omap.go:80] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0219 13:26:21.934577       1 omap.go:159] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42:314fb68c-7c63-4645-a546-28d081553e42])
I0219 13:26:21.942934       1 omap.go:159] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 set omap keys (pool="kube", namespace="", name="csi.volume.314fb68c-7c63-4645-a546-28d081553e42"): map[csi.imagename:csi-vol-314fb68c-7c63-4645-a546-28d081553e42 csi.volname:pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 csi.volume.owner:default])
I0219 13:26:21.942956       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-314fb68c-7c63-4645-a546-28d081553e42) and image name (csi-vol-314fb68c-7c63-4645-a546-28d081553e42) for request name (pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42)
I0219 13:26:21.943004       1 rbd_util.go:423] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 rbd: create kube/csi-vol-314fb68c-7c63-4645-a546-28d081553e42 size 5120M (features: [layering]) using mon 162.253.55.62
I0219 13:26:21.943025       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 setting image options on kube/csi-vol-314fb68c-7c63-4645-a546-28d081553e42
I0219 13:26:23.241963       1 controllerserver.go:763] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 created image kube/csi-vol-314fb68c-7c63-4645-a546-28d081553e42 backed for request name pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42
I0219 13:26:23.278533       1 omap.go:159] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 set omap keys (pool="kube", namespace="", name="csi.volume.314fb68c-7c63-4645-a546-28d081553e42"): map[csi.imageid:37d85c1f57e1])
I0219 13:26:23.381733       1 utils.go:205] ID: 23 Req-ID: pvc-f43dd008-488a-45bf-88ac-23bfe65d1f42 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-314fb68c-7c63-4645-a546-28d081553e42","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-314fb68c-7c63-4645-a546-28d081553e42"}}
I0219 13:26:25.563727       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0219 13:26:25.563780       1 utils.go:199] ID: 24 GRPC request: {}
I0219 13:26:25.563798       1 utils.go:205] ID: 24 GRPC response: {}