ceph / ceph-csi

CSI driver for Ceph
Apache License 2.0
1.26k stars 536 forks source link

Persisten Volume Claim (PVC) stuck in status pending #2712

Closed pascalhobus closed 2 years ago

pascalhobus commented 2 years ago

Describe the bug

Following this guide, the PVC I want to create gets stuck at status Pending. with the following detail message Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists. I don't know how to further debug this. One thing which I found out is, that from the csi-rbdplugin-provisioner/csi-rbdplugin containers I cannot reach ceph cluster. From csi-rbdplugin/csi-rbdplugin containers I can reach the ceph cluster (see section Additional Context). I don't know if this is how it should be (?).

Environment details

The Ceph cluster is hosted on a Proxmox 7 environment. The MicroK8S nodes are running on Ubuntu 20.04 VMs on Proxmox. MicroK8S is running in HA mode (3 nodes) which means that Calico CNI is used. Enabled add-ons for microk8s are: dns, ha-cluster, ingress, metallb, metrics-server, rbac.

Steps to reproduce

Same as in this guide:

  1. having ceph cluster running
  2. having a pool created and initialized
  3. kubectl: apply configmap
  4. kubectl: apply csi rbd provisioner rbac
  5. kubectl: apply csi rbd plugin rbac
  6. kubectl: apply csi rbd provisioner
  7. kubectl: apply csi rbd plugin
  8. kubectl: apply storageclass
  9. kubectl: apply pvc

Actual results

The PVC is stuck in status pending.

Expected behavior

The PVC should be created successfully.

Additional context

When kubectl exec -i -t csi-rbdplugin-provisioner-6bbfdc7c78-5mrgq --container csi-rbdplugin -- /bin/bash, from this container I cannot reach my ceph cluster (ping does not work). My network interfaces in this container are the following:

[root@csi-rbdplugin-provisioner-6bbfdc7c78-5mrgq /]# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000 link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo valid_lft forever preferred_lft forever inet6 ::1/128 scope host valid_lft forever preferred_lft forever 3: eth0@if6: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether b2:db:e0:7a:c7:d7 brd ff:ff:ff:ff:ff:ff link-netnsid 0 inet 10.1.49.124/32 brd 10.1.49.124 scope global eth0 valid_lft forever preferred_lft forever inet6 fe80::b0db:e0ff:fe7a:c7d7/64 scope link valid_lft forever preferred_lft forever

When kubectl exec -i -t csi-rbdplugin-cfmfh --container csi-rbdplugin -- /bin/bash, from this container I can reach my ceph cluster. The network interfaces are the following (which are the same as in the host machine k8s-node-[1..3]:

[root@k8s-node-2 /]# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000 link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo valid_lft forever preferred_lft forever inet6 ::1/128 scope host valid_lft forever preferred_lft forever 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000 link/ether f6:fd:02:86:52:6a brd ff:ff:ff:ff:ff:ff inet 10.1.1.121/24 brd 10.1.1.255 scope global dynamic eth0 valid_lft 85327sec preferred_lft 85327sec inet6 fe80::f4fd:2ff:fe86:526a/64 scope link valid_lft forever preferred_lft forever 3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000 link/ether be:b0:20:76:ed:96 brd ff:ff:ff:ff:ff:ff inet 10.1.20.2/24 brd 10.1.20.255 scope global eth1 valid_lft forever preferred_lft forever inet6 fe80::bcb0:20ff:fe76:ed96/64 scope link valid_lft forever preferred_lft forever 4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000 link/ether a2:33:50:be:1c:60 brd ff:ff:ff:ff:ff:ff inet 10.1.30.102/24 brd 10.1.30.255 scope global eth2 valid_lft forever preferred_lft forever inet6 fe80::a033:50ff:febe:1c60/64 scope link valid_lft forever preferred_lft forever 5: cali9764115c7e6@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 0 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 6: cali32649d941ce@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 1 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 7: caliec969c09be2@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 2 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 8: cali7d388d3f15a@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 3 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 9: calia8ee4fac971@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 4 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 10: calia3a156c689c@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 5 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 11: cali9f48ce44cdd@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UP group default link/ether ee:ee:ee:ee:ee:ee brd ff:ff:ff:ff:ff:ff link-netnsid 6 inet6 fe80::ecee:eeff:feee:eeee/64 scope link valid_lft forever preferred_lft forever 14: vxlan.calico: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1440 qdisc noqueue state UNKNOWN group default link/ether 66:c4:b3:f6:19:0b brd ff:ff:ff:ff:ff:ff inet 10.1.80.128/32 scope global vxlan.calico valid_lft forever preferred_lft forever inet6 fe80::64c4:b3ff:fef6:190b/64 scope link valid_lft forever preferred_lft forever

Logs

If the issue is in PVC creation, deletion, cloning please attach complete logs of below containers.

csi-rbdplugin-provisioner/csi-rbdplugin

❯ kubectl logs csi-rbdplugin-provisioner-6bbfdc7c78-zzlf5 -c csi-rbdplugin I1214 08:32:38.124844 1 cephcsi.go:167] Driver version: v3.4.0 and Git version: 94ef181bc866c8ccaf507de66f213b26608309ff I1214 08:32:38.125655 1 cephcsi.go:185] Initial PID limit is set to -1 I1214 08:32:38.125910 1 cephcsi.go:191] Reconfigured PID limit to -1 (max) I1214 08:32:38.125944 1 cephcsi.go:212] Starting driver type: rbd with name: rbd.csi.ceph.com I1214 08:32:38.126587 1 driver.go:94] Enabling controller service capability: CREATE_DELETE_VOLUME I1214 08:32:38.126631 1 driver.go:94] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I1214 08:32:38.126646 1 driver.go:94] Enabling controller service capability: CLONE_VOLUME I1214 08:32:38.126661 1 driver.go:94] Enabling controller service capability: EXPAND_VOLUME I1214 08:32:38.126677 1 driver.go:106] Enabling volume access mode: SINGLE_NODE_WRITER I1214 08:32:38.126691 1 driver.go:106] Enabling volume access mode: MULTI_NODE_MULTI_WRITER I1214 08:32:38.127610 1 server.go:131] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"} I1214 08:32:38.386124 1 utils.go:176] ID: 1 GRPC call: /csi.v1.Identity/Probe I1214 08:32:38.391653 1 utils.go:180] ID: 1 GRPC request: {} I1214 08:32:38.391895 1 utils.go:187] ID: 1 GRPC response: {} I1214 08:32:38.394951 1 utils.go:176] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo I1214 08:32:38.395096 1 utils.go:180] ID: 2 GRPC request: {} I1214 08:32:38.395127 1 identityserver-default.go:38] ID: 2 Using default GetPluginInfo I1214 08:32:38.395299 1 utils.go:187] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.4.0"} I1214 08:32:38.397065 1 utils.go:176] ID: 3 GRPC call: /csi.v1.Identity/GetPluginCapabilities I1214 08:32:38.397232 1 utils.go:180] ID: 3 GRPC request: {} I1214 08:32:38.397908 1 utils.go:187] ID: 3 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I1214 08:32:38.400424 1 utils.go:176] ID: 4 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:38.400514 1 utils.go:180] ID: 4 GRPC request: {} I1214 08:32:38.400557 1 controllerserver-default.go:74] ID: 4 Using default ControllerGetCapabilities I1214 08:32:38.400999 1 utils.go:187] ID: 4 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:32:38.618393 1 utils.go:176] ID: 5 GRPC call: /csi.v1.Identity/Probe I1214 08:32:38.618540 1 utils.go:180] ID: 5 GRPC request: {} I1214 08:32:38.618599 1 utils.go:187] ID: 5 GRPC response: {} I1214 08:32:38.620886 1 utils.go:176] ID: 6 GRPC call: /csi.v1.Identity/GetPluginInfo I1214 08:32:38.621163 1 utils.go:180] ID: 6 GRPC request: {} I1214 08:32:38.621225 1 identityserver-default.go:38] ID: 6 Using default GetPluginInfo I1214 08:32:38.621301 1 utils.go:187] ID: 6 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.4.0"} I1214 08:32:38.623211 1 utils.go:176] ID: 7 GRPC call: /csi.v1.Identity/GetPluginCapabilities I1214 08:32:38.623346 1 utils.go:180] ID: 7 GRPC request: {} I1214 08:32:38.623566 1 utils.go:187] ID: 7 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I1214 08:32:38.626205 1 utils.go:176] ID: 8 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:38.626371 1 utils.go:180] ID: 8 GRPC request: {} I1214 08:32:38.626400 1 controllerserver-default.go:74] ID: 8 Using default ControllerGetCapabilities I1214 08:32:38.627110 1 utils.go:187] ID: 8 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:32:38.692072 1 utils.go:176] ID: 9 GRPC call: /csi.v1.Identity/Probe I1214 08:32:38.692243 1 utils.go:180] ID: 9 GRPC request: {} I1214 08:32:38.692362 1 utils.go:187] ID: 9 GRPC response: {} I1214 08:32:38.697750 1 utils.go:176] ID: 10 GRPC call: /csi.v1.Identity/GetPluginInfo I1214 08:32:38.697933 1 utils.go:180] ID: 10 GRPC request: {} I1214 08:32:38.697962 1 identityserver-default.go:38] ID: 10 Using default GetPluginInfo I1214 08:32:38.698042 1 utils.go:187] ID: 10 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.4.0"} I1214 08:32:38.700197 1 utils.go:176] ID: 11 GRPC call: /csi.v1.Identity/GetPluginCapabilities I1214 08:32:38.700358 1 utils.go:180] ID: 11 GRPC request: {} I1214 08:32:38.700599 1 utils.go:187] ID: 11 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I1214 08:32:38.705823 1 utils.go:176] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:38.705924 1 utils.go:180] ID: 12 GRPC request: {} I1214 08:32:38.705951 1 controllerserver-default.go:74] ID: 12 Using default ControllerGetCapabilities I1214 08:32:38.706204 1 utils.go:187] ID: 12 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:32:38.712090 1 utils.go:176] ID: 13 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:38.712190 1 utils.go:180] ID: 13 GRPC request: {} I1214 08:32:38.712216 1 controllerserver-default.go:74] ID: 13 Using default ControllerGetCapabilities I1214 08:32:38.712442 1 utils.go:187] ID: 13 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:32:39.240130 1 utils.go:176] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo I1214 08:32:39.240291 1 utils.go:180] ID: 14 GRPC request: {} I1214 08:32:39.240319 1 identityserver-default.go:38] ID: 14 Using default GetPluginInfo I1214 08:32:39.240397 1 utils.go:187] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.4.0"} I1214 08:32:39.242849 1 utils.go:176] ID: 15 GRPC call: /csi.v1.Identity/Probe I1214 08:32:39.243060 1 utils.go:180] ID: 15 GRPC request: {} I1214 08:32:39.243153 1 utils.go:187] ID: 15 GRPC response: {} I1214 08:32:39.244628 1 utils.go:176] ID: 16 GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:39.244763 1 utils.go:180] ID: 16 GRPC request: {} I1214 08:32:39.244807 1 controllerserver-default.go:74] ID: 16 Using default ControllerGetCapabilities I1214 08:32:39.245197 1 utils.go:187] ID: 16 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:33:39.187774 1 utils.go:176] ID: 17 GRPC call: /csi.v1.Identity/Probe I1214 08:33:39.187927 1 utils.go:180] ID: 17 GRPC request: {} I1214 08:33:39.187985 1 utils.go:187] ID: 17 GRPC response: {} I1214 08:34:39.187307 1 utils.go:176] ID: 18 GRPC call: /csi.v1.Identity/Probe I1214 08:34:39.187478 1 utils.go:180] ID: 18 GRPC request: {} I1214 08:34:39.187555 1 utils.go:187] ID: 18 GRPC response: {} I1214 08:35:39.188116 1 utils.go:176] ID: 19 GRPC call: /csi.v1.Identity/Probe I1214 08:35:39.189009 1 utils.go:180] ID: 19 GRPC request: {} I1214 08:35:39.189864 1 utils.go:187] ID: 19 GRPC response: {} I1214 08:36:34.832162 1 utils.go:176] ID: 20 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 08:36:34.833214 1 utils.go:180] ID: 20 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:36:34.833958 1 rbd_util.go:1109] ID: 20 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd I1214 08:36:39.186838 1 utils.go:176] ID: 21 GRPC call: /csi.v1.Identity/Probe I1214 08:36:39.187015 1 utils.go:180] ID: 21 GRPC request: {} I1214 08:36:39.187139 1 utils.go:187] ID: 21 GRPC response: {} I1214 08:37:39.186180 1 utils.go:176] ID: 22 GRPC call: /csi.v1.Identity/Probe I1214 08:37:39.186309 1 utils.go:180] ID: 22 GRPC request: {} I1214 08:37:39.186366 1 utils.go:187] ID: 22 GRPC response: {} I1214 08:38:39.186956 1 utils.go:176] ID: 23 GRPC call: /csi.v1.Identity/Probe I1214 08:38:39.187165 1 utils.go:180] ID: 23 GRPC request: {} I1214 08:38:39.187290 1 utils.go:187] ID: 23 GRPC response: {} I1214 08:39:04.849994 1 utils.go:176] ID: 24 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:04.850560 1 utils.go:180] ID: 24 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:04.852092 1 rbd_util.go:1109] ID: 24 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 08:39:04.852194 1 controllerserver.go:288] ID: 24 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 08:39:04.852302 1 utils.go:185] ID: 24 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:05.343881 1 utils.go:176] ID: 25 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:05.344415 1 utils.go:180] ID: 25 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:05.344892 1 rbd_util.go:1109] ID: 25 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 08:39:05.344977 1 controllerserver.go:288] ID: 25 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 08:39:05.345071 1 utils.go:185] ID: 25 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:07.359348 1 utils.go:176] ID: 26 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:07.359695 1 utils.go:180] ID: 26 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:07.360080 1 rbd_util.go:1109] ID: 26 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 08:39:07.360128 1 controllerserver.go:288] ID: 26 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 08:39:07.360235 1 utils.go:185] ID: 26 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists

[...]

I1214 10:35:28.491145 1 utils.go:176] ID: 178 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 10:35:28.492488 1 utils.go:180] ID: 178 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 10:35:28.493368 1 rbd_util.go:1109] ID: 178 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 10:35:28.493473 1 controllerserver.go:288] ID: 178 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 10:35:28.493631 1 utils.go:185] ID: 178 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 10:35:39.186011 1 utils.go:176] ID: 179 GRPC call: /csi.v1.Identity/Probe I1214 10:35:39.186177 1 utils.go:180] ID: 179 GRPC request: {} I1214 10:35:39.186242 1 utils.go:187] ID: 179 GRPC response: {} I1214 10:36:39.186653 1 utils.go:176] ID: 180 GRPC call: /csi.v1.Identity/Probe I1214 10:36:39.186961 1 utils.go:180] ID: 180 GRPC request: {} I1214 10:36:39.187148 1 utils.go:187] ID: 180 GRPC response: {} I1214 10:37:39.186402 1 utils.go:176] ID: 181 GRPC call: /csi.v1.Identity/Probe I1214 10:37:39.186553 1 utils.go:180] ID: 181 GRPC request: {} I1214 10:37:39.186614 1 utils.go:187] ID: 181 GRPC response: {} I1214 10:38:39.186789 1 utils.go:176] ID: 182 GRPC call: /csi.v1.Identity/Probe I1214 10:38:39.186972 1 utils.go:180] ID: 182 GRPC request: {} I1214 10:38:39.187086 1 utils.go:187] ID: 182 GRPC response: {} I1214 10:39:39.186622 1 utils.go:176] ID: 183 GRPC call: /csi.v1.Identity/Probe I1214 10:39:39.186889 1 utils.go:180] ID: 183 GRPC request: {} I1214 10:39:39.186958 1 utils.go:187] ID: 183 GRPC response: {} I1214 10:40:28.524848 1 utils.go:176] ID: 184 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 10:40:28.525394 1 utils.go:180] ID: 184 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 10:40:28.525957 1 rbd_util.go:1109] ID: 184 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 10:40:28.526085 1 controllerserver.go:288] ID: 184 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 10:40:28.526190 1 utils.go:185] ID: 184 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 10:40:39.186458 1 utils.go:176] ID: 185 GRPC call: /csi.v1.Identity/Probe I1214 10:40:39.186603 1 utils.go:180] ID: 185 GRPC request: {} I1214 10:40:39.186658 1 utils.go:187] ID: 185 GRPC response: {} I1214 10:41:39.187515 1 utils.go:176] ID: 186 GRPC call: /csi.v1.Identity/Probe I1214 10:41:39.187769 1 utils.go:180] ID: 186 GRPC request: {} I1214 10:41:39.187965 1 utils.go:187] ID: 186 GRPC response: {} I1214 10:42:39.186338 1 utils.go:176] ID: 187 GRPC call: /csi.v1.Identity/Probe I1214 10:42:39.186547 1 utils.go:180] ID: 187 GRPC request: {} I1214 10:42:39.186641 1 utils.go:187] ID: 187 GRPC response: {} I1214 10:43:39.186812 1 utils.go:176] ID: 188 GRPC call: /csi.v1.Identity/Probe I1214 10:43:39.187005 1 utils.go:180] ID: 188 GRPC request: {} I1214 10:43:39.187102 1 utils.go:187] ID: 188 GRPC response: {} I1214 10:44:39.186080 1 utils.go:176] ID: 189 GRPC call: /csi.v1.Identity/Probe I1214 10:44:39.186230 1 utils.go:180] ID: 189 GRPC request: {} I1214 10:44:39.186291 1 utils.go:187] ID: 189 GRPC response: {} I1214 10:45:28.554207 1 utils.go:176] ID: 190 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 10:45:28.554862 1 utils.go:180] ID: 190 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 10:45:28.555395 1 rbd_util.go:1109] ID: 190 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 10:45:28.555474 1 controllerserver.go:288] ID: 190 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 10:45:28.555578 1 utils.go:185] ID: 190 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 10:45:39.186624 1 utils.go:176] ID: 191 GRPC call: /csi.v1.Identity/Probe I1214 10:45:39.186827 1 utils.go:180] ID: 191 GRPC request: {} I1214 10:45:39.186892 1 utils.go:187] ID: 191 GRPC response: {} I1214 10:46:39.186645 1 utils.go:176] ID: 192 GRPC call: /csi.v1.Identity/Probe I1214 10:46:39.186827 1 utils.go:180] ID: 192 GRPC request: {} I1214 10:46:39.186927 1 utils.go:187] ID: 192 GRPC response: {} I1214 10:47:39.187228 1 utils.go:176] ID: 193 GRPC call: /csi.v1.Identity/Probe I1214 10:47:39.187440 1 utils.go:180] ID: 193 GRPC request: {} I1214 10:47:39.187529 1 utils.go:187] ID: 193 GRPC response: {} I1214 10:47:58.420798 1 utils.go:176] ID: 194 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC call: /csi.v1.Controller/CreateVolume I1214 10:47:58.421328 1 utils.go:180] ID: 194 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 10:47:58.421907 1 rbd_util.go:1109] ID: 194 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 setting disableInUseChecks: false image features: [layering] mounter: rbd E1214 10:47:58.422023 1 controllerserver.go:288] ID: 194 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists E1214 10:47:58.422161 1 utils.go:185] ID: 194 Req-ID: pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists

csi-rbdplugin-provisioner/csi-provisioner

W1214 08:32:35.600062 1 feature_gate.go:235] Setting GA feature gate Topology=false. It will be removed in a future release. I1214 08:32:35.600418 1 feature_gate.go:243] feature gates: &{map[Topology:false]} I1214 08:32:35.600533 1 csi-provisioner.go:138] Version: v2.2.2 I1214 08:32:35.600606 1 csi-provisioner.go:161] Building kube configs for running in cluster... I1214 08:32:35.646577 1 connection.go:153] Connecting to unix:///csi/csi-provisioner.sock I1214 08:32:38.603110 1 common.go:111] Probing CSI driver for readiness I1214 08:32:38.603217 1 connection.go:182] GRPC call: /csi.v1.Identity/Probe I1214 08:32:38.603237 1 connection.go:183] GRPC request: {} I1214 08:32:38.619610 1 connection.go:185] GRPC response: {} I1214 08:32:38.619994 1 connection.go:186] GRPC error: I1214 08:32:38.620071 1 connection.go:182] GRPC call: /csi.v1.Identity/GetPluginInfo I1214 08:32:38.620088 1 connection.go:183] GRPC request: {} I1214 08:32:38.622049 1 connection.go:185] GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.4.0"} I1214 08:32:38.622358 1 connection.go:186] GRPC error: I1214 08:32:38.622402 1 csi-provisioner.go:212] Detected CSI driver rbd.csi.ceph.com I1214 08:32:38.622471 1 connection.go:182] GRPC call: /csi.v1.Identity/GetPluginCapabilities I1214 08:32:38.622499 1 connection.go:183] GRPC request: {} I1214 08:32:38.624586 1 connection.go:185] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]} I1214 08:32:38.625180 1 connection.go:186] GRPC error: I1214 08:32:38.625209 1 connection.go:182] GRPC call: /csi.v1.Controller/ControllerGetCapabilities I1214 08:32:38.625223 1 connection.go:183] GRPC request: {} I1214 08:32:38.629362 1 connection.go:185] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]} I1214 08:32:38.631003 1 connection.go:186] GRPC error: I1214 08:32:38.631426 1 csi-provisioner.go:284] CSI driver does not support PUBLISH_UNPUBLISH_VOLUME, not watching VolumeAttachments I1214 08:32:38.633698 1 controller.go:756] Using saving PVs to API server in background I1214 08:32:38.639342 1 leaderelection.go:243] attempting to acquire leader lease default/rbd-csi-ceph-com... I1214 08:32:38.669895 1 leaderelection.go:346] lock is held by csi-rbdplugin-provisioner-67477fd968-vkz7q and has not yet expired I1214 08:32:38.669997 1 leaderelection.go:248] failed to acquire lease default/rbd-csi-ceph-com I1214 08:32:38.670101 1 leader_election.go:212] new leader detected, current leader: csi-rbdplugin-provisioner-67477fd968-vkz7q I1214 08:32:49.333413 1 leaderelection.go:346] lock is held by csi-rbdplugin-provisioner-67477fd968-vkz7q and has not yet expired I1214 08:32:49.333505 1 leaderelection.go:248] failed to acquire lease default/rbd-csi-ceph-com I1214 08:32:58.372435 1 leaderelection.go:253] successfully acquired lease default/rbd-csi-ceph-com I1214 08:32:58.373082 1 leader_election.go:205] became leader, starting I1214 08:32:58.373265 1 leader_election.go:212] new leader detected, current leader: csi-rbdplugin-provisioner-6bbfdc7c78-zzlf5 I1214 08:32:58.376841 1 reflector.go:219] Starting reflector v1.PersistentVolumeClaim (15m0s) from k8s.io/client-go/informers/factory.go:134 I1214 08:32:58.376924 1 reflector.go:255] Listing and watching v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134 I1214 08:32:58.377940 1 reflector.go:219] Starting reflector v1.StorageClass (1h0m0s) from k8s.io/client-go/informers/factory.go:134 I1214 08:32:58.377970 1 reflector.go:255] Listing and watching v1.StorageClass from k8s.io/client-go/informers/factory.go:134 I1214 08:32:58.451477 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:32:58.473972 1 shared_informer.go:270] caches populated I1214 08:32:58.474019 1 shared_informer.go:270] caches populated I1214 08:32:58.474091 1 controller.go:835] Starting provisioner controller rbd.csi.ceph.com_csi-rbdplugin-provisioner-6bbfdc7c78-zzlf5_5a6db88e-2d30-4527-83cd-8f4a8db96274! I1214 08:32:58.474147 1 clone_controller.go:66] Starting CloningProtection controller I1214 08:32:58.474215 1 volume_store.go:97] Starting save volume queue I1214 08:32:58.474294 1 clone_controller.go:84] Started CloningProtection controller I1214 08:32:58.474481 1 reflector.go:219] Starting reflector v1.PersistentVolume (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:869 I1214 08:32:58.474522 1 reflector.go:255] Listing and watching v1.PersistentVolume from sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:869 I1214 08:32:58.474714 1 reflector.go:219] Starting reflector v1.PersistentVolumeClaim (15m0s) from pkg/controller/clone_controller.go:82 I1214 08:32:58.474804 1 reflector.go:255] Listing and watching v1.PersistentVolumeClaim from pkg/controller/clone_controller.go:82 I1214 08:32:58.475229 1 reflector.go:219] Starting reflector v1.StorageClass (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:872 I1214 08:32:58.475260 1 reflector.go:255] Listing and watching v1.StorageClass from sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:872 I1214 08:32:58.575183 1 shared_informer.go:270] caches populated I1214 08:32:58.576096 1 controller.go:884] Started provisioner controller rbd.csi.ceph.com_csi-rbdplugin-provisioner-6bbfdc7c78-zzlf5_5a6db88e-2d30-4527-83cd-8f4a8db96274! I1214 08:33:03.515377 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:08.583852 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:13.639663 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:18.706963 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:23.761330 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:28.828250 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:33.890062 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:38.948587 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:44.002498 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:49.079874 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:54.162832 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:33:59.219988 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:04.283105 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:09.372198 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:14.431004 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:19.506633 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:24.570259 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:29.629344 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:34.698995 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:39.754109 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:44.801713 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:49.862556 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:34:54.954298 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:00.016965 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:05.084173 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:10.146006 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:15.285411 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:20.356796 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:25.460165 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:30.538165 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:35.590025 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:40.697904 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:45.750181 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:50.795242 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:35:55.866878 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:00.925588 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:06.080348 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:11.127171 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:16.192990 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:21.247495 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:26.295814 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:31.360077 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:34.781187 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:36:34.782554 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:36:34.821662 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:36:34.821760 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:36:36.401549 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:41.453411 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:46.506169 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:51.558507 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:36:56.609371 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:01.672394 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:06.748073 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:11.827711 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:16.905400 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:21.974168 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:27.045800 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:32.114006 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:37.179034 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:42.235405 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:47.291376 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:52.350466 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:37:57.452852 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:02.530900 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:07.585362 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:12.653888 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:17.481760 1 reflector.go:530] pkg/controller/clone_controller.go:82: Watch close - v1.PersistentVolumeClaim total 2 items received I1214 08:38:17.745299 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:22.841728 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:27.498781 1 reflector.go:530] sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:869: Watch close - v1.PersistentVolume total 0 items received I1214 08:38:27.907048 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:32.985423 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:38.047051 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:43.120047 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:44.481874 1 reflector.go:530] sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller/controller.go:872: Watch close - *v1.StorageClass total 7 items received I1214 08:38:48.203609 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:53.296128 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:38:58.348203 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:03.407053 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:04.823423 1 connection.go:185] GRPC response: {} I1214 08:39:04.824553 1 connection.go:186] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded I1214 08:39:04.825477 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = DeadlineExceeded desc = context deadline exceeded I1214 08:39:04.825786 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:04.825876 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 0 E1214 08:39:04.826000 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded I1214 08:39:04.826328 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:04.827511 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded I1214 08:39:04.827918 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:04.846039 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:04.846119 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:04.852899 1 connection.go:185] GRPC response: {} I1214 08:39:04.852982 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:04.853059 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:04.853147 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:04.853200 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 1 E1214 08:39:04.853249 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:04.853455 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:05.327062 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:05.328679 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:05.342031 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:05.342098 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:05.345530 1 connection.go:185] GRPC response: {} I1214 08:39:05.345682 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:05.345790 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:05.345895 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:05.345950 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 2 E1214 08:39:05.346006 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:05.346104 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:07.346462 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:07.347096 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:07.357689 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:07.357741 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:07.360704 1 connection.go:185] GRPC response: {} I1214 08:39:07.360779 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:07.360834 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:07.360950 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:07.360984 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 3 E1214 08:39:07.361033 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:07.361080 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:08.458777 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:11.362392 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:11.362980 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:11.384233 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:11.384321 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:11.389183 1 connection.go:185] GRPC response: {} I1214 08:39:11.389284 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:11.389348 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:11.389448 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:11.389502 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 4 E1214 08:39:11.389555 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:11.389609 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:13.524391 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:18.597169 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:19.389791 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:19.390464 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:19.409200 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:19.409268 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:19.412218 1 connection.go:185] GRPC response: {} I1214 08:39:19.412291 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:19.412344 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:19.412411 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:19.412440 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 5 E1214 08:39:19.412484 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:19.412552 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:23.664148 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:28.746830 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:33.841188 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:35.413032 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:39:35.413946 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:39:35.424405 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:39:35.424477 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:39:35.427611 1 connection.go:185] GRPC response: {} I1214 08:39:35.427960 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:35.428178 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:35.428561 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:39:35.428969 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 6 E1214 08:39:35.429195 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:35.428858 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:39:38.916253 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:44.002040 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:49.081503 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:54.162103 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:39:59.255262 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:04.328183 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:05.393240 1 reflector.go:530] k8s.io/client-go/informers/factory.go:134: Watch close - *v1.StorageClass total 10 items received I1214 08:40:07.429553 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:40:07.431443 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:40:07.447637 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:40:07.447709 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:40:07.450449 1 connection.go:185] GRPC response: {} I1214 08:40:07.450535 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:40:07.450608 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:40:07.450684 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:40:07.450801 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 7 E1214 08:40:07.450852 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:40:07.450953 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:40:09.385075 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:14.444528 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:19.667219 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:24.903412 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:29.981421 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:35.048704 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:40.104115 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:45.199547 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:50.363241 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:40:55.516966 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:00.588365 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:05.647086 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:10.692924 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:11.451281 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:41:11.452257 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:41:11.470023 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:41:11.470125 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:41:11.473067 1 connection.go:185] GRPC response: {} I1214 08:41:11.473176 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:41:11.473276 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:41:11.473368 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:41:11.473401 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 8 E1214 08:41:11.473476 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:41:11.473549 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:41:15.751652 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:20.807461 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:24.395340 1 reflector.go:530] k8s.io/client-go/informers/factory.go:134: Watch close - *v1.PersistentVolumeClaim total 2 items received I1214 08:41:25.864629 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:30.914194 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:35.974426 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:41.036456 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:46.093128 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:51.143134 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:41:56.222003 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:01.275599 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:06.374609 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:11.428808 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:16.472624 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:21.515952 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:26.580310 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:31.655660 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:36.734550 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:41.825117 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:46.975900 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:52.043579 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:42:57.103873 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:02.190375 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:07.248993 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:12.291553 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:17.341963 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:19.474636 1 controller.go:1332] provision "default/raw-block-pvc" class "csi-rbd-sc": started I1214 08:43:19.478569 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/raw-block-pvc" I1214 08:43:19.497292 1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume I1214 08:43:19.497391 1 connection.go:183] GRPC request: {"capacity_range":{"required_bytes":1073741824},"name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","parameters":{"clusterID":"d2383c4d-1fad-4701-90d9-b5079b403737","csi.storage.k8s.io/pv/name":"pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5","csi.storage.k8s.io/pvc/name":"raw-block-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"mycluster-hdd"},"secrets":"stripped","volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":1}}]} I1214 08:43:19.503509 1 connection.go:185] GRPC response: {} I1214 08:43:19.503644 1 connection.go:186] GRPC error: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:43:19.503832 1 controller.go:753] CreateVolume failed, supports topology = false, node selected false => may reschedule = false => state = Background: rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:43:19.504150 1 controller.go:1106] Temporary error received, adding PVC 55b22d71-055e-4f23-9e61-7386e4cde6c5 to claims in progress W1214 08:43:19.504288 1 controller.go:958] Retrying syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5", failure 9 E1214 08:43:19.504464 1 controller.go:981] error syncing claim "55b22d71-055e-4f23-9e61-7386e4cde6c5": failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:43:19.504608 1 event.go:282] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"raw-block-pvc", UID:"55b22d71-055e-4f23-9e61-7386e4cde6c5", APIVersion:"v1", ResourceVersion:"17149191", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-rbd-sc": rpc error: code = Aborted desc = an operation with the given Volume ID pvc-55b22d71-055e-4f23-9e61-7386e4cde6c5 already exists I1214 08:43:22.396710 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:27.441252 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:32.493891 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:37.545747 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:42.650254 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:47.698674 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:52.790565 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com I1214 08:43:57.882413 1 leaderelection.go:273] successfully renewed lease default/rbd-csi-ceph-com [...]

If the issue is in PVC resize please attach complete logs of below containers.

If the issue is in snapshot creation and deletion please attach complete logs of below containers.

If the issue is in PVC mounting please attach complete logs of below containers.

dmesg of csi-rbdplugin-provisioner-6bbfdc7c78-5mrgq/csi-rbdplugin

[root@csi-rbdplugin-provisioner-6bbfdc7c78-5mrgq /]# dmesg [ 0.000000] Linux version 5.4.0-91-generic (buildd@lcy01-amd64-017) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #102-Ubuntu SMP Fri Nov 5 16:31:28 UTC 2021 (Ubuntu 5.4.0-91.102-generic 5.4.151) [ 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-5.4.0-91-generic root=UUID=519ebb83-6f64-4303-82cd-394f96cf8612 ro console=tty1 console=ttyS0 [ 0.000000] KERNEL supported cpus: [ 0.000000] Intel GenuineIntel [ 0.000000] AMD AuthenticAMD [ 0.000000] Hygon HygonGenuine [ 0.000000] Centaur CentaurHauls [ 0.000000] zhaoxin Shanghai [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'

[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format. [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffd9fff] usable [ 0.000000] BIOS-e820: [mem 0x00000000bffda000-0x00000000bfffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved [ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000023fffffff] usable [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] SMBIOS 2.8 present. [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014 [ 0.000000] Hypervisor detected: KVM [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00 [ 0.000001] kvm-clock: cpu 0, msr 143401001, primary cpu clock [ 0.000001] kvm-clock: using sched offset of 524036270569704 cycles [ 0.000010] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns [ 0.000016] tsc: Detected 2593.750 MHz processor [ 0.003094] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved [ 0.003096] e820: remove [mem 0x000a0000-0x000fffff] usable [ 0.003103] last_pfn = 0x240000 max_arch_pfn = 0x400000000 [ 0.003145] MTRR default type: write-back [ 0.003146] MTRR fixed ranges enabled: [ 0.003148] 00000-9FFFF write-back [ 0.003149] A0000-BFFFF uncachable [ 0.003150] C0000-FFFFF write-protect [ 0.003151] MTRR variable ranges enabled: [ 0.003152] 0 base 00C0000000 mask FFC0000000 uncachable [ 0.003153] 1 disabled [ 0.003153] 2 disabled [ 0.003154] 3 disabled [ 0.003154] 4 disabled [ 0.003155] 5 disabled [ 0.003155] 6 disabled [ 0.003156] 7 disabled [ 0.003177] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT [ 0.003197] last_pfn = 0xbffda max_arch_pfn = 0x400000000 [ 0.015352] found SMP MP-table at [mem 0x000f5a70-0x000f5a7f] [ 0.015552] check: Scanning 1 areas for low memory corruption [ 0.015988] RAMDISK: [mem 0x34aef000-0x3656efff] [ 0.015999] ACPI: Early table checksum verification disabled [ 0.016024] ACPI: RSDP 0x00000000000F5870 000014 (v00 BOCHS ) [ 0.016035] ACPI: RSDT 0x00000000BFFE2035 00003C (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016115] ACPI: FACP 0x00000000BFFE1D1F 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016125] ACPI: DSDT 0x00000000BFFDF040 002CDF (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016134] ACPI: FACS 0x00000000BFFDF000 000040 [ 0.016139] ACPI: APIC 0x00000000BFFE1D93 000090 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016145] ACPI: SSDT 0x00000000BFFE1E23 0000CA (v01 BOCHS VMGENID 00000001 BXPC 00000001) [ 0.016150] ACPI: HPET 0x00000000BFFE1EED 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016155] ACPI: SRAT 0x00000000BFFE1F25 0000E8 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016160] ACPI: WAET 0x00000000BFFE200D 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.016165] ACPI: Reserving FACP table memory at [mem 0xbffe1d1f-0xbffe1d92] [ 0.016167] ACPI: Reserving DSDT table memory at [mem 0xbffdf040-0xbffe1d1e] [ 0.016168] ACPI: Reserving FACS table memory at [mem 0xbffdf000-0xbffdf03f] [ 0.016169] ACPI: Reserving APIC table memory at [mem 0xbffe1d93-0xbffe1e22] [ 0.016170] ACPI: Reserving SSDT table memory at [mem 0xbffe1e23-0xbffe1eec] [ 0.016171] ACPI: Reserving HPET table memory at [mem 0xbffe1eed-0xbffe1f24] [ 0.016172] ACPI: Reserving SRAT table memory at [mem 0xbffe1f25-0xbffe200c] [ 0.016173] ACPI: Reserving WAET table memory at [mem 0xbffe200d-0xbffe2034] [ 0.016211] ACPI: Local APIC address 0xfee00000 [ 0.016281] SRAT: PXM 0 -> APIC 0x00 -> Node 0 [ 0.016282] SRAT: PXM 0 -> APIC 0x01 -> Node 0 [ 0.016283] SRAT: PXM 0 -> APIC 0x02 -> Node 0 [ 0.016284] SRAT: PXM 0 -> APIC 0x03 -> Node 0 [ 0.016290] ACPI: SRAT: Node 0 PXM 0 [mem 0x00000000-0x0009ffff] [ 0.016292] ACPI: SRAT: Node 0 PXM 0 [mem 0x00100000-0xbfffffff] [ 0.016293] ACPI: SRAT: Node 0 PXM 0 [mem 0x100000000-0x23fffffff] [ 0.016298] NUMA: Node 0 [mem 0x00000000-0x0009ffff] + [mem 0x00100000-0xbfffffff] -> [mem 0x00000000-0xbfffffff] [ 0.016300] NUMA: Node 0 [mem 0x00000000-0xbfffffff] + [mem 0x100000000-0x23fffffff] -> [mem 0x00000000-0x23fffffff] [ 0.016314] NODE_DATA(0) allocated [mem 0x23ffd1000-0x23fffbfff] [ 0.016651] Zone ranges: [ 0.016653] DMA [mem 0x0000000000001000-0x0000000000ffffff] [ 0.016654] DMA32 [mem 0x0000000001000000-0x00000000ffffffff] [ 0.016656] Normal [mem 0x0000000100000000-0x000000023fffffff] [ 0.016657] Device empty [ 0.016658] Movable zone start for each node [ 0.016662] Early memory node ranges [ 0.016663] node 0: [mem 0x0000000000001000-0x000000000009efff] [ 0.016665] node 0: [mem 0x0000000000100000-0x00000000bffd9fff] [ 0.016667] node 0: [mem 0x0000000100000000-0x000000023fffffff] [ 0.016685] Zeroed struct page in unavailable ranges: 136 pages [ 0.016687] Initmem setup node 0 [mem 0x0000000000001000-0x000000023fffffff] [ 0.016690] On node 0 totalpages: 2097016 [ 0.016694] DMA zone: 64 pages used for memmap [ 0.016694] DMA zone: 21 pages reserved [ 0.016695] DMA zone: 3998 pages, LIFO batch:0 [ 0.016800] DMA32 zone: 12224 pages used for memmap [ 0.016801] DMA32 zone: 782298 pages, LIFO batch:63 [ 0.035373] Normal zone: 20480 pages used for memmap [ 0.035376] Normal zone: 1310720 pages, LIFO batch:63 [ 0.063368] ACPI: PM-Timer IO Port: 0x608 [ 0.063378] ACPI: Local APIC address 0xfee00000 [ 0.063409] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.063490] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 [ 0.063495] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.063498] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.063499] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.063501] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.063503] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.063506] ACPI: IRQ0 used by override. [ 0.063507] ACPI: IRQ5 used by override. [ 0.063507] ACPI: IRQ9 used by override. [ 0.063508] ACPI: IRQ10 used by override. [ 0.063509] ACPI: IRQ11 used by override. [ 0.063512] Using ACPI (MADT) for SMP configuration information [ 0.063515] ACPI: HPET id: 0x8086a201 base: 0xfed00000 [ 0.063528] TSC deadline timer available [ 0.063531] smpboot: Allowing 4 CPUs, 0 hotplug CPUs [ 0.063571] PM: Registered nosave memory: [mem 0x00000000-0x00000fff] [ 0.063573] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] [ 0.063574] PM: Registered nosave memory: [mem 0x000a0000-0x000effff] [ 0.063575] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff] [ 0.063577] PM: Registered nosave memory: [mem 0xbffda000-0xbfffffff] [ 0.063578] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff] [ 0.063579] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff] [ 0.063580] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff] [ 0.063581] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff] [ 0.063585] [mem 0xc0000000-0xfeffbfff] available for PCI devices [ 0.063586] Booting paravirtualized kernel on KVM [ 0.063597] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns [ 0.063605] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 [ 0.064466] percpu: Embedded 55 pages/cpu s188416 r8192 d28672 u524288 [ 0.064473] pcpu-alloc: s188416 r8192 d28672 u524288 alloc=1*2097152 [ 0.064474] pcpu-alloc: [0] 0 1 2 3 [ 0.064531] setup async PF for cpu 0 [ 0.064539] kvm-stealtime: cpu 0, msr 237a2d040 [ 0.064550] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear) [ 0.064562] Built 1 zonelists, mobility grouping on. Total pages: 2064227 [ 0.064564] Policy zone: Normal [ 0.064566] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.4.0-91-generic root=UUID=519ebb83-6f64-4303-82cd-394f96cf8612 ro console=tty1 console=ttyS0 [ 0.067195] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) [ 0.067989] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.068107] mem auto-init: stack:off, heap alloc:on, heap free:off [ 0.090178] Calgary: detecting Calgary via BIOS EBDA area [ 0.090182] Calgary: Unable to locate Rio Grande table in EBDA - bailing! [ 0.116273] Memory: 8117620K/8388064K available (14339K kernel code, 2400K rwdata, 5020K rodata, 2736K init, 4964K bss, 270444K reserved, 0K cma-reserved) [ 0.116297] random: get_random_u64 called from kmem_cache_open+0x2d/0x410 with crng_init=0 [ 0.116465] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.116493] Kernel/User page tables isolation: enabled [ 0.116540] ftrace: allocating 44628 entries in 175 pages [ 0.138397] rcu: Hierarchical RCU implementation. [ 0.138400] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4. [ 0.138401] Tasks RCU enabled. [ 0.138403] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. [ 0.138404] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.141713] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 [ 0.162728] Console: colour VGA+ 80x25 [ 0.230728] printk: console [tty1] enabled [ 0.347046] printk: console [ttyS0] enabled [ 0.348030] ACPI: Core revision 20190816 [ 0.349150] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns [ 0.351147] APIC: Switch to symmetric I/O mode setup [ 0.352672] x2apic enabled [ 0.353776] Switched APIC routing to physical x2apic. [ 0.356566] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.357817] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x25632c21275, max_idle_ns: 440795290422 ns [ 0.359946] Calibrating delay loop (skipped) preset value.. 5187.50 BogoMIPS (lpj=10375000) [ 0.361670] pid_max: default: 32768 minimum: 301 [ 0.362688] LSM: Security Framework initializing [ 0.363960] Yama: becoming mindful. [ 0.364808] AppArmor: AppArmor initialized [ 0.365763] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.367349] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.367967] VALIDATE tmpfs [ 0.368944] VALIDATE proc [ 0.369810] VALIDATE cgroup1 [ 0.371946] VALIDATE cgroup2 [ 0.372962] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.374069] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.375269] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization [ 0.375944] Spectre V2 : Mitigation: Full generic retpoline [ 0.377074] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch [ 0.379943] Speculative Store Bypass: Vulnerable [ 0.380915] MDS: Vulnerable: Clear CPU buffers attempted, no microcode [ 0.382457] Freeing SMP alternatives memory: 40K [ 0.386382] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (family: 0x6, model: 0x2a, stepping: 0x1) [ 0.387940] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only. [ 0.387940] rcu: Hierarchical SRCU implementation. [ 0.388676] NMI watchdog: Perf NMI watchdog permanently disabled [ 0.390043] smp: Bringing up secondary CPUs ... [ 0.391192] x86: Booting SMP configuration: [ 0.391949] .... node #0, CPUs: #1 [ 0.214034] kvm-clock: cpu 1, msr 143401041, secondary cpu clock [ 0.395648] setup async PF for cpu 1 [ 0.395940] kvm-stealtime: cpu 1, msr 237aad040 [ 0.400154] #2 [ 0.214034] kvm-clock: cpu 2, msr 143401081, secondary cpu clock [ 0.403970] setup async PF for cpu 2 [ 0.406916] kvm-stealtime: cpu 2, msr 237b2d040 [ 0.408137] #3 [ 0.214034] kvm-clock: cpu 3, msr 1434010c1, secondary cpu clock [ 0.410670] setup async PF for cpu 3 [ 0.411940] kvm-stealtime: cpu 3, msr 237bad040 [ 0.420076] smp: Brought up 1 node, 4 CPUs [ 0.420998] smpboot: Max logical packages: 1 [ 0.421904] smpboot: Total of 4 processors activated (20750.00 BogoMIPS) [ 0.424150] devtmpfs: initialized [ 0.424780] x86/mm: Memory block size: 128MB [ 0.426669] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.427967] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.429447] pinctrl core: initialized pinctrl subsystem [ 0.430752] PM: RTC time: 11:07:00, date: 2021-12-14 [ 0.432078] NET: Registered protocol family 16 [ 0.433151] audit: initializing netlink subsys (disabled) [ 0.434277] audit: type=2000 audit(1639480019.615:1): state=initialized audit_enabled=0 res=1 [ 0.434277] EISA bus registered [ 0.436801] cpuidle: using governor ladder [ 0.437827] cpuidle: using governor menu [ 0.438963] ACPI: bus type PCI registered [ 0.439955] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 [ 0.441676] PCI: Using configuration type 1 for base access [ 0.445710] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 0.452164] ACPI: Added _OSI(Module Device) [ 0.455957] ACPI: Added _OSI(Processor Device) [ 0.457828] ACPI: Added _OSI(3.0 _SCP Extensions) [ 0.459937] ACPI: Added _OSI(Processor Aggregator Device) [ 0.459953] ACPI: Added _OSI(Linux-Dell-Video) [ 0.461957] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio) [ 0.463952] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics) [ 0.471395] ACPI: 2 ACPI AML tables successfully acquired and loaded [ 0.478206] ACPI: Interpreter enabled [ 0.479996] ACPI: (supports S0 S3 S4 S5) [ 0.481629] ACPI: Using IOAPIC for interrupt routing [ 0.483868] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.484447] ACPI: Enabled 3 GPEs in block 00 to 0F [ 0.500886] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.503549] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] [ 0.507988] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. [ 0.512758] acpiphp: Slot [3] registered [ 0.514660] acpiphp: Slot [4] registered [ 0.516012] acpiphp: Slot [5] registered [ 0.517928] acpiphp: Slot [6] registered [ 0.519807] acpiphp: Slot [7] registered [ 0.524019] acpiphp: Slot [8] registered [ 0.525915] acpiphp: Slot [9] registered [ 0.527805] acpiphp: Slot [10] registered [ 0.528014] acpiphp: Slot [11] registered [ 0.529962] acpiphp: Slot [12] registered [ 0.531912] acpiphp: Slot [13] registered [ 0.536024] acpiphp: Slot [14] registered [ 0.537963] acpiphp: Slot [15] registered [ 0.539897] acpiphp: Slot [16] registered [ 0.540013] acpiphp: Slot [17] registered [ 0.541939] acpiphp: Slot [18] registered [ 0.543644] acpiphp: Slot [19] registered [ 0.544020] acpiphp: Slot [20] registered [ 0.545669] acpiphp: Slot [21] registered [ 0.547272] acpiphp: Slot [22] registered [ 0.552012] acpiphp: Slot [23] registered [ 0.553667] acpiphp: Slot [24] registered [ 0.555579] acpiphp: Slot [25] registered [ 0.556022] acpiphp: Slot [26] registered [ 0.558372] acpiphp: Slot [27] registered [ 0.560034] acpiphp: Slot [28] registered [ 0.561945] acpiphp: Slot [29] registered [ 0.564001] PCI host bridge to bus 0000:00 [ 0.565905] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] [ 0.567960] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] [ 0.570797] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] [ 0.575953] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window] [ 0.579207] pci_bus 0000:00: root bus resource [mem 0x240000000-0x2bfffffff window] [ 0.579953] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.582456] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 [ 0.586189] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 [ 0.593860] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 [ 0.604893] pci 0000:00:01.1: reg 0x20: [io 0xe100-0xe10f] [ 0.609819] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] [ 0.611954] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] [ 0.614736] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] [ 0.619955] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] [ 0.623247] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 [ 0.630506] pci 0000:00:01.2: reg 0x20: [io 0xe080-0xe09f] [ 0.635572] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 [ 0.641413] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.643980] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 0.648171] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 [ 0.657247] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref] [ 0.664006] pci 0000:00:02.0: reg 0x18: [mem 0xfead0000-0xfead0fff] [ 0.680018] pci 0000:00:02.0: reg 0x30: [mem 0xfeac0000-0xfeacffff pref] [ 0.683701] pci 0000:00:03.0: [1af4:1002] type 00 class 0x00ff00 [ 0.685008] pci 0000:00:03.0: reg 0x10: [io 0xe000-0xe03f] [ 0.690610] pci 0000:00:03.0: reg 0x20: [mem 0xfe400000-0xfe403fff 64bit pref] [ 0.694356] pci 0000:00:05.0: [1af4:1004] type 00 class 0x010000 [ 0.696731] pci 0000:00:05.0: reg 0x10: [io 0xe040-0xe07f] [ 0.699395] pci 0000:00:05.0: reg 0x14: [mem 0xfead1000-0xfead1fff] [ 0.707950] pci 0000:00:05.0: reg 0x20: [mem 0xfe404000-0xfe407fff 64bit pref] [ 0.717310] pci 0000:00:12.0: [1af4:1000] type 00 class 0x020000 [ 0.719904] pci 0000:00:12.0: reg 0x10: [io 0xe0a0-0xe0bf] [ 0.721124] pci 0000:00:12.0: reg 0x14: [mem 0xfead2000-0xfead2fff] [ 0.726959] pci 0000:00:12.0: reg 0x20: [mem 0xfe408000-0xfe40bfff 64bit pref] [ 0.729173] pci 0000:00:12.0: reg 0x30: [mem 0xfea00000-0xfea3ffff pref] [ 0.731797] pci 0000:00:13.0: [1af4:1000] type 00 class 0x020000 [ 0.735068] pci 0000:00:13.0: reg 0x10: [io 0xe0c0-0xe0df] [ 0.737120] pci 0000:00:13.0: reg 0x14: [mem 0xfead3000-0xfead3fff] [ 0.741816] pci 0000:00:13.0: reg 0x20: [mem 0xfe40c000-0xfe40ffff 64bit pref] [ 0.747948] pci 0000:00:13.0: reg 0x30: [mem 0xfea40000-0xfea7ffff pref] [ 0.752301] pci 0000:00:14.0: [1af4:1000] type 00 class 0x020000 [ 0.754896] pci 0000:00:14.0: reg 0x10: [io 0xe0e0-0xe0ff] [ 0.757128] pci 0000:00:14.0: reg 0x14: [mem 0xfead4000-0xfead4fff] [ 0.762276] pci 0000:00:14.0: reg 0x20: [mem 0xfe410000-0xfe413fff 64bit pref] [ 0.764603] pci 0000:00:14.0: reg 0x30: [mem 0xfea80000-0xfeabffff pref] [ 0.769338] pci 0000:00:1e.0: [1b36:0001] type 01 class 0x060400 [ 0.772880] pci 0000:00:1e.0: reg 0x10: [mem 0xfead5000-0xfead50ff 64bit] [ 0.776646] pci 0000:00:1f.0: [1b36:0001] type 01 class 0x060400 [ 0.779387] pci 0000:00:1f.0: reg 0x10: [mem 0xfead6000-0xfead60ff 64bit] [ 0.782853] pci_bus 0000:01: extended config space not accessible [ 0.784339] acpiphp: Slot [0] registered [ 0.785218] acpiphp: Slot [1] registered [ 0.786112] acpiphp: Slot [2] registered [ 0.786986] acpiphp: Slot [3-2] registered [ 0.787893] acpiphp: Slot [4-2] registered [ 0.787978] acpiphp: Slot [5-2] registered [ 0.788887] acpiphp: Slot [6-2] registered [ 0.790442] acpiphp: Slot [7-2] registered [ 0.791360] acpiphp: Slot [8-2] registered [ 0.792003] acpiphp: Slot [9-2] registered [ 0.792926] acpiphp: Slot [10-2] registered [ 0.793842] acpiphp: Slot [11-2] registered [ 0.794756] acpiphp: Slot [12-2] registered [ 0.795678] acpiphp: Slot [13-2] registered [ 0.795990] acpiphp: Slot [14-2] registered [ 0.796913] acpiphp: Slot [15-2] registered [ 0.797831] acpiphp: Slot [16-2] registered [ 0.798752] acpiphp: Slot [17-2] registered [ 0.799678] acpiphp: Slot [18-2] registered [ 0.803983] acpiphp: Slot [19-2] registered [ 0.804951] acpiphp: Slot [20-2] registered [ 0.805918] acpiphp: Slot [21-2] registered [ 0.806872] acpiphp: Slot [22-2] registered [ 0.807831] acpiphp: Slot [23-2] registered [ 0.807978] acpiphp: Slot [24-2] registered [ 0.808936] acpiphp: Slot [25-2] registered [ 0.809891] acpiphp: Slot [26-2] registered [ 0.810855] acpiphp: Slot [27-2] registered [ 0.811818] acpiphp: Slot [28-2] registered [ 0.811980] acpiphp: Slot [29-2] registered [ 0.812927] acpiphp: Slot [30] registered [ 0.813865] acpiphp: Slot [31] registered [ 0.822681] pci 0000:00:1e.0: PCI bridge to [bus 01] [ 0.823760] pci 0000:00:1e.0: bridge window [io 0xd000-0xdfff] [ 0.823975] pci 0000:00:1e.0: bridge window [mem 0xfe800000-0xfe9fffff] [ 0.825386] pci 0000:00:1e.0: bridge window [mem 0xfe200000-0xfe3fffff 64bit pref] [ 0.827766] pci_bus 0000:02: extended config space not accessible [ 0.832305] acpiphp: Slot [0-2] registered [ 0.833249] acpiphp: Slot [1-2] registered [ 0.834188] acpiphp: Slot [2-2] registered [ 0.835131] acpiphp: Slot [3-3] registered [ 0.835980] acpiphp: Slot [4-3] registered [ 0.836924] acpiphp: Slot [5-3] registered [ 0.837863] acpiphp: Slot [6-3] registered [ 0.838805] acpiphp: Slot [7-3] registered [ 0.839758] acpiphp: Slot [8-3] registered [ 0.839982] acpiphp: Slot [9-3] registered [ 0.840921] acpiphp: Slot [10-3] registered [ 0.842040] acpiphp: Slot [11-3] registered [ 0.843012] acpiphp: Slot [12-3] registered [ 0.843982] acpiphp: Slot [13-3] registered [ 0.844951] acpiphp: Slot [14-3] registered [ 0.845911] acpiphp: Slot [15-3] registered [ 0.846867] acpiphp: Slot [16-3] registered [ 0.847826] acpiphp: Slot [17-3] registered [ 0.847984] acpiphp: Slot [18-3] registered [ 0.848947] acpiphp: Slot [19-3] registered [ 0.849902] acpiphp: Slot [20-3] registered [ 0.850867] acpiphp: Slot [21-3] registered [ 0.851836] acpiphp: Slot [22-3] registered [ 0.855982] acpiphp: Slot [23-3] registered [ 0.856937] acpiphp: Slot [24-3] registered [ 0.857898] acpiphp: Slot [25-3] registered [ 0.858883] acpiphp: Slot [26-3] registered [ 0.859836] acpiphp: Slot [27-3] registered [ 0.859980] acpiphp: Slot [28-3] registered [ 0.860941] acpiphp: Slot [29-3] registered [ 0.861903] acpiphp: Slot [30-2] registered [ 0.862862] acpiphp: Slot [31-2] registered [ 0.873088] pci 0000:00:1f.0: PCI bridge to [bus 02] [ 0.874175] pci 0000:00:1f.0: bridge window [io 0xc000-0xcfff] [ 0.875442] pci 0000:00:1f.0: bridge window [mem 0xfe600000-0xfe7fffff] [ 0.875993] pci 0000:00:1f.0: bridge window [mem 0xfe000000-0xfe1fffff 64bit pref] [ 0.879673] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 10 11) [ 0.880148] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 10 11) [ 0.881507] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 11) [ 0.882862] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 11) [ 0.884049] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) [ 0.888258] iommu: Default domain type: Translated [ 0.889465] SCSI subsystem initialized [ 0.889465] libata version 3.00 loaded. [ 0.889465] pci 0000:00:02.0: vgaarb: setting as boot VGA device [ 0.889540] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none [ 0.891287] pci 0000:00:02.0: vgaarb: bridge control possible [ 0.891962] vgaarb: loaded [ 0.892691] ACPI: bus type USB registered [ 0.893616] usbcore: registered new interface driver usbfs [ 0.894783] usbcore: registered new interface driver hub [ 0.895914] usbcore: registered new device driver usb [ 0.900001] pps_core: LinuxPPS API ver. 1 registered [ 0.901054] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it [ 0.902895] PTP clock support registered [ 0.904013] EDAC MC: Ver: 3.0.0 [ 0.905269] PCI: Using ACPI for IRQ routing [ 0.907970] PCI: pci_cache_line_size set to 64 bytes [ 0.908666] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] [ 0.908674] e820: reserve RAM buffer [mem 0xbffda000-0xbfffffff] [ 0.909311] NetLabel: Initializing [ 0.910977] NetLabel: domain hash size = 128 [ 0.911951] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 0.914480] NetLabel: unlabeled traffic allowed by default [ 0.916220] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 [ 0.918619] hpet0: 3 comparators, 64-bit 100.000000 MHz counter [ 0.926463] clocksource: Switched to clocksource kvm-clock [ 0.962612] VALIDATE bpf [ 0.964538] VFS: Disk quotas dquot_6.6.0 [ 0.966438] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 0.969718] VALIDATE ramfs [ 0.971563] VALIDATE hugetlbfs [ 0.974269] AppArmor: AppArmor Filesystem Enabled [ 0.977018] pnp: PnP ACPI init [ 0.978836] pnp 00:00: Plug and Play ACPI device, IDs PNP0303 (active) [ 0.978902] pnp 00:01: Plug and Play ACPI device, IDs PNP0f13 (active) [ 0.978929] pnp 00:02: [dma 2] [ 0.978962] pnp 00:02: Plug and Play ACPI device, IDs PNP0700 (active) [ 0.979011] pnp 00:03: Plug and Play ACPI device, IDs PNP0b00 (active) [ 0.979994] pnp: PnP ACPI: found 4 devices [ 0.991972] thermal_sys: Registered thermal governor 'fair_share' [ 0.991974] thermal_sys: Registered thermal governor 'bang_bang' [ 0.994633] thermal_sys: Registered thermal governor 'step_wise' [ 0.997202] thermal_sys: Registered thermal governor 'user_space' [ 1.000112] thermal_sys: Registered thermal governor 'power_allocator' [ 1.007831] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns [ 1.014865] pci 0000:00:1e.0: PCI bridge to [bus 01] [ 1.017285] pci 0000:00:1e.0: bridge window [io 0xd000-0xdfff] [ 1.022956] pci 0000:00:1e.0: bridge window [mem 0xfe800000-0xfe9fffff] [ 1.027663] pci 0000:00:1e.0: bridge window [mem 0xfe200000-0xfe3fffff 64bit pref] [ 1.035859] pci 0000:00:1f.0: PCI bridge to [bus 02] [ 1.038175] pci 0000:00:1f.0: bridge window [io 0xc000-0xcfff] [ 1.043491] pci 0000:00:1f.0: bridge window [mem 0xfe600000-0xfe7fffff] [ 1.048123] pci 0000:00:1f.0: bridge window [mem 0xfe000000-0xfe1fffff 64bit pref] [ 1.052922] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window] [ 1.054211] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window] [ 1.055432] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window] [ 1.056760] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff window] [ 1.058087] pci_bus 0000:00: resource 8 [mem 0x240000000-0x2bfffffff window] [ 1.059452] pci_bus 0000:01: resource 0 [io 0xd000-0xdfff] [ 1.060576] pci_bus 0000:01: resource 1 [mem 0xfe800000-0xfe9fffff] [ 1.061808] pci_bus 0000:01: resource 2 [mem 0xfe200000-0xfe3fffff 64bit pref] [ 1.063282] pci_bus 0000:02: resource 0 [io 0xc000-0xcfff] [ 1.064403] pci_bus 0000:02: resource 1 [mem 0xfe600000-0xfe7fffff] [ 1.065706] pci_bus 0000:02: resource 2 [mem 0xfe000000-0xfe1fffff 64bit pref] [ 1.067432] NET: Registered protocol family 2 [ 1.068681] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear) [ 1.071560] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear) [ 1.073398] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear) [ 1.075314] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear) [ 1.076891] TCP: Hash tables configured (established 65536 bind 65536) [ 1.078280] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear) [ 1.079660] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear) [ 1.081378] NET: Registered protocol family 1 [ 1.082375] NET: Registered protocol family 44 [ 1.083362] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.084590] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.085848] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.122473] PCI Interrupt Link [LNKD] enabled at IRQ 11 [ 1.159049] pci 0000:00:01.2: quirk_usb_early_handoff+0x0/0x670 took 70234 usecs [ 1.160653] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] [ 1.162404] PCI: CLS 0 bytes, default 64 [ 1.163389] Trying to unpack rootfs image as initramfs... [ 1.311921] Freeing initrd memory: 27136K [ 1.312936] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) [ 1.314210] software IO TLB: mapped [mem 0xbbfda000-0xbffda000] (64MB) [ 1.315575] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x25632c21275, max_idle_ns: 440795290422 ns [ 1.317613] check: Scanning for low memory corruption every 60 seconds [ 1.319800] Initialise system trusted keyrings [ 1.320784] Key type blacklist registered [ 1.321958] workingset: timestamp_bits=36 max_order=21 bucketorder=0 [ 1.324768] zbud: loaded [ 1.325958] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 1.327627] fuse: init (API version 7.31) [ 1.328532] VALIDATE fuse [ 1.329289] VALIDATE fuse [ 1.330180] Platform Keyring initialized [ 1.335224] Key type asymmetric registered [ 1.336139] Asymmetric key parser 'x509' registered [ 1.337157] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244) [ 1.338849] io scheduler mq-deadline registered [ 1.340424] shpchp 0000:00:1e.0: Requesting control of SHPC hotplug via OSHP (_SB.PCI0.SF0) [ 1.344138] shpchp 0000:00:1e.0: Requesting control of SHPC hotplug via OSHP (_SB.PCI0) [ 1.345800] shpchp 0000:00:1e.0: Cannot get control of SHPC hotplug [ 1.347663] shpchp 0000:00:1f.0: Requesting control of SHPC hotplug via OSHP (_SB.PCI0.SF8) [ 1.351280] shpchp 0000:00:1f.0: Requesting control of SHPC hotplug via OSHP (_SB_.PCI0) [ 1.354757] shpchp 0000:00:1f.0: Cannot get control of SHPC hotplug [ 1.357464] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 1.360303] intel_idle: Please enable MWAIT in BIOS SETUP [ 1.360584] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 1.363768] ACPI: Power Button [PWRF] [ 1.442315] PCI Interrupt Link [LNKC] enabled at IRQ 10 [ 1.526820] PCI Interrupt Link [LNKA] enabled at IRQ 10 [ 1.576258] PCI Interrupt Link [LNKB] enabled at IRQ 11 [ 1.653100] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled [ 1.657555] Linux agpgart interface v0.103 [ 1.792084] loop: module loaded [ 1.794151] ata_piix 0000:00:01.1: version 2.13 [ 1.796288] scsi host0: ata_piix [ 1.798917] scsi host1: ata_piix [ 1.800603] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xe100 irq 14 [ 1.803371] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xe108 irq 15 [ 1.806545] libphy: Fixed MDIO Bus: probed [ 1.808600] tun: Universal TUN/TAP device driver, 1.6 [ 1.811033] PPP generic driver version 2.4.2 [ 1.813319] VFIO - User Level meta-driver version: 0.3 [ 1.815817] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.818518] ehci-pci: EHCI PCI platform driver [ 1.820549] ehci-platform: EHCI generic platform driver [ 1.822806] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 1.825369] ohci-pci: OHCI PCI platform driver [ 1.827365] ohci-platform: OHCI generic platform driver [ 1.829599] uhci_hcd: USB Universal Host Controller Interface driver [ 1.914354] uhci_hcd 0000:00:01.2: UHCI Host Controller [ 1.916887] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1 [ 1.920286] uhci_hcd 0000:00:01.2: detected 2 ports [ 1.922821] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000e080 [ 1.926091] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.04 [ 1.929833] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.937791] usb usb1: Product: UHCI Host Controller [ 1.940040] usb usb1: Manufacturer: Linux 5.4.0-91-generic uhci_hcd [ 1.942936] usb usb1: SerialNumber: 0000:00:01.2 [ 1.945632] hub 1-0:1.0: USB hub found [ 1.947765] hub 1-0:1.0: 2 ports detected [ 1.950562] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 1.956418] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 1.958985] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 1.961802] mousedev: PS/2 mouse device common for all mice [ 1.965151] rtc_cmos 00:03: RTC can wake from S4 [ 1.965596] ata2.01: NODEV after polling detection [ 1.968965] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100 [ 1.969018] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 1.972302] rtc_cmos 00:03: registered as rtc0 [ 1.974270] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5 [ 1.977117] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray [ 1.978278] rtc_cmos 00:03: alarms up to one day, y3k, 242 bytes nvram, hpet irqs [ 1.981910] cdrom: Uniform CD-ROM driver Revision: 3.20 [ 1.984889] i2c /dev entries driver [ 1.985029] device-mapper: uevent: version 1.0.3 [ 1.994855] device-mapper: ioctl: 4.41.0-ioctl (2019-09-16) initialised: dm-devel@redhat.com [ 1.998670] platform eisa.0: Probing EISA bus 0 [ 2.000863] platform eisa.0: EISA: Cannot allocate resource for mainboard [ 2.003778] platform eisa.0: Cannot allocate resource for EISA slot 1 [ 2.006596] platform eisa.0: Cannot allocate resource for EISA slot 2 [ 2.009420] platform eisa.0: Cannot allocate resource for EISA slot 3 [ 2.012190] platform eisa.0: Cannot allocate resource for EISA slot 4 [ 2.014986] platform eisa.0: Cannot allocate resource for EISA slot 5 [ 2.017901] platform eisa.0: Cannot allocate resource for EISA slot 6 [ 2.020670] platform eisa.0: Cannot allocate resource for EISA slot 7 [ 2.023452] platform eisa.0: Cannot allocate resource for EISA slot 8 [ 2.026398] platform eisa.0: EISA: Detected 0 cards [ 2.028695] intel_pstate: CPU model not supported [ 2.031319] ledtrig-cpu: registered to indicate activity on CPUs [ 2.034178] drop_monitor: Initializing network drop monitor service [ 2.037023] sr 1:0:0:0: Attached scsi CD-ROM sr0 [ 2.037198] sr 1:0:0:0: Attached scsi generic sg0 type 5 [ 2.037500] NET: Registered protocol family 10 [ 2.062568] Segment Routing with IPv6 [ 2.064502] NET: Registered protocol family 17 [ 2.066855] Key type dns_resolver registered [ 2.069983] RAS: Correctable Errors collector initialized. [ 2.072605] IPI shorthand broadcast: enabled [ 2.074700] sched_clock: Marking stable (1862508311, 210034085)->(2090566474, -18024078) [ 2.078705] registered taskstats version 1 [ 2.080762] Loading compiled-in X.509 certificates [ 2.085497] Loaded X.509 cert 'Build time autogenerated kernel key: 168dd4ce00092acf2ca44d8312eb368aba9b9faa' [ 2.091438] Loaded X.509 cert 'Canonical Ltd. Live Patch Signing: 14df34d1a87cf37625abec039ef2bf521249b969' [ 2.097284] Loaded X.509 cert 'Canonical Ltd. Kernel Module Signing: 88f752e560a1e0737e31163a466ad7b70a850c19' [ 2.101739] zswap: loaded using pool lzo/zbud [ 2.104358] Key type ._fscrypt registered [ 2.106297] Key type .fscrypt registered [ 2.123651] Key type big_key registered [ 2.132873] Key type encrypted registered [ 2.134883] AppArmor: AppArmor sha1 policy hashing enabled [ 2.137390] ima: No TPM chip found, activating TPM-bypass! [ 2.139895] ima: Allocated hash algorithm: sha1 [ 2.142104] ima: No architecture policies found [ 2.144362] evm: Initialising EVM extended attributes: [ 2.146655] evm: security.selinux [ 2.148332] evm: security.SMACK64 [ 2.149985] evm: security.SMACK64EXEC [ 2.151798] evm: security.SMACK64TRANSMUTE [ 2.153747] evm: security.SMACK64MMAP [ 2.155580] evm: security.apparmor [ 2.157267] evm: security.ima [ 2.158809] evm: security.capability [ 2.160573] evm: HMAC attrs: 0x1 [ 2.165629] PM: Magic number: 1:320:125 [ 2.167675] acpi device:00: hash matches [ 2.169876] rtc_cmos 00:03: setting system clock to 2021-12-14T11:07:02 UTC (1639480022) [ 2.177779] Freeing unused decrypted memory: 2040K [ 2.182902] Freeing unused kernel image memory: 2736K [ 2.192038] usb 1-1: new full-speed USB device number 2 using uhci_hcd [ 2.200048] Write protecting the kernel read-only data: 22528k [ 2.206228] Freeing unused kernel image memory: 2008K [ 2.209431] Freeing unused kernel image memory: 1124K [ 2.234560] x86/mm: Checked W+X mappings: passed, no W+X pages found. [ 2.237381] x86/mm: Checking user space page tables [ 2.262130] x86/mm: Checked W+X mappings: passed, no W+X pages found. [ 2.265081] Run /init as init process [ 2.306640] systemd-udevd[159]: Starting version 245.4-4ubuntu3.13 [ 2.312838] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:24 The line takes no effect, ignoring. [ 2.317343] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:25 The line takes no effect, ignoring. [ 2.321775] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:29 The line takes no effect, ignoring. [ 2.326206] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:32 The line takes no effect, ignoring. [ 2.330716] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:33 The line takes no effect, ignoring. [ 2.335301] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:34 The line takes no effect, ignoring. [ 2.339671] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:35 The line takes no effect, ignoring. [ 2.344140] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:36 The line takes no effect, ignoring. [ 2.348564] systemd-udevd[160]: /usr/lib/udev/rules.d/50-udev-default.rules:37 The line takes no effect, ignoring. [ 2.392010] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00 [ 2.395688] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10 [ 2.398933] usb 1-1: Product: QEMU USB Tablet [ 2.401035] usb 1-1: Manufacturer: QEMU [ 2.402885] usb 1-1: SerialNumber: 28754-0000:00:01.2-1 [ 2.437381] hidraw: raw HID events driver (C) Jiri Kosina [ 2.450365] usbcore: registered new interface driver usbhid [ 2.452974] usbhid: USB HID core driver [ 2.477972] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input3 [ 2.480374] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0 [ 2.485196] FDC 0 is a S82078B [ 2.498448] scsi host2: Virtio SCSI HBA [ 2.501175] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5 [ 2.502794] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5 [ 2.517028] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4 [ 2.523841] cryptd: max_cpu_qlen set to 1000 [ 2.530790] AVX version of gcm_enc/dec engaged. [ 2.531906] AES CTR mode by8 optimization enabled [ 2.539894] random: fast init done [ 2.540092] random: systemd-udevd: uninitialized urandom read (16 bytes read) [ 2.540342] random: systemd-udevd: uninitialized urandom read (16 bytes read) [ 2.547382] random: systemd-udevd: uninitialized urandom read (16 bytes read) [ 2.547646] sd 2:0:0:0: Power-on or device reset occurred [ 2.547692] sd 2:0:0:0: Attached scsi generic sg1 type 0 [ 2.553747] sd 2:0:0:0: [sda] 41940992 512-byte logical blocks: (21.5 GB/20.0 GiB) [ 2.555738] sd 2:0:0:0: [sda] Write Protect is off [ 2.556985] sd 2:0:0:0: [sda] Mode Sense: 63 00 00 08 [ 2.557208] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 2.587136] sda: sda1 sda14 sda15 [ 2.592518] virtio_net virtio4 ens20: renamed from eth2 [ 2.612873] sd 2:0:0:0: [sda] Attached SCSI disk [ 2.620166] virtio_net virtio2 ens18: renamed from eth0 [ 2.644710] virtio_net virtio3 ens19: renamed from eth1 [ 4.240000] raid6: sse2x4 gen() 4935 MB/s [ 4.287997] raid6: sse2x4 xor() 3369 MB/s [ 4.335992] raid6: sse2x2 gen() 3946 MB/s [ 4.383994] raid6: sse2x2 xor() 2750 MB/s [ 4.431965] raid6: sse2x1 gen() 3464 MB/s [ 4.480004] raid6: sse2x1 xor() 5396 MB/s [ 4.480929] raid6: using algorithm sse2x4 gen() 4935 MB/s [ 4.482011] raid6: .... xor() 3369 MB/s, rmw enabled [ 4.483038] raid6: using ssse3x2 recovery algorithm [ 4.485456] xor: automatically using best checksumming function avx [ 4.489108] async_tx: api initialized (async) [ 4.602261] Btrfs loaded, crc32c=crc32c-intel [ 4.849220] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null) [ 4.982005] printk: systemd-udevd: 34 output lines suppressed due to ratelimiting [ 5.841837] systemd[1]: Inserted module 'autofs4' [ 5.918640] systemd[1]: systemd 245.4-4ubuntu3.13 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid) [ 5.929106] systemd[1]: Detected virtualization kvm. [ 5.931570] systemd[1]: Detected architecture x86-64. [ 5.972239] systemd[1]: Set hostname to . [ 7.287604] systemd[1]: Created slice system-modprobe.slice. [ 7.291569] systemd[1]: Created slice system-systemd\x2dfsck.slice. [ 7.295426] systemd[1]: Created slice User and Session Slice. [ 7.298819] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ 7.302990] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 7.311856] systemd[1]: Reached target ceph target allowing to start/stop all ceph*@.service instances at once. [ 7.316482] systemd[1]: Reached target User and Group Name Lookups. [ 7.319451] systemd[1]: Reached target Slices. [ 7.321719] systemd[1]: Reached target Swap. [ 7.324153] systemd[1]: Listening on Device-mapper event daemon FIFOs. [ 7.327426] systemd[1]: Listening on LVM2 poll daemon socket. [ 7.330277] systemd[1]: Listening on multipathd control socket. [ 7.333354] systemd[1]: Listening on Syslog Socket. [ 7.336075] systemd[1]: Listening on fsck to fsckd communication Socket. [ 7.339346] systemd[1]: Listening on initctl Compatibility Named Pipe. [ 7.343043] systemd[1]: Listening on Journal Audit Socket. [ 7.345954] systemd[1]: Listening on Journal Socket (/dev/log). [ 7.349140] systemd[1]: Listening on Journal Socket. [ 7.352044] systemd[1]: Listening on Network Service Netlink Socket. [ 7.355344] systemd[1]: Listening on udev Control Socket. [ 7.358154] systemd[1]: Listening on udev Kernel Socket. [ 7.363717] systemd[1]: Mounting Huge Pages File System... [ 7.369550] systemd[1]: Mounting POSIX Message Queue File System... [ 7.375443] systemd[1]: Mounting Kernel Debug File System... [ 7.381109] systemd[1]: Mounting Kernel Trace File System... [ 7.388587] systemd[1]: Starting Journal Service... [ 7.394544] systemd[1]: Starting Set the console keyboard layout... [ 7.401474] systemd[1]: Starting Create list of static device nodes for the current kernel... [ 7.408752] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling... [ 7.416683] systemd[1]: Starting Load Kernel Module drm... [ 7.419648] systemd[1]: Condition check resulted in OpenVSwitch configuration for cleanup being skipped. [ 7.426683] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. [ 7.428902] systemd[1]: Condition check resulted in File System Check on Root Device being skipped. [ 7.435359] systemd[1]: Starting Load Kernel Modules... [ 7.438186] systemd[1]: Starting Remount Root and Kernel File Systems... [ 7.441581] systemd[1]: Starting udev Coldplug all Devices... [ 7.444457] systemd[1]: Starting Uncomplicated firewall... [ 7.448523] systemd[1]: Mounted Huge Pages File System. [ 7.450018] systemd[1]: Mounted POSIX Message Queue File System. [ 7.451560] systemd[1]: Mounted Kernel Debug File System. [ 7.453072] systemd[1]: Mounted Kernel Trace File System. [ 7.455243] systemd[1]: Finished Create list of static device nodes for the current kernel. [ 7.463645] systemd[1]: Finished Uncomplicated firewall. [ 7.470158] systemd[1]: modprobe@drm.service: Succeeded. [ 7.471802] systemd[1]: Finished Load Kernel Module drm. [ 7.476065] EXT4-fs (sda1): re-mounted. Opts: (null) [ 7.480956] systemd[1]: Finished Remount Root and Kernel File Systems. [ 7.485424] systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. [ 7.487279] systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped. [ 7.490801] systemd[1]: Starting Load/Save Random Seed... [ 7.494026] systemd[1]: Starting Create System Users... [ 7.513060] systemd[1]: Finished Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling. [ 7.533026] systemd[1]: Finished Create System Users. [ 7.536398] systemd[1]: Starting Create Static Device Nodes in /dev... [ 7.550752] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP) [ 7.553125] systemd[1]: Finished Load/Save Random Seed. [ 7.555412] IPVS: Connection hash table configured (size=4096, memory=64Kbytes) [ 7.557248] IPVS: ipvs loaded. [ 7.559575] systemd[1]: Finished Set the console keyboard layout. [ 7.561266] IPVS: [rr] scheduler registered. [ 7.564818] IPVS: [sh] scheduler registered. [ 7.567978] IPVS: [wrr] scheduler registered. [ 7.569369] systemd[1]: Started Journal Service. [ 7.582112] systemd-journald[383]: Received client request to flush runtime journal. [ 8.203176] virtio_net virtio4 eth2: renamed from ens20 [ 8.216885] virtio_net virtio2 eth0: renamed from ens18 [ 8.240748] virtio_net virtio3 eth1: renamed from ens19 [ 8.965360] alua: device handler registered [ 8.975446] emc: device handler registered [ 8.982840] rdac: device handler registered [ 9.395399] random: crng init done [ 9.395405] random: 7 urandom warning(s) missed due to ratelimiting [ 9.677510] audit: type=1400 audit(1639480030.004:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=589 comm="apparmor_parser" [ 9.677521] audit: type=1400 audit(1639480030.004:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=589 comm="apparmor_parser" [ 9.677526] audit: type=1400 audit(1639480030.004:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=589 comm="apparmor_parser" [ 9.677786] audit: type=1400 audit(1639480030.004:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=587 comm="apparmor_parser" [ 9.677794] audit: type=1400 audit(1639480030.004:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=587 comm="apparmor_parser" [ 9.687225] audit: type=1400 audit(1639480030.012:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=588 comm="apparmor_parser" [ 9.689189] audit: type=1400 audit(1639480030.016:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="cri-containerd.apparmor.d" pid=590 comm="apparmor_parser" [ 9.689456] audit: type=1400 audit(1639480030.016:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=591 comm="apparmor_parser" [ 9.689463] audit: type=1400 audit(1639480030.016:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=591 comm="apparmor_parser" [ 9.692196] audit: type=1400 audit(1639480030.020:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=586 comm="apparmor_parser" [ 14.458816] ISO 9660 Extensions: RRIP_1991A [ 20.845915] kauditd_printk_skb: 63 callbacks suppressed [ 20.845918] audit: type=1400 audit(1639480040.248:75): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/sbin/tcpdump" pid=1233 comm="apparmor_parser" [ 20.845924] audit: type=1400 audit(1639480040.248:76): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=1232 comm="apparmor_parser" [ 20.845927] audit: type=1400 audit(1639480040.248:77): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=1232 comm="apparmor_parser" [ 20.856073] audit: type=1400 audit(1639480040.260:78): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/bin/man" pid=1234 comm="apparmor_parser" [ 20.856078] audit: type=1400 audit(1639480040.260:79): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="man_filter" pid=1234 comm="apparmor_parser" [ 20.856090] audit: type=1400 audit(1639480040.260:80): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="man_groff" pid=1234 comm="apparmor_parser" [ 20.856094] audit: type=1400 audit(1639480040.260:81): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=1231 comm="apparmor_parser" [ 20.856097] audit: type=1400 audit(1639480040.260:82): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1231 comm="apparmor_parser" [ 20.856100] audit: type=1400 audit(1639480040.260:83): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=1231 comm="apparmor_parser" [ 20.856103] audit: type=1400 audit(1639480040.260:84): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/{,usr/}sbin/dhclient" pid=1231 comm="apparmor_parser" [ 21.423875] Started bpfilter [ 21.423899] bpfilter: Loaded bpfilter_umh pid 1358 [ 23.870180] aufs 5.4.3-20200302 [ 24.134504] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. [ 24.137738] Bridge firewalling registered [ 52.308713] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 52.308772] IPv6: ADDRCONF(NETDEV_CHANGE): cali471b40b31ed: link becomes ready [ 52.345943] cgroup: cgroup: disabling cgroup2 socket matching due to net_prio or net_cls activation [ 53.025146] IPv6: ADDRCONF(NETDEV_CHANGE): cali788afd238a2: link becomes ready [ 53.698679] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 53.698776] IPv6: ADDRCONF(NETDEV_CHANGE): cali1ad7429c68b: link becomes ready [ 53.940539] IPv6: ADDRCONF(NETDEV_CHANGE): cali58986b1a6a4: link becomes ready [ 54.183751] IPv6: ADDRCONF(NETDEV_CHANGE): cali0118534ca07: link becomes ready [ 54.427733] IPv6: ADDRCONF(NETDEV_CHANGE): cali7ccf07b93e3: link becomes ready [ 54.647143] IPv6: ADDRCONF(NETDEV_CHANGE): cali768a45af362: link becomes ready [ 55.020354] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 55.020461] IPv6: ADDRCONF(NETDEV_CHANGE): cali858b9495889: link becomes ready [ 77.613748] Initializing XFRM netlink socket

Madhu-1 commented 2 years ago

@hoba84 can you please paste the configmap output which contains the clusterID and mon mapping? can you also try running commands like ceph -s or rbd ls -p mycluster-hdd from csi-rbdplugin container of the provisioner pod?

Note- you need to pass monitor, user, key parameters when executing the above ceph/rbd commands in the rbd-plugin container.

pascalhobus commented 2 years ago

Hi @Madhu-1, these are the two config maps for ceph-config and ceph-csi-config:

❯ kubectl get configmap ceph-config -n default -o yaml apiVersion: v1 data: ceph.conf: | [global] auth_cluster_required = cephx auth_service_required = cephx auth_client_required = cephx keyring: "" kind: ConfigMap metadata: annotations: kubectl.kubernetes.io/last-applied-configuration: | {"apiVersion":"v1","data":{"ceph.conf":"[global]\nauth_cluster_required = cephx\nauth_service_required = cephx\nauth_client_required = cephx\n","keyring":""},"kind":"ConfigMap","metadata":{"annotations":{},"name":"ceph-config","namespace":"default"}} creationTimestamp: "2021-12-14T08:31:58Z" name: ceph-config namespace: default resourceVersion: "17148057" selfLink: /api/v1/namespaces/default/configmaps/ceph-config uid: d398daaf-276f-405d-9738-9f63588243cd

❯ kubectl get configmap ceph-csi-config -n default -o yaml apiVersion: v1 data: config.json: |- [ { "clusterID": "d2383c4d-1fad-4701-90d9-b5079b403737", "monitors": [ "10.1.30.1:6789", "10.1.30.2:6789", "10.1.30.3:6789" ] } ] kind: ConfigMap metadata: annotations: kubectl.kubernetes.io/last-applied-configuration: | {"apiVersion":"v1","data":{"config.json":"[\n {\n \"clusterID\": \"d2383c4d-1fad-4701-90d9-b5079b403737\",\n \"monitors\": [\n \"10.1.30.1:6789\",\n \"10.1.30.2:6789\",\n \"10.1.30.3:6789\"\n ]\n }\n]"},"kind":"ConfigMap","metadata":{"annotations":{},"name":"ceph-csi-config","namespace":"default"}} creationTimestamp: "2021-12-14T08:31:58Z" name: ceph-csi-config namespace: default resourceVersion: "17148055" selfLink: /api/v1/namespaces/default/configmaps/ceph-csi-config uid: c68d6bdb-bbc0-43f3-8910-c0d0452f552f

For our suggested debugging I run ❯ kubectl exec -i -t csi-rbdplugin-provisioner-6bbfdc7c78-5mrgq --container csi-rbdplugin -- /bin/bash but in that container I cannot even ping any monitor (e.g. 10.1.30.1).

Also, I do not know how to pass monitor, user and key to that container.

Madhu-1 commented 2 years ago

rbd ls -p mycluster-hdd -m 10.1.30.1:6789 --user <username> --key the command goes like this you need to pass the user and key as per your cluster.

To check network connectivity you can run the below command in the csi-rbdplugin container

cat < /dev/tcp/10.1.30.1/6789

If above command does not return any value like ceph v027���'e����'^C it could be network issue.

pascalhobus commented 2 years ago

Hi @Madhu-1, the above command rbd ls -p [...] does not return anything in my case (it gets stuck). Also cat < /dev/tcp/10.1.30.1/6789 does not return anything. There is no /dev/tcp* device listed when I do ls -la /dev. As the container comes from ceph-csi, what prerequisites does it need for networking?

The only speciality in my setup is, that the kubernetes nodes have multiple network interfaces. One (10.1.30.0/24) is dedicated to ceph access. In the other container (pod:csi-rbdplugin with container:csi-rbdplugin) I can run the above commands to access ceph cluster.

Madhu-1 commented 2 years ago

@hoba84 we don't put any requirement for networking, the pre-req is that the ceph cluster should be reachable from the csi pods.

pascalhobus commented 2 years ago

Hi @Madhu-1, I could solve the problem and indeed it was missing network connectivity inside the provisioner pod. I've resolved that by configuring with help of multus a network interface - now I was able to use the PVC. Maybe the documentation and/or logging could be improved. Thanks again for your valuable hep!