I0709 14:41:26.691665       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0709 14:41:26.691785       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0709 14:41:26.691801       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0709 14:41:26.691805       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0709 14:41:26.691811       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0709 14:41:26.691815       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0709 14:41:26.691820       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0709 14:41:26.691823       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0709 14:41:26.691827       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0709 14:41:26.691831       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0709 14:41:26.692179       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0709 14:41:26.692187       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0709 14:41:35.876242       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:35.878268       1 utils.go:199] ID: 1 GRPC request: {}
I0709 14:41:35.878349       1 utils.go:205] ID: 1 GRPC response: {}
I0709 14:41:35.886188       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 14:41:35.886416       1 utils.go:199] ID: 2 GRPC request: {}
I0709 14:41:35.886466       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0709 14:41:35.886607       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 14:41:35.888712       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:35.888755       1 utils.go:199] ID: 3 GRPC request: {}
I0709 14:41:35.888771       1 utils.go:205] ID: 3 GRPC response: {}
I0709 14:41:35.889372       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 14:41:35.889446       1 utils.go:199] ID: 4 GRPC request: {}
I0709 14:41:35.889576       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 14:41:35.890286       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:35.890356       1 utils.go:199] ID: 5 GRPC request: {}
I0709 14:41:35.890369       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0709 14:41:35.890472       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}}}]}
I0709 14:41:39.964295       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:39.964366       1 utils.go:199] ID: 6 GRPC request: {}
I0709 14:41:39.964401       1 utils.go:205] ID: 6 GRPC response: {}
I0709 14:41:39.967812       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 14:41:39.967853       1 utils.go:199] ID: 7 GRPC request: {}
I0709 14:41:39.967864       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0709 14:41:39.967893       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 14:41:39.972694       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:39.972750       1 utils.go:199] ID: 8 GRPC request: {}
I0709 14:41:39.972790       1 utils.go:205] ID: 8 GRPC response: {}
I0709 14:41:39.973331       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 14:41:39.973370       1 utils.go:199] ID: 9 GRPC request: {}
I0709 14:41:39.973476       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 14:41:39.974249       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:39.974291       1 utils.go:199] ID: 10 GRPC request: {}
I0709 14:41:39.974333       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0709 14:41:39.974469       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}}}]}
I0709 14:41:39.975349       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:39.975426       1 utils.go:199] ID: 11 GRPC request: {}
I0709 14:41:39.975504       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0709 14:41:39.975789       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}}}]}
I0709 14:41:39.976469       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:39.976502       1 utils.go:199] ID: 12 GRPC request: {}
I0709 14:41:39.976513       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0709 14:41:39.976598       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}}}]}
I0709 14:41:42.630757       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 14:41:42.630812       1 utils.go:199] ID: 13 GRPC request: {}
I0709 14:41:42.630825       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0709 14:41:42.630861       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 14:41:42.634937       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:42.634997       1 utils.go:199] ID: 14 GRPC request: {}
I0709 14:41:42.635026       1 utils.go:205] ID: 14 GRPC response: {}
I0709 14:41:42.635810       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:42.635909       1 utils.go:199] ID: 15 GRPC request: {}
I0709 14:41:42.635928       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0709 14:41:42.636137       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}}}]}
I0709 14:41:44.472611       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:44.472653       1 utils.go:199] ID: 16 GRPC request: {}
I0709 14:41:44.472726       1 utils.go:205] ID: 16 GRPC response: {}
I0709 14:41:44.474945       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0709 14:41:44.474967       1 utils.go:199] ID: 17 GRPC request: {}
I0709 14:41:44.474977       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0709 14:41:44.475019       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0709 14:41:44.477519       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0709 14:41:44.477566       1 utils.go:199] ID: 18 GRPC request: {}
I0709 14:41:44.477590       1 utils.go:205] ID: 18 GRPC response: {}
I0709 14:41:44.478047       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0709 14:41:44.478069       1 utils.go:199] ID: 19 GRPC request: {}
I0709 14:41:44.478208       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0709 14:41:44.479002       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0709 14:41:44.479032       1 utils.go:199] ID: 20 GRPC request: {}
I0709 14:41:44.479043       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0709 14:41:44.479193       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}}}]}
I0709 14:42:44.750549       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0709 14:42:44.750605       1 utils.go:199] ID: 21 GRPC request: {}
I0709 14:42:44.750631       1 utils.go:205] ID: 21 GRPC response: {}
I0709 14:43:44.750320       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0709 14:43:44.750355       1 utils.go:199] ID: 22 GRPC request: {}
I0709 14:43:44.750368       1 utils.go:205] ID: 22 GRPC response: {}
I0709 14:44:44.750012       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0709 14:44:44.750091       1 utils.go:199] ID: 23 GRPC request: {}
I0709 14:44:44.750126       1 utils.go:205] ID: 23 GRPC response: {}
I0709 14:45:23.892754       1 utils.go:198] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 GRPC call: /csi.v1.Controller/CreateVolume
I0709 14:45:23.893453       1 utils.go:199] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9","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}}]}
I0709 14:45:23.894279       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0709 14:45:23.913108       1 omap.go:80] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0709 14:45:23.928030       1 omap.go:159] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9:8185cafc-547c-4edf-8576-9363d314937a])
I0709 14:45:23.933706       1 omap.go:159] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 set omap keys (pool="kube", namespace="", name="csi.volume.8185cafc-547c-4edf-8576-9363d314937a"): map[csi.imagename:csi-vol-8185cafc-547c-4edf-8576-9363d314937a csi.volname:pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 csi.volume.owner:default])
I0709 14:45:23.933886       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8185cafc-547c-4edf-8576-9363d314937a) and image name (csi-vol-8185cafc-547c-4edf-8576-9363d314937a) for request name (pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9)
I0709 14:45:23.934130       1 rbd_util.go:423] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 rbd: create kube/csi-vol-8185cafc-547c-4edf-8576-9363d314937a size 5120M (features: [layering]) using mon 199.19.213.232
I0709 14:45:23.934306       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 setting image options on kube/csi-vol-8185cafc-547c-4edf-8576-9363d314937a
I0709 14:45:23.963324       1 controllerserver.go:763] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 created image kube/csi-vol-8185cafc-547c-4edf-8576-9363d314937a backed for request name pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9
I0709 14:45:23.995817       1 omap.go:159] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 set omap keys (pool="kube", namespace="", name="csi.volume.8185cafc-547c-4edf-8576-9363d314937a"): map[csi.imageid:37ed7ae0f66b])
I0709 14:45:24.084705       1 utils.go:205] ID: 24 Req-ID: pvc-93f9e748-b7e8-4dcc-911e-0cb03480f7b9 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8185cafc-547c-4edf-8576-9363d314937a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8185cafc-547c-4edf-8576-9363d314937a"}}
I0709 14:45:44.763868       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0709 14:45:44.764133       1 utils.go:199] ID: 25 GRPC request: {}
I0709 14:45:44.764382       1 utils.go:205] ID: 25 GRPC response: {}