I0717 10:55:58.259522 1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a I0717 10:55:58.259717 1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com I0717 10:55:58.259746 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME I0717 10:55:58.259754 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I0717 10:55:58.259761 1 driver.go:95] Enabling controller service capability: CLONE_VOLUME I0717 10:55:58.259768 1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME I0717 10:55:58.259782 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER I0717 10:55:58.259788 1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER I0717 10:55:58.259796 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER I0717 10:55:58.259809 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER I0717 10:55:58.260325 1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"} I0717 10:55:58.260335 1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"} I0717 10:56:05.617376 1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe I0717 10:56:05.620423 1 utils.go:199] ID: 1 GRPC request: {} I0717 10:56:05.620543 1 utils.go:205] ID: 1 GRPC response: {} I0717 10:56:05.624528 1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo I0717 10:56:05.624583 1 utils.go:199] ID: 2 GRPC request: {} I0717 10:56:05.624598 1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo I0717 10:56:05.624663 1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0717 10:56:05.626637 1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe I0717 10:56:05.626670 1 utils.go:199] ID: 3 GRPC request: {} I0717 10:56:05.626679 1 utils.go:205] ID: 3 GRPC response: {} I0717 10:56:05.627403 1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0717 10:56:05.627596 1 utils.go:199] ID: 4 GRPC request: {} I0717 10:56:05.627984 1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0717 10:56:05.629018 1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:05.629074 1 utils.go:199] ID: 5 GRPC request: {} I0717 10:56:05.629082 1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities I0717 10:56:05.629180 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}}}]} I0717 10:56:10.669246 1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe I0717 10:56:10.669509 1 utils.go:199] ID: 6 GRPC request: {} I0717 10:56:10.669531 1 utils.go:205] ID: 6 GRPC response: {} I0717 10:56:10.672039 1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo I0717 10:56:10.672111 1 utils.go:199] ID: 7 GRPC request: {} I0717 10:56:10.672123 1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo I0717 10:56:10.672170 1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0717 10:56:10.674544 1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe I0717 10:56:10.674592 1 utils.go:199] ID: 8 GRPC request: {} I0717 10:56:10.674625 1 utils.go:205] ID: 8 GRPC response: {} I0717 10:56:10.675310 1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0717 10:56:10.675349 1 utils.go:199] ID: 9 GRPC request: {} I0717 10:56:10.675474 1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0717 10:56:10.678207 1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:10.678249 1 utils.go:199] ID: 10 GRPC request: {} I0717 10:56:10.678275 1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities I0717 10:56:10.678413 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}}}]} I0717 10:56:10.679294 1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:10.679385 1 utils.go:199] ID: 11 GRPC request: {} I0717 10:56:10.679420 1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities I0717 10:56:10.679577 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}}}]} I0717 10:56:10.680159 1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:10.680184 1 utils.go:199] ID: 12 GRPC request: {} I0717 10:56:10.680211 1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities I0717 10:56:10.680324 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}}}]} I0717 10:56:12.809693 1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo I0717 10:56:12.809881 1 utils.go:199] ID: 13 GRPC request: {} I0717 10:56:12.809916 1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo I0717 10:56:12.809963 1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0717 10:56:12.813709 1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe I0717 10:56:12.813826 1 utils.go:199] ID: 14 GRPC request: {} I0717 10:56:12.813856 1 utils.go:205] ID: 14 GRPC response: {} I0717 10:56:12.814974 1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:12.815062 1 utils.go:199] ID: 15 GRPC request: {} I0717 10:56:12.815087 1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities I0717 10:56:12.815203 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}}}]} I0717 10:56:14.283976 1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe I0717 10:56:14.284107 1 utils.go:199] ID: 16 GRPC request: {} I0717 10:56:14.284179 1 utils.go:205] ID: 16 GRPC response: {} I0717 10:56:14.287499 1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo I0717 10:56:14.287588 1 utils.go:199] ID: 17 GRPC request: {} I0717 10:56:14.287620 1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo I0717 10:56:14.287689 1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0717 10:56:14.289805 1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe I0717 10:56:14.289833 1 utils.go:199] ID: 18 GRPC request: {} I0717 10:56:14.289850 1 utils.go:205] ID: 18 GRPC response: {} I0717 10:56:14.290390 1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0717 10:56:14.290542 1 utils.go:199] ID: 19 GRPC request: {} I0717 10:56:14.290642 1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0717 10:56:14.291419 1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0717 10:56:14.291439 1 utils.go:199] ID: 20 GRPC request: {} I0717 10:56:14.291447 1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities I0717 10:56:14.291506 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}}}]} I0717 10:57:14.486903 1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe I0717 10:57:14.487074 1 utils.go:199] ID: 21 GRPC request: {} I0717 10:57:14.487163 1 utils.go:205] ID: 21 GRPC response: {} I0717 10:58:14.486105 1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe I0717 10:58:14.487286 1 utils.go:199] ID: 22 GRPC request: {} I0717 10:58:14.487399 1 utils.go:205] ID: 22 GRPC response: {} I0717 10:59:14.485820 1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe I0717 10:59:14.485894 1 utils.go:199] ID: 23 GRPC request: {} I0717 10:59:14.485991 1 utils.go:205] ID: 23 GRPC response: {} I0717 11:00:14.500190 1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe I0717 11:00:14.500548 1 utils.go:199] ID: 24 GRPC request: {} I0717 11:00:14.500583 1 utils.go:205] ID: 24 GRPC response: {} I0717 11:00:50.847794 1 utils.go:198] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 GRPC call: /csi.v1.Controller/CreateVolume I0717 11:00:50.848077 1 utils.go:199] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4","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}}]} I0717 11:00:50.848292 1 rbd_util.go:1315] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 setting disableInUseChecks: false image features: [layering] mounter: rbd E0717 11:00:50.871119 1 omap.go:80] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory I0717 11:00:50.887022 1 omap.go:159] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4:f6d2f40f-697e-412f-80d7-3e2ef82f3297]) I0717 11:00:50.893551 1 omap.go:159] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 set omap keys (pool="kube", namespace="", name="csi.volume.f6d2f40f-697e-412f-80d7-3e2ef82f3297"): map[csi.imagename:csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297 csi.volname:pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 csi.volume.owner:default]) I0717 11:00:50.893607 1 rbd_journal.go:491] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f6d2f40f-697e-412f-80d7-3e2ef82f3297) and image name (csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297) for request name (pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4) I0717 11:00:50.893694 1 rbd_util.go:423] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 rbd: create kube/csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297 size 5120M (features: [layering]) using mon 199.204.45.70 I0717 11:00:50.893742 1 rbd_util.go:1563] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 setting image options on kube/csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297 I0717 11:00:50.925968 1 controllerserver.go:763] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 created image kube/csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297 backed for request name pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 I0717 11:00:50.959204 1 omap.go:159] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 set omap keys (pool="kube", namespace="", name="csi.volume.f6d2f40f-697e-412f-80d7-3e2ef82f3297"): map[csi.imageid:37f4c2205587]) I0717 11:00:51.055180 1 utils.go:205] ID: 25 Req-ID: pvc-30bba5b1-7c4d-42d8-be7e-56ac74c4ddd4 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-f6d2f40f-697e-412f-80d7-3e2ef82f3297","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f6d2f40f-697e-412f-80d7-3e2ef82f3297"}} I0717 11:01:14.485045 1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe I0717 11:01:14.485192 1 utils.go:199] ID: 26 GRPC request: {} I0717 11:01:14.485224 1 utils.go:205] ID: 26 GRPC response: {}