ccm-linode doesnt start properly on k8s v1.19.3

Avaar0032 commented 3 years ago

General:

[x] Have you removed all sensitive information, including but not limited to access keys and passwords?

[x] Have you checked to ensure there aren't other open or closed Pull Requests for the same bug/feature/question? Hello! I currently try manually deploy k8s cluster on Linode VMs and stuck on deploying linode cloud controller manager following the manual on Github. ccm-linode pods start with status "Running" but in pod logs a lot of errors:

Linode Cloud Controller Manager starting up
SENTRY_DSN not set, not initializing Sentry
ERROR: logging before flag.Parse: I1126 16:07:37.724777       1 flags.go:27] FLAG: --address="0.0.0.0"
ERROR: logging before flag.Parse: I1126 16:07:37.724881       1 flags.go:27] FLAG: --allocate-node-cidrs="false"
ERROR: logging before flag.Parse: I1126 16:07:37.724890       1 flags.go:27] FLAG: --allow-untagged-cloud="false"
ERROR: logging before flag.Parse: I1126 16:07:37.724896       1 flags.go:27] FLAG: --alsologtostderr="false"
ERROR: logging before flag.Parse: I1126 16:07:37.724902       1 flags.go:27] FLAG: --bind-address="0.0.0.0"
ERROR: logging before flag.Parse: I1126 16:07:37.724908       1 flags.go:27] FLAG: --cert-dir="/var/run/kubernetes"
ERROR: logging before flag.Parse: I1126 16:07:37.724915       1 flags.go:27] FLAG: --cidr-allocator-type="RangeAllocator"
ERROR: logging before flag.Parse: I1126 16:07:37.724921       1 flags.go:27] FLAG: --cloud-config=""
ERROR: logging before flag.Parse: I1126 16:07:37.724926       1 flags.go:27] FLAG: --cloud-provider="linode"
ERROR: logging before flag.Parse: I1126 16:07:37.724932       1 flags.go:27] FLAG: --cluster-cidr=""
ERROR: logging before flag.Parse: I1126 16:07:37.724936       1 flags.go:27] FLAG: --cluster-name="kubernetes"
ERROR: logging before flag.Parse: I1126 16:07:37.724941       1 flags.go:27] FLAG: --concurrent-service-syncs="1"
ERROR: logging before flag.Parse: I1126 16:07:37.724948       1 flags.go:27] FLAG: --configure-cloud-routes="true"
ERROR: logging before flag.Parse: I1126 16:07:37.724953       1 flags.go:27] FLAG: --contention-profiling="false"
ERROR: logging before flag.Parse: I1126 16:07:37.724958       1 flags.go:27] FLAG: --controller-start-interval="0s"
ERROR: logging before flag.Parse: I1126 16:07:37.724965       1 flags.go:27] FLAG: --feature-gates=""
ERROR: logging before flag.Parse: I1126 16:07:37.724974       1 flags.go:27] FLAG: --help="false"
ERROR: logging before flag.Parse: I1126 16:07:37.724979       1 flags.go:27] FLAG: --http2-max-streams-per-connection="0"
ERROR: logging before flag.Parse: I1126 16:07:37.724986       1 flags.go:27] FLAG: --kube-api-burst="30"
ERROR: logging before flag.Parse: I1126 16:07:37.724991       1 flags.go:27] FLAG: --kube-api-content-type="application/vnd.kubernetes.protobuf"
ERROR: logging before flag.Parse: I1126 16:07:37.724997       1 flags.go:27] FLAG: --kube-api-qps="20"
ERROR: logging before flag.Parse: I1126 16:07:37.725005       1 flags.go:27] FLAG: --kubeconfig=""
ERROR: logging before flag.Parse: I1126 16:07:37.725010       1 flags.go:27] FLAG: --leader-elect="true"
ERROR: logging before flag.Parse: I1126 16:07:37.725015       1 flags.go:27] FLAG: --leader-elect-lease-duration="15s"
ERROR: logging before flag.Parse: I1126 16:07:37.725020       1 flags.go:27] FLAG: --leader-elect-renew-deadline="10s"
ERROR: logging before flag.Parse: I1126 16:07:37.725025       1 flags.go:27] FLAG: --leader-elect-resource-lock="endpoints"
ERROR: logging before flag.Parse: I1126 16:07:37.725030       1 flags.go:27] FLAG: --leader-elect-retry-period="2s"
ERROR: logging before flag.Parse: I1126 16:07:37.725036       1 flags.go:27] FLAG: --linodego-debug="false"
ERROR: logging before flag.Parse: I1126 16:07:37.725041       1 flags.go:27] FLAG: --log-backtrace-at=":0"
ERROR: logging before flag.Parse: I1126 16:07:37.725051       1 flags.go:27] FLAG: --log-dir=""
ERROR: logging before flag.Parse: I1126 16:07:37.725056       1 flags.go:27] FLAG: --log-flush-frequency="5s"
ERROR: logging before flag.Parse: I1126 16:07:37.725061       1 flags.go:27] FLAG: --logtostderr="true"
ERROR: logging before flag.Parse: I1126 16:07:37.725066       1 flags.go:27] FLAG: --master=""
ERROR: logging before flag.Parse: I1126 16:07:37.725071       1 flags.go:27] FLAG: --min-resync-period="12h0m0s"
ERROR: logging before flag.Parse: I1126 16:07:37.725077       1 flags.go:27] FLAG: --node-monitor-period="5s"
ERROR: logging before flag.Parse: I1126 16:07:37.725082       1 flags.go:27] FLAG: --node-status-update-frequency="5m0s"
ERROR: logging before flag.Parse: I1126 16:07:37.725087       1 flags.go:27] FLAG: --node-sync-period="0s"
ERROR: logging before flag.Parse: I1126 16:07:37.725092       1 flags.go:27] FLAG: --port="0"
ERROR: logging before flag.Parse: I1126 16:07:37.725659       1 flags.go:27] FLAG: --profiling="false"
ERROR: logging before flag.Parse: I1126 16:07:37.725676       1 flags.go:27] FLAG: --route-reconciliation-period="10s"
ERROR: logging before flag.Parse: I1126 16:07:37.725683       1 flags.go:27] FLAG: --secure-port="10253"
ERROR: logging before flag.Parse: I1126 16:07:37.725701       1 flags.go:27] FLAG: --stderrthreshold="2"
ERROR: logging before flag.Parse: I1126 16:07:37.725707       1 flags.go:27] FLAG: --tls-cert-file=""
ERROR: logging before flag.Parse: I1126 16:07:37.725713       1 flags.go:27] FLAG: --tls-cipher-suites="[]"
ERROR: logging before flag.Parse: I1126 16:07:37.725731       1 flags.go:27] FLAG: --tls-min-version=""
ERROR: logging before flag.Parse: I1126 16:07:37.725736       1 flags.go:27] FLAG: --tls-private-key-file=""
ERROR: logging before flag.Parse: I1126 16:07:37.725741       1 flags.go:27] FLAG: --tls-sni-cert-key="[]"
ERROR: logging before flag.Parse: I1126 16:07:37.725750       1 flags.go:27] FLAG: --use-service-account-credentials="false"
ERROR: logging before flag.Parse: I1126 16:07:37.725756       1 flags.go:27] FLAG: --v="3"
ERROR: logging before flag.Parse: I1126 16:07:37.725761       1 flags.go:27] FLAG: --version="false"
ERROR: logging before flag.Parse: I1126 16:07:37.725786       1 flags.go:27] FLAG: --vmodule=""
ERROR: logging before flag.Parse: W1126 16:07:37.726762       1 client_config.go:552] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
ERROR: logging before flag.Parse: W1126 16:07:37.743830       1 authentication.go:55] Authentication is disabled
ERROR: logging before flag.Parse: I1126 16:07:37.743896       1 serve.go:96] Serving securely on [::]:10253
ERROR: logging before flag.Parse: I1126 16:07:37.745494       1 leaderelection.go:185] attempting to acquire leader lease  kube-system/cloud-controller-manager...
ERROR: logging before flag.Parse: I1126 16:07:37.901579       1 leaderelection.go:194] successfully acquired lease kube-system/cloud-controller-manager
ERROR: logging before flag.Parse: I1126 16:07:37.906483       1 node_controller.go:89] Sending events to api server.
ERROR: logging before flag.Parse: I1126 16:07:37.907681       1 reflector.go:202] Starting reflector *v1.Service (0s) from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:37.907854       1 reflector.go:240] Listing and watching *v1.Service from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:37.908661       1 event.go:221] Event(v1.ObjectReference{Kind:"Endpoints", Namespace:"kube-system", Name:"cloud-controller-manager", UID:"46e55630-e01e-463f-9c7e-db2ea8759096", APIVersion:"v1", ResourceVersion:"3204", FieldPath:""}): type: 'Normal' reason: 'LeaderElection' li1406-143.members.linode.com_80b62809-3001-11eb-9103-f23c924ffb7c became leader
ERROR: logging before flag.Parse: I1126 16:07:37.910077       1 pvlcontroller.go:107] Starting PersistentVolumeLabelController
ERROR: logging before flag.Parse: I1126 16:07:37.910174       1 controller_utils.go:1025] Waiting for caches to sync for persistent volume label controller
ERROR: logging before flag.Parse: I1126 16:07:37.910366       1 reflector.go:202] Starting reflector *v1.PersistentVolume (0s) from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:37.910424       1 reflector.go:240] Listing and watching *v1.PersistentVolume from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:37.910854       1 controllermanager.go:264] Will not configure cloud provider routes for allocate-node-cidrs: false, configure-cloud-routes: true.
ERROR: logging before flag.Parse: I1126 16:07:37.911017       1 service_controller.go:183] Starting service controller
ERROR: logging before flag.Parse: I1126 16:07:37.911030       1 controller_utils.go:1025] Waiting for caches to sync for service controller
ERROR: logging before flag.Parse: I1126 16:07:38.010438       1 controller_utils.go:1032] Caches are synced for persistent volume label controller
ERROR: logging before flag.Parse: I1126 16:07:38.013170       1 reflector.go:202] Starting reflector *v1.Service (30s) from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:38.013207       1 reflector.go:240] Listing and watching *v1.Service from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:38.013666       1 reflector.go:202] Starting reflector *v1.Node (14h44m20.885595692s) from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:38.013694       1 reflector.go:240] Listing and watching *v1.Node from pkg/mod/k8s.io/client-go@v8.0.0+incompatible/tools/cache/reflector.go:99
ERROR: logging before flag.Parse: I1126 16:07:38.115381       1 controller_utils.go:1032] Caches are synced for service controller
ERROR: logging before flag.Parse: I1126 16:07:38.115568       1 service_controller.go:636] Detected change in list of current cluster nodes. New node set: map[li1403-18.members.linode.com:{} li1483-253.members.linode.com:{} li1800-66.members.linode.com:{}]
ERROR: logging before flag.Parse: I1126 16:07:38.115687       1 service_controller.go:644] Successfully updated 0 out of 0 load balancers to direct traffic to the updated set of nodes
ERROR: logging before flag.Parse: I1126 16:07:38.115825       1 service_controller.go:326] Not persisting unchanged LoadBalancerStatus for service kube-system/kube-dns to registry.
ERROR: logging before flag.Parse: I1126 16:07:38.115850       1 service_controller.go:326] Not persisting unchanged LoadBalancerStatus for service calico-system/calico-typha to registry.
ERROR: logging before flag.Parse: I1126 16:07:38.115866       1 service_controller.go:326] Not persisting unchanged LoadBalancerStatus for service default/kubernetes to registry.
ERROR: logging before flag.Parse: E1126 16:07:38.825542       1 node_controller.go:353] failed to set node provider id: failed to get instance ID from cloud provider: instance not found
ERROR: logging before flag.Parse: E1126 16:07:39.080552       1 node_controller.go:417] NodeAddress: Error fetching by providerID: providerID cannot be empty string Error fetching by NodeName: instance not found
ERROR: logging before flag.Parse: E1126 16:07:39.292917       1 node_controller.go:353] failed to set node provider id: failed to get instance ID from cloud provider: instance not found
ERROR: logging before flag.Parse: E1126 16:07:39.484441       1 node_controller.go:417] NodeAddress: Error fetching by providerID: providerID cannot be empty string Error fetching by NodeName: instance not found
ERROR: logging before flag.Parse: E1126 16:07:39.754549       1 node_controller.go:353] failed to set node provider id: failed to get instance ID from cloud provider: instance not found
ERROR: logging before flag.Parse: E1126 16:07:39.939516       1 node_controller.go:417] NodeAddress: Error fetching by providerID: providerID cannot be empty string Error fetching by NodeName: instance not found
ERROR: logging before flag.Parse: E1126 16:07:40.178981       1 node_controller.go:353] failed to set node provider id: failed to get instance ID from cloud provider: instance not found

and coredns stuck in pending state. Is there is another thing what must be done except described in manual or ccm does not support k8s 19.3? kubelet kubectl kubead v 19.3

Bug Reporting

Expected Behavior

ccm pods starting properly & Linode NodeBalancer created on creating service with type LoadBalancer

Actual Behavior

ccm pods started with state Running and errors in log, k8s coredns pods stuck in pending state

Steps to Reproduce the Problem

Create k8s cluster on Linode VMs
Generate ccm manifest with Linode account api access token with full access
apply generated manifest to cluster

Environment Specifications

VMs with centos7

Screenshots, Code Blocks, and Logs

Additional Notes

For general help or discussion, join the Kubernetes Slack team channel #linode. To sign up, use the Kubernetes Slack inviter.

The Linode Community is a great place to get additional support.

displague commented 3 years ago

Is there is another thing what must be done except described in manual or ccm does not support k8s 19.3?

@Avaar0032 the node name is expected to match the Linode label: https://github.com/linode/linode-cloud-controller-manager/blob/6e3f585f6e7d5dd4b3e33f2f03792e41a978c77c/cloud/linode/instances.go#L191-L203

Do they match?

li1403-18, li1483-253, and li1800-66 in this case.

if you add LINODE_DEBUG=1 to the environment of the CCM pods, or the command-line argument --linodego-debug=true you should see the API call including the label filter parameter and any messages received by the Linode API service.

phillc commented 3 years ago

Hello,

Internally we only test up to the current LKE version, which is at 1.18. It would not surprise me that we are behind on updating something. We will work on updating CCM in the near future.

Thanks for the report!

Avaar0032 commented 3 years ago

Thanks for reply! We currently testing some database on cluster, when finish i will redeploy ccm with debug argument and test it again.

linode / linode-cloud-controller-manager