I0129 03:19:55.851680       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0129 03:19:55.851814       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0129 03:19:55.851948       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0129 03:19:55.851957       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0129 03:19:55.851960       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0129 03:19:55.851963       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0129 03:19:55.851966       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0129 03:19:55.851969       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0129 03:19:55.851972       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0129 03:19:55.851976       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0129 03:19:55.852268       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0129 03:19:55.852409       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0129 03:20:02.532191       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:02.533461       1 utils.go:199] ID: 1 GRPC request: {}
I0129 03:20:02.533529       1 utils.go:205] ID: 1 GRPC response: {}
I0129 03:20:02.535486       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:20:02.535678       1 utils.go:199] ID: 2 GRPC request: {}
I0129 03:20:02.535984       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0129 03:20:02.536060       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:20:02.537649       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:02.537679       1 utils.go:199] ID: 3 GRPC request: {}
I0129 03:20:02.537737       1 utils.go:205] ID: 3 GRPC response: {}
I0129 03:20:02.539077       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:20:02.539152       1 utils.go:199] ID: 4 GRPC request: {}
I0129 03:20:02.539364       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:20:02.540025       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:02.540173       1 utils.go:199] ID: 5 GRPC request: {}
I0129 03:20:02.540185       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0129 03:20:02.540358       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}}}]}
I0129 03:20:05.256808       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:05.256845       1 utils.go:199] ID: 6 GRPC request: {}
I0129 03:20:05.256863       1 utils.go:205] ID: 6 GRPC response: {}
I0129 03:20:05.259432       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:20:05.259533       1 utils.go:199] ID: 7 GRPC request: {}
I0129 03:20:05.259576       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0129 03:20:05.259624       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:20:05.262685       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:05.262788       1 utils.go:199] ID: 8 GRPC request: {}
I0129 03:20:05.262854       1 utils.go:205] ID: 8 GRPC response: {}
I0129 03:20:05.263562       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:20:05.263595       1 utils.go:199] ID: 9 GRPC request: {}
I0129 03:20:05.263684       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:20:05.264221       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:05.264332       1 utils.go:199] ID: 10 GRPC request: {}
I0129 03:20:05.264423       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0129 03:20:05.264576       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}}}]}
I0129 03:20:05.265142       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:05.265158       1 utils.go:199] ID: 11 GRPC request: {}
I0129 03:20:05.265182       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0129 03:20:05.265300       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}}}]}
I0129 03:20:05.265580       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:05.265655       1 utils.go:199] ID: 12 GRPC request: {}
I0129 03:20:05.265699       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0129 03:20:05.265806       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}}}]}
I0129 03:20:09.515118       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:20:09.515165       1 utils.go:199] ID: 13 GRPC request: {}
I0129 03:20:09.515319       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0129 03:20:09.515446       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:20:09.519013       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:09.519037       1 utils.go:199] ID: 14 GRPC request: {}
I0129 03:20:09.519050       1 utils.go:205] ID: 14 GRPC response: {}
I0129 03:20:09.519660       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:09.519713       1 utils.go:199] ID: 15 GRPC request: {}
I0129 03:20:09.519721       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0129 03:20:09.521125       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}}}]}
I0129 03:20:14.854223       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:14.854258       1 utils.go:199] ID: 16 GRPC request: {}
I0129 03:20:14.854291       1 utils.go:205] ID: 16 GRPC response: {}
I0129 03:20:14.859695       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:20:14.859715       1 utils.go:199] ID: 17 GRPC request: {}
I0129 03:20:14.859721       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0129 03:20:14.859738       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:20:14.862912       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0129 03:20:14.862926       1 utils.go:199] ID: 18 GRPC request: {}
I0129 03:20:14.862935       1 utils.go:205] ID: 18 GRPC response: {}
I0129 03:20:14.863310       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:20:14.863333       1 utils.go:199] ID: 19 GRPC request: {}
I0129 03:20:14.863398       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:20:14.864663       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:20:14.864684       1 utils.go:199] ID: 20 GRPC request: {}
I0129 03:20:14.864695       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0129 03:20:14.864748       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}}}]}
I0129 03:21:15.234685       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0129 03:21:15.234716       1 utils.go:199] ID: 21 GRPC request: {}
I0129 03:21:15.234728       1 utils.go:205] ID: 21 GRPC response: {}
I0129 03:22:15.239821       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0129 03:22:15.240139       1 utils.go:199] ID: 22 GRPC request: {}
I0129 03:22:15.240643       1 utils.go:205] ID: 22 GRPC response: {}
I0129 03:23:15.290385       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0129 03:23:15.290457       1 utils.go:199] ID: 23 GRPC request: {}
I0129 03:23:15.290485       1 utils.go:205] ID: 23 GRPC response: {}
I0129 03:23:33.296032       1 utils.go:198] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 GRPC call: /csi.v1.Controller/CreateVolume
I0129 03:23:33.296527       1 utils.go:199] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-960bd230-9010-40a6-836a-dbaab0dff2c1","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-960bd230-9010-40a6-836a-dbaab0dff2c1","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}}]}
I0129 03:23:33.296904       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0129 03:23:33.316091       1 omap.go:80] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0129 03:23:33.344419       1 omap.go:159] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-960bd230-9010-40a6-836a-dbaab0dff2c1:e00d6753-9af3-4b72-81b1-19264c55ee67])
I0129 03:23:33.353600       1 omap.go:159] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 set omap keys (pool="kube", namespace="", name="csi.volume.e00d6753-9af3-4b72-81b1-19264c55ee67"): map[csi.imagename:csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67 csi.volname:pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 csi.volume.owner:default])
I0129 03:23:33.354592       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e00d6753-9af3-4b72-81b1-19264c55ee67) and image name (csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67) for request name (pvc-960bd230-9010-40a6-836a-dbaab0dff2c1)
I0129 03:23:33.354696       1 rbd_util.go:423] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 rbd: create kube/csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67 size 5120M (features: [layering]) using mon 199.204.45.156
I0129 03:23:33.354778       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 setting image options on kube/csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67
I0129 03:23:34.749000       1 controllerserver.go:763] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 created image kube/csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67 backed for request name pvc-960bd230-9010-40a6-836a-dbaab0dff2c1
I0129 03:23:34.817242       1 omap.go:159] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 set omap keys (pool="kube", namespace="", name="csi.volume.e00d6753-9af3-4b72-81b1-19264c55ee67"): map[csi.imageid:37d97ce89564])
I0129 03:23:34.941176       1 utils.go:205] ID: 24 Req-ID: pvc-960bd230-9010-40a6-836a-dbaab0dff2c1 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-e00d6753-9af3-4b72-81b1-19264c55ee67","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e00d6753-9af3-4b72-81b1-19264c55ee67"}}
I0129 03:24:15.245562       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0129 03:24:15.245602       1 utils.go:199] ID: 25 GRPC request: {}
I0129 03:24:15.245618       1 utils.go:205] ID: 25 GRPC response: {}