I0206 05:56:49.282976       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0206 05:56:49.283291       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0206 05:56:49.283358       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0206 05:56:49.283439       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0206 05:56:49.283495       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0206 05:56:49.283519       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0206 05:56:49.283601       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0206 05:56:49.283661       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0206 05:56:49.283719       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0206 05:56:49.283775       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0206 05:56:49.285161       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0206 05:56:49.285324       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0206 05:56:53.512540       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0206 05:56:53.513895       1 utils.go:199] ID: 1 GRPC request: {}
I0206 05:56:53.514008       1 utils.go:205] ID: 1 GRPC response: {}
I0206 05:56:53.518170       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 05:56:53.518594       1 utils.go:199] ID: 2 GRPC request: {}
I0206 05:56:53.518659       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0206 05:56:53.518751       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 05:56:53.524266       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0206 05:56:53.525512       1 utils.go:199] ID: 3 GRPC request: {}
I0206 05:56:53.525580       1 utils.go:205] ID: 3 GRPC response: {}
I0206 05:56:53.525956       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 05:56:53.526041       1 utils.go:199] ID: 4 GRPC request: {}
I0206 05:56:53.526311       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 05:56:53.529189       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:56:53.529295       1 utils.go:199] ID: 5 GRPC request: {}
I0206 05:56:53.529345       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0206 05:56:53.529493       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}}}]}
I0206 05:56:56.010096       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0206 05:56:56.010158       1 utils.go:199] ID: 6 GRPC request: {}
I0206 05:56:56.010184       1 utils.go:205] ID: 6 GRPC response: {}
I0206 05:56:56.014060       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 05:56:56.014103       1 utils.go:199] ID: 7 GRPC request: {}
I0206 05:56:56.014120       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0206 05:56:56.014151       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 05:56:56.015119       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0206 05:56:56.015157       1 utils.go:199] ID: 8 GRPC request: {}
I0206 05:56:56.015179       1 utils.go:205] ID: 8 GRPC response: {}
I0206 05:56:56.015429       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 05:56:56.015469       1 utils.go:199] ID: 9 GRPC request: {}
I0206 05:56:56.015554       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 05:56:56.015933       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:56:56.015965       1 utils.go:199] ID: 10 GRPC request: {}
I0206 05:56:56.015981       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0206 05:56:56.016068       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}}}]}
I0206 05:56:56.016334       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:56:56.016364       1 utils.go:199] ID: 11 GRPC request: {}
I0206 05:56:56.016378       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0206 05:56:56.016426       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}}}]}
I0206 05:56:56.016625       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:56:56.016648       1 utils.go:199] ID: 12 GRPC request: {}
I0206 05:56:56.016661       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0206 05:56:56.016707       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}}}]}
I0206 05:56:58.524794       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 05:56:58.524924       1 utils.go:199] ID: 13 GRPC request: {}
I0206 05:56:58.524937       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0206 05:56:58.525019       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 05:56:58.526790       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0206 05:56:58.526899       1 utils.go:199] ID: 14 GRPC request: {}
I0206 05:56:58.526978       1 utils.go:205] ID: 14 GRPC response: {}
I0206 05:56:58.527381       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:56:58.527451       1 utils.go:199] ID: 15 GRPC request: {}
I0206 05:56:58.527463       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0206 05:56:58.527592       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}}}]}
I0206 05:57:01.286342       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0206 05:57:01.286378       1 utils.go:199] ID: 16 GRPC request: {}
I0206 05:57:01.286396       1 utils.go:205] ID: 16 GRPC response: {}
I0206 05:57:01.290098       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 05:57:01.290112       1 utils.go:199] ID: 17 GRPC request: {}
I0206 05:57:01.290123       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0206 05:57:01.290143       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 05:57:01.291270       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0206 05:57:01.291283       1 utils.go:199] ID: 18 GRPC request: {}
I0206 05:57:01.291295       1 utils.go:205] ID: 18 GRPC response: {}
I0206 05:57:01.291492       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 05:57:01.291505       1 utils.go:199] ID: 19 GRPC request: {}
I0206 05:57:01.291580       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 05:57:01.292202       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 05:57:01.292217       1 utils.go:199] ID: 20 GRPC request: {}
I0206 05:57:01.292223       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0206 05:57:01.292282       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}}}]}
I0206 05:58:01.484482       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0206 05:58:01.484525       1 utils.go:199] ID: 21 GRPC request: {}
I0206 05:58:01.485020       1 utils.go:205] ID: 21 GRPC response: {}
I0206 05:59:01.484306       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0206 05:59:01.484425       1 utils.go:199] ID: 22 GRPC request: {}
I0206 05:59:01.484472       1 utils.go:205] ID: 22 GRPC response: {}
I0206 05:59:52.978433       1 utils.go:198] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 GRPC call: /csi.v1.Controller/CreateVolume
I0206 05:59:52.980671       1 utils.go:199] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2","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}}]}
I0206 05:59:52.980935       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0206 05:59:53.029737       1 omap.go:80] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0206 05:59:53.045443       1 omap.go:159] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2:47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c])
I0206 05:59:53.050844       1 omap.go:159] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 set omap keys (pool="kube", namespace="", name="csi.volume.47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c"): map[csi.imagename:csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c csi.volname:pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 csi.volume.owner:default])
I0206 05:59:53.050868       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c) and image name (csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c) for request name (pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2)
I0206 05:59:53.050942       1 rbd_util.go:423] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 rbd: create kube/csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c size 5120M (features: [layering]) using mon 162.253.55.49
I0206 05:59:53.050973       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 setting image options on kube/csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c
I0206 05:59:54.797706       1 controllerserver.go:763] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 created image kube/csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c backed for request name pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2
I0206 05:59:54.823437       1 omap.go:159] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 set omap keys (pool="kube", namespace="", name="csi.volume.47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c"): map[csi.imageid:37d86a0f440a])
I0206 05:59:54.916938       1 utils.go:205] ID: 23 Req-ID: pvc-7fdb472b-2535-4654-8ad7-70b5a672a9e2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-47dd14d2-e5fe-4e00-9b2c-b3c93c2c387c"}}
I0206 06:00:01.481913       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0206 06:00:01.482251       1 utils.go:199] ID: 24 GRPC request: {}
I0206 06:00:01.482465       1 utils.go:205] ID: 24 GRPC response: {}