I0922 01:52:40.555063       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0922 01:52:40.555201       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0922 01:52:40.555213       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0922 01:52:40.555216       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0922 01:52:40.555219       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0922 01:52:40.555222       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0922 01:52:40.555236       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0922 01:52:40.555238       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0922 01:52:40.555241       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0922 01:52:40.555244       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0922 01:52:40.555537       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0922 01:52:40.555621       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0922 01:52:44.801330       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:44.803456       1 utils.go:199] ID: 1 GRPC request: {}
I0922 01:52:44.803587       1 utils.go:205] ID: 1 GRPC response: {}
I0922 01:52:44.806661       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 01:52:44.806875       1 utils.go:199] ID: 2 GRPC request: {}
I0922 01:52:44.806950       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0922 01:52:44.807059       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 01:52:44.810359       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:44.810430       1 utils.go:199] ID: 3 GRPC request: {}
I0922 01:52:44.810511       1 utils.go:205] ID: 3 GRPC response: {}
I0922 01:52:44.811454       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 01:52:44.811633       1 utils.go:199] ID: 4 GRPC request: {}
I0922 01:52:44.811935       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 01:52:44.812893       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:44.812991       1 utils.go:199] ID: 5 GRPC request: {}
I0922 01:52:44.813075       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0922 01:52:44.813412       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}}}]}
I0922 01:52:46.355953       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:46.356053       1 utils.go:199] ID: 6 GRPC request: {}
I0922 01:52:46.356086       1 utils.go:205] ID: 6 GRPC response: {}
I0922 01:52:46.358407       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 01:52:46.358438       1 utils.go:199] ID: 7 GRPC request: {}
I0922 01:52:46.358448       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0922 01:52:46.358538       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 01:52:46.362070       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:46.362149       1 utils.go:199] ID: 8 GRPC request: {}
I0922 01:52:46.362178       1 utils.go:205] ID: 8 GRPC response: {}
I0922 01:52:46.362977       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 01:52:46.363005       1 utils.go:199] ID: 9 GRPC request: {}
I0922 01:52:46.363242       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 01:52:46.364403       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:46.364427       1 utils.go:199] ID: 10 GRPC request: {}
I0922 01:52:46.364488       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0922 01:52:46.364670       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}}}]}
I0922 01:52:46.365502       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:46.365553       1 utils.go:199] ID: 11 GRPC request: {}
I0922 01:52:46.365568       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0922 01:52:46.365691       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}}}]}
I0922 01:52:46.366298       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:46.366357       1 utils.go:199] ID: 12 GRPC request: {}
I0922 01:52:46.366378       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0922 01:52:46.366493       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}}}]}
I0922 01:52:47.849550       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 01:52:47.849625       1 utils.go:199] ID: 13 GRPC request: {}
I0922 01:52:47.849639       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0922 01:52:47.849940       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 01:52:47.852969       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:47.853031       1 utils.go:199] ID: 14 GRPC request: {}
I0922 01:52:47.853062       1 utils.go:205] ID: 14 GRPC response: {}
I0922 01:52:47.853831       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:47.853884       1 utils.go:199] ID: 15 GRPC request: {}
I0922 01:52:47.853895       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0922 01:52:47.854036       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}}}]}
I0922 01:52:49.308887       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:49.308937       1 utils.go:199] ID: 16 GRPC request: {}
I0922 01:52:49.308960       1 utils.go:205] ID: 16 GRPC response: {}
I0922 01:52:49.311772       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 01:52:49.311811       1 utils.go:199] ID: 17 GRPC request: {}
I0922 01:52:49.311819       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0922 01:52:49.311844       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 01:52:49.313984       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0922 01:52:49.314010       1 utils.go:199] ID: 18 GRPC request: {}
I0922 01:52:49.314023       1 utils.go:205] ID: 18 GRPC response: {}
I0922 01:52:49.314484       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 01:52:49.314639       1 utils.go:199] ID: 19 GRPC request: {}
I0922 01:52:49.314982       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 01:52:49.319030       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 01:52:49.319064       1 utils.go:199] ID: 20 GRPC request: {}
I0922 01:52:49.319115       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0922 01:52:49.319339       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}}}]}
I0922 01:53:49.513817       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0922 01:53:49.513887       1 utils.go:199] ID: 21 GRPC request: {}
I0922 01:53:49.513911       1 utils.go:205] ID: 21 GRPC response: {}
I0922 01:54:49.515547       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0922 01:54:49.515596       1 utils.go:199] ID: 22 GRPC request: {}
I0922 01:54:49.515641       1 utils.go:205] ID: 22 GRPC response: {}
I0922 01:55:49.512789       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0922 01:55:49.512838       1 utils.go:199] ID: 23 GRPC request: {}
I0922 01:55:49.512859       1 utils.go:205] ID: 23 GRPC response: {}
I0922 01:56:49.524019       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0922 01:56:49.524147       1 utils.go:199] ID: 24 GRPC request: {}
I0922 01:56:49.524202       1 utils.go:205] ID: 24 GRPC response: {}
I0922 01:57:13.477214       1 utils.go:198] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 GRPC call: /csi.v1.Controller/CreateVolume
I0922 01:57:13.477755       1 utils.go:199] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-440de854-808d-404d-a34f-09fc6046abe2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-440de854-808d-404d-a34f-09fc6046abe2","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}}]}
I0922 01:57:13.478166       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0922 01:57:13.502469       1 omap.go:80] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0922 01:57:13.522315       1 omap.go:159] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-440de854-808d-404d-a34f-09fc6046abe2:06c3dbf8-e565-4af7-976e-7b6fa35e616d])
I0922 01:57:13.531017       1 omap.go:159] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 set omap keys (pool="kube", namespace="", name="csi.volume.06c3dbf8-e565-4af7-976e-7b6fa35e616d"): map[csi.imagename:csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d csi.volname:pvc-440de854-808d-404d-a34f-09fc6046abe2 csi.volume.owner:default])
I0922 01:57:13.531123       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-06c3dbf8-e565-4af7-976e-7b6fa35e616d) and image name (csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d) for request name (pvc-440de854-808d-404d-a34f-09fc6046abe2)
I0922 01:57:13.531379       1 rbd_util.go:423] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 rbd: create kube/csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d size 5120M (features: [layering]) using mon 162.253.55.165
I0922 01:57:13.531471       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 setting image options on kube/csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d
I0922 01:57:13.567284       1 controllerserver.go:763] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 created image kube/csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d backed for request name pvc-440de854-808d-404d-a34f-09fc6046abe2
I0922 01:57:13.604735       1 omap.go:159] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 set omap keys (pool="kube", namespace="", name="csi.volume.06c3dbf8-e565-4af7-976e-7b6fa35e616d"): map[csi.imageid:37f41dcea484])
I0922 01:57:13.708454       1 utils.go:205] ID: 25 Req-ID: pvc-440de854-808d-404d-a34f-09fc6046abe2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-06c3dbf8-e565-4af7-976e-7b6fa35e616d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-06c3dbf8-e565-4af7-976e-7b6fa35e616d"}}
I0922 01:57:49.515308       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0922 01:57:49.515341       1 utils.go:199] ID: 26 GRPC request: {}
I0922 01:57:49.515354       1 utils.go:205] ID: 26 GRPC response: {}