I0511 17:00:24.537417 1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a I0511 17:00:24.537549 1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com I0511 17:00:24.537591 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME I0511 17:00:24.537597 1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I0511 17:00:24.537600 1 driver.go:95] Enabling controller service capability: CLONE_VOLUME I0511 17:00:24.537603 1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME I0511 17:00:24.537608 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER I0511 17:00:24.537611 1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER I0511 17:00:24.537614 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER I0511 17:00:24.537617 1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER I0511 17:00:24.537912 1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"} I0511 17:00:24.538009 1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"} I0511 17:00:25.984404 1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe I0511 17:00:25.985686 1 utils.go:199] ID: 1 GRPC request: {} I0511 17:00:25.985743 1 utils.go:205] ID: 1 GRPC response: {} I0511 17:00:25.989856 1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo I0511 17:00:25.989962 1 utils.go:199] ID: 2 GRPC request: {} I0511 17:00:25.989977 1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo I0511 17:00:25.990036 1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0511 17:00:25.991529 1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe I0511 17:00:25.991569 1 utils.go:199] ID: 3 GRPC request: {} I0511 17:00:25.991587 1 utils.go:205] ID: 3 GRPC response: {} I0511 17:00:25.992000 1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0511 17:00:25.992060 1 utils.go:199] ID: 4 GRPC request: {} I0511 17:00:25.992190 1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0511 17:00:25.993148 1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:25.993202 1 utils.go:199] ID: 5 GRPC request: {} I0511 17:00:25.993212 1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities I0511 17:00:25.993518 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}}}]} I0511 17:00:29.531159 1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe I0511 17:00:29.531192 1 utils.go:199] ID: 6 GRPC request: {} I0511 17:00:29.531288 1 utils.go:205] ID: 6 GRPC response: {} I0511 17:00:29.535604 1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo I0511 17:00:29.535648 1 utils.go:199] ID: 7 GRPC request: {} I0511 17:00:29.535659 1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo I0511 17:00:29.535705 1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0511 17:00:29.537969 1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe I0511 17:00:29.537998 1 utils.go:199] ID: 8 GRPC request: {} I0511 17:00:29.538017 1 utils.go:205] ID: 8 GRPC response: {} I0511 17:00:29.538561 1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0511 17:00:29.538582 1 utils.go:199] ID: 9 GRPC request: {} I0511 17:00:29.538687 1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0511 17:00:29.539399 1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:29.539429 1 utils.go:199] ID: 10 GRPC request: {} I0511 17:00:29.539443 1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities I0511 17:00:29.539546 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}}}]} I0511 17:00:29.540228 1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:29.540361 1 utils.go:199] ID: 11 GRPC request: {} I0511 17:00:29.540468 1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities I0511 17:00:29.540724 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}}}]} I0511 17:00:29.541339 1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:29.541375 1 utils.go:199] ID: 12 GRPC request: {} I0511 17:00:29.541386 1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities I0511 17:00:29.541495 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}}}]} I0511 17:00:30.747240 1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo I0511 17:00:30.747279 1 utils.go:199] ID: 13 GRPC request: {} I0511 17:00:30.747294 1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo I0511 17:00:30.747330 1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0511 17:00:30.749757 1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe I0511 17:00:30.749814 1 utils.go:199] ID: 14 GRPC request: {} I0511 17:00:30.749835 1 utils.go:205] ID: 14 GRPC response: {} I0511 17:00:30.750300 1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:30.750330 1 utils.go:199] ID: 15 GRPC request: {} I0511 17:00:30.750345 1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities I0511 17:00:30.750501 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}}}]} I0511 17:00:32.022256 1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe I0511 17:00:32.022406 1 utils.go:199] ID: 16 GRPC request: {} I0511 17:00:32.022434 1 utils.go:205] ID: 16 GRPC response: {} I0511 17:00:32.031273 1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo I0511 17:00:32.031357 1 utils.go:199] ID: 17 GRPC request: {} I0511 17:00:32.031392 1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo I0511 17:00:32.031516 1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"} I0511 17:00:32.033788 1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe I0511 17:00:32.033870 1 utils.go:199] ID: 18 GRPC request: {} I0511 17:00:32.033906 1 utils.go:205] ID: 18 GRPC response: {} I0511 17:00:32.035814 1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities I0511 17:00:32.035834 1 utils.go:199] ID: 19 GRPC request: {} I0511 17:00:32.035905 1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I0511 17:00:32.038800 1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I0511 17:00:32.038821 1 utils.go:199] ID: 20 GRPC request: {} I0511 17:00:32.038828 1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities I0511 17:00:32.038957 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}}}]} I0511 17:01:32.204991 1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe I0511 17:01:32.205037 1 utils.go:199] ID: 21 GRPC request: {} I0511 17:01:32.205058 1 utils.go:205] ID: 21 GRPC response: {} I0511 17:02:32.207909 1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe I0511 17:02:32.208159 1 utils.go:199] ID: 22 GRPC request: {} I0511 17:02:32.208236 1 utils.go:205] ID: 22 GRPC response: {} I0511 17:03:32.204168 1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe I0511 17:03:32.204207 1 utils.go:199] ID: 23 GRPC request: {} I0511 17:03:32.204225 1 utils.go:205] ID: 23 GRPC response: {} I0511 17:03:40.132258 1 utils.go:198] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 GRPC call: /csi.v1.Controller/CreateVolume I0511 17:03:40.132768 1 utils.go:199] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-60461e44-4aa2-400e-bcf3-138c868b6095","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-60461e44-4aa2-400e-bcf3-138c868b6095","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}}]} I0511 17:03:40.133215 1 rbd_util.go:1315] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 setting disableInUseChecks: false image features: [layering] mounter: rbd E0511 17:03:40.148966 1 omap.go:80] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory I0511 17:03:40.165260 1 omap.go:159] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-60461e44-4aa2-400e-bcf3-138c868b6095:624608f5-8a20-4065-a022-50bd01c1ed47]) I0511 17:03:40.170594 1 omap.go:159] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 set omap keys (pool="kube", namespace="", name="csi.volume.624608f5-8a20-4065-a022-50bd01c1ed47"): map[csi.imagename:csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47 csi.volname:pvc-60461e44-4aa2-400e-bcf3-138c868b6095 csi.volume.owner:default]) I0511 17:03:40.170644 1 rbd_journal.go:491] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-624608f5-8a20-4065-a022-50bd01c1ed47) and image name (csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47) for request name (pvc-60461e44-4aa2-400e-bcf3-138c868b6095) I0511 17:03:40.170861 1 rbd_util.go:423] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 rbd: create kube/csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47 size 5120M (features: [layering]) using mon 199.204.45.116 I0511 17:03:40.171056 1 rbd_util.go:1563] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 setting image options on kube/csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47 I0511 17:03:42.021501 1 controllerserver.go:763] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 created image kube/csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47 backed for request name pvc-60461e44-4aa2-400e-bcf3-138c868b6095 I0511 17:03:42.053906 1 omap.go:159] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 set omap keys (pool="kube", namespace="", name="csi.volume.624608f5-8a20-4065-a022-50bd01c1ed47"): map[csi.imageid:37d9df8b407c]) I0511 17:03:42.136211 1 utils.go:205] ID: 24 Req-ID: pvc-60461e44-4aa2-400e-bcf3-138c868b6095 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-624608f5-8a20-4065-a022-50bd01c1ed47","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-624608f5-8a20-4065-a022-50bd01c1ed47"}}