I0811 15:03:15.224849       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0811 15:03:15.225035       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0811 15:03:15.225049       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0811 15:03:15.225062       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0811 15:03:15.225065       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0811 15:03:15.225068       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0811 15:03:15.225072       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0811 15:03:15.225075       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0811 15:03:15.225077       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0811 15:03:15.225080       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0811 15:03:15.225355       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0811 15:03:15.225496       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0811 15:03:19.338074       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:19.339936       1 utils.go:199] ID: 1 GRPC request: {}
I0811 15:03:19.339996       1 utils.go:205] ID: 1 GRPC response: {}
I0811 15:03:19.342745       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 15:03:19.342975       1 utils.go:199] ID: 2 GRPC request: {}
I0811 15:03:19.343004       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0811 15:03:19.343145       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 15:03:19.344951       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:19.345007       1 utils.go:199] ID: 3 GRPC request: {}
I0811 15:03:19.345021       1 utils.go:205] ID: 3 GRPC response: {}
I0811 15:03:19.345405       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 15:03:19.345470       1 utils.go:199] ID: 4 GRPC request: {}
I0811 15:03:19.345676       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 15:03:19.346634       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:19.346691       1 utils.go:199] ID: 5 GRPC request: {}
I0811 15:03:19.346703       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0811 15:03:19.346858       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}}}]}
I0811 15:03:23.218974       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:23.219048       1 utils.go:199] ID: 6 GRPC request: {}
I0811 15:03:23.219077       1 utils.go:205] ID: 6 GRPC response: {}
I0811 15:03:23.221610       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 15:03:23.221658       1 utils.go:199] ID: 7 GRPC request: {}
I0811 15:03:23.221685       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0811 15:03:23.221726       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 15:03:23.223748       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:23.223791       1 utils.go:199] ID: 8 GRPC request: {}
I0811 15:03:23.223809       1 utils.go:205] ID: 8 GRPC response: {}
I0811 15:03:23.224442       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 15:03:23.224459       1 utils.go:199] ID: 9 GRPC request: {}
I0811 15:03:23.224554       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 15:03:23.228694       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:23.228722       1 utils.go:199] ID: 10 GRPC request: {}
I0811 15:03:23.228734       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0811 15:03:23.228842       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}}}]}
I0811 15:03:23.230133       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:23.230161       1 utils.go:199] ID: 11 GRPC request: {}
I0811 15:03:23.230169       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0811 15:03:23.230256       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}}}]}
I0811 15:03:23.230998       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:23.231048       1 utils.go:199] ID: 12 GRPC request: {}
I0811 15:03:23.231060       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0811 15:03:23.231200       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}}}]}
I0811 15:03:24.598083       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 15:03:24.598134       1 utils.go:199] ID: 13 GRPC request: {}
I0811 15:03:24.598142       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0811 15:03:24.598170       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 15:03:24.600330       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:24.600352       1 utils.go:199] ID: 14 GRPC request: {}
I0811 15:03:24.600366       1 utils.go:205] ID: 14 GRPC response: {}
I0811 15:03:24.601102       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:24.601201       1 utils.go:199] ID: 15 GRPC request: {}
I0811 15:03:24.601218       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0811 15:03:24.601351       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}}}]}
I0811 15:03:25.994418       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:25.994473       1 utils.go:199] ID: 16 GRPC request: {}
I0811 15:03:25.994489       1 utils.go:205] ID: 16 GRPC response: {}
I0811 15:03:25.999029       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 15:03:25.999101       1 utils.go:199] ID: 17 GRPC request: {}
I0811 15:03:25.999112       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0811 15:03:25.999143       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 15:03:26.001404       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0811 15:03:26.001464       1 utils.go:199] ID: 18 GRPC request: {}
I0811 15:03:26.001492       1 utils.go:205] ID: 18 GRPC response: {}
I0811 15:03:26.002539       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 15:03:26.002566       1 utils.go:199] ID: 19 GRPC request: {}
I0811 15:03:26.002690       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 15:03:26.003624       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 15:03:26.003665       1 utils.go:199] ID: 20 GRPC request: {}
I0811 15:03:26.003684       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0811 15:03:26.003820       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}}}]}
I0811 15:04:26.254257       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0811 15:04:26.254298       1 utils.go:199] ID: 21 GRPC request: {}
I0811 15:04:26.254315       1 utils.go:205] ID: 21 GRPC response: {}
I0811 15:05:26.203809       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0811 15:05:26.203893       1 utils.go:199] ID: 22 GRPC request: {}
I0811 15:05:26.203915       1 utils.go:205] ID: 22 GRPC response: {}
I0811 15:06:13.162160       1 utils.go:198] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 GRPC call: /csi.v1.Controller/CreateVolume
I0811 15:06:13.162454       1 utils.go:199] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-b50310bc-f99f-432e-a29c-b452a2e73498","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-b50310bc-f99f-432e-a29c-b452a2e73498","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}}]}
I0811 15:06:13.162662       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0811 15:06:13.180260       1 omap.go:80] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0811 15:06:13.189757       1 omap.go:159] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-b50310bc-f99f-432e-a29c-b452a2e73498:00685d00-22f4-4fc9-a275-58bd0fb2b433])
I0811 15:06:13.194272       1 omap.go:159] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 set omap keys (pool="kube", namespace="", name="csi.volume.00685d00-22f4-4fc9-a275-58bd0fb2b433"): map[csi.imagename:csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433 csi.volname:pvc-b50310bc-f99f-432e-a29c-b452a2e73498 csi.volume.owner:default])
I0811 15:06:13.194298       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-00685d00-22f4-4fc9-a275-58bd0fb2b433) and image name (csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433) for request name (pvc-b50310bc-f99f-432e-a29c-b452a2e73498)
I0811 15:06:13.194352       1 rbd_util.go:423] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 rbd: create kube/csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433 size 5120M (features: [layering]) using mon 199.204.45.227
I0811 15:06:13.194404       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 setting image options on kube/csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433
I0811 15:06:13.211959       1 controllerserver.go:763] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 created image kube/csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433 backed for request name pvc-b50310bc-f99f-432e-a29c-b452a2e73498
I0811 15:06:13.232791       1 omap.go:159] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 set omap keys (pool="kube", namespace="", name="csi.volume.00685d00-22f4-4fc9-a275-58bd0fb2b433"): map[csi.imageid:3802a102815e])
I0811 15:06:13.309965       1 utils.go:205] ID: 23 Req-ID: pvc-b50310bc-f99f-432e-a29c-b452a2e73498 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-00685d00-22f4-4fc9-a275-58bd0fb2b433","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-00685d00-22f4-4fc9-a275-58bd0fb2b433"}}
I0811 15:06:26.197487       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0811 15:06:26.197550       1 utils.go:199] ID: 24 GRPC request: {}
I0811 15:06:26.197577       1 utils.go:205] ID: 24 GRPC response: {}