I0131 21:24:20.240852 1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a I0131 21:24:20.241017 1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com I0131 21:24:20.241099 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME I0131 21:24:20.241159 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I0131 21:24:20.241279 1 driver.go:95] Enabling controller service capability: CLONE_VOLUME I0131 21:24:20.241303 1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME I0131 21:24:20.241334 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER I0131 21:24:20.241351 1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER I0131 21:24:20.241380 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER I0131 21:24:20.241401 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER I0131 21:24:20.242110 1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"} I0131 21:24:20.242224 1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"} I0131 21:24:24.336978 1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe I0131 21:24:24.338010 1 utils.go:199] ID: 1 GRPC request: {} I0131 21:24:24.338527 1 utils.go:205] ID: 1 GRPC response: {} I0131 21:24:24.342631 1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo I0131 21:24:24.342711 1 utils.go:199] ID: 2 GRPC request: {} I0131 21:24:24.342733 1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo I0131 21:24:24.342780 1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0131 21:24:24.344598 1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe I0131 21:24:24.344615 1 utils.go:199] ID: 3 GRPC request: {} I0131 21:24:24.344626 1 utils.go:205] ID: 3 GRPC response: {} I0131 21:24:24.344892 1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0131 21:24:24.344934 1 utils.go:199] ID: 4 GRPC request: {} I0131 21:24:24.345085 1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0131 21:24:24.345599 1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:24.345632 1 utils.go:199] ID: 5 GRPC request: {} I0131 21:24:24.345653 1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities I0131 21:24:24.345750 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}}}]} I0131 21:24:27.695150 1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe I0131 21:24:27.695192 1 utils.go:199] ID: 6 GRPC request: {} I0131 21:24:27.695207 1 utils.go:205] ID: 6 GRPC response: {} I0131 21:24:27.697451 1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo I0131 21:24:27.697479 1 utils.go:199] ID: 7 GRPC request: {} I0131 21:24:27.697491 1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo I0131 21:24:27.697512 1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0131 21:24:27.698735 1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe I0131 21:24:27.698750 1 utils.go:199] ID: 8 GRPC request: {} I0131 21:24:27.698812 1 utils.go:205] ID: 8 GRPC response: {} I0131 21:24:27.699273 1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0131 21:24:27.699288 1 utils.go:199] ID: 9 GRPC request: {} I0131 21:24:27.699432 1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0131 21:24:27.699992 1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:27.700008 1 utils.go:199] ID: 10 GRPC request: {} I0131 21:24:27.700037 1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities I0131 21:24:27.700148 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}}}]} I0131 21:24:27.700572 1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:27.700594 1 utils.go:199] ID: 11 GRPC request: {} I0131 21:24:27.700600 1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities I0131 21:24:27.700665 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}}}]} I0131 21:24:27.701019 1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:27.701138 1 utils.go:199] ID: 12 GRPC request: {} I0131 21:24:27.701147 1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities I0131 21:24:27.701279 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}}}]} I0131 21:24:29.918046 1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo I0131 21:24:29.918101 1 utils.go:199] ID: 13 GRPC request: {} I0131 21:24:29.918118 1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo I0131 21:24:29.918156 1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0131 21:24:29.923730 1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe I0131 21:24:29.923826 1 utils.go:199] ID: 14 GRPC request: {} I0131 21:24:29.923890 1 utils.go:205] ID: 14 GRPC response: {} I0131 21:24:29.924280 1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:29.924336 1 utils.go:199] ID: 15 GRPC request: {} I0131 21:24:29.924364 1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities I0131 21:24:29.924509 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}}}]} I0131 21:24:32.169390 1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe I0131 21:24:32.169594 1 utils.go:199] ID: 16 GRPC request: {} I0131 21:24:32.169685 1 utils.go:205] ID: 16 GRPC response: {} I0131 21:24:32.177143 1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo I0131 21:24:32.177185 1 utils.go:199] ID: 17 GRPC request: {} I0131 21:24:32.177212 1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo I0131 21:24:32.177237 1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0131 21:24:32.180778 1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe I0131 21:24:32.180799 1 utils.go:199] ID: 18 GRPC request: {} I0131 21:24:32.180829 1 utils.go:205] ID: 18 GRPC response: {} I0131 21:24:32.182016 1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0131 21:24:32.182157 1 utils.go:199] ID: 19 GRPC request: {} I0131 21:24:32.182252 1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0131 21:24:32.182744 1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0131 21:24:32.182777 1 utils.go:199] ID: 20 GRPC request: {} I0131 21:24:32.182797 1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities I0131 21:24:32.182908 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}}}]} I0131 21:25:32.390587 1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe I0131 21:25:32.390883 1 utils.go:199] ID: 21 GRPC request: {} I0131 21:25:32.391009 1 utils.go:205] ID: 21 GRPC response: {} I0131 21:26:32.392382 1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe I0131 21:26:32.392428 1 utils.go:199] ID: 22 GRPC request: {} I0131 21:26:32.392449 1 utils.go:205] ID: 22 GRPC response: {} I0131 21:27:27.871346 1 utils.go:198] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd GRPC call: /csi.v1.Controller/CreateVolume I0131 21:27:27.876024 1 utils.go:199] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-eedd14a5-3072-443a-9b06-c0312975a3fd","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-eedd14a5-3072-443a-9b06-c0312975a3fd","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}}]} I0131 21:27:27.876319 1 rbd_util.go:1315] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd setting disableInUseChecks: false image features: [layering] mounter: rbd E0131 21:27:27.924624 1 omap.go:80] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory I0131 21:27:27.941579 1 omap.go:159] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-eedd14a5-3072-443a-9b06-c0312975a3fd:c7bc2f3e-7dae-4d46-9e99-394872871f08]) I0131 21:27:27.964121 1 omap.go:159] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd set omap keys (pool="kube", namespace="", name="csi.volume.c7bc2f3e-7dae-4d46-9e99-394872871f08"): map[csi.imagename:csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08 csi.volname:pvc-eedd14a5-3072-443a-9b06-c0312975a3fd csi.volume.owner:default]) I0131 21:27:27.964177 1 rbd_journal.go:491] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c7bc2f3e-7dae-4d46-9e99-394872871f08) and image name (csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08) for request name (pvc-eedd14a5-3072-443a-9b06-c0312975a3fd) I0131 21:27:27.964559 1 rbd_util.go:423] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd rbd: create kube/csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08 size 5120M (features: [layering]) using mon 162.253.55.227 I0131 21:27:27.964604 1 rbd_util.go:1563] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd setting image options on kube/csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08 I0131 21:27:30.042897 1 controllerserver.go:763] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd created image kube/csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08 backed for request name pvc-eedd14a5-3072-443a-9b06-c0312975a3fd I0131 21:27:30.079856 1 omap.go:159] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd set omap keys (pool="kube", namespace="", name="csi.volume.c7bc2f3e-7dae-4d46-9e99-394872871f08"): map[csi.imageid:37d92624bae5]) I0131 21:27:30.174803 1 utils.go:205] ID: 23 Req-ID: pvc-eedd14a5-3072-443a-9b06-c0312975a3fd GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c7bc2f3e-7dae-4d46-9e99-394872871f08","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c7bc2f3e-7dae-4d46-9e99-394872871f08"}} I0131 21:27:32.389916 1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe I0131 21:27:32.390262 1 utils.go:199] ID: 24 GRPC request: {} I0131 21:27:32.390451 1 utils.go:205] ID: 24 GRPC response: {}