Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Scale up delayed by Cluster Autoscaler for large request #3835

Closed
nshekhar221 opened this issue Jan 21, 2021 · 20 comments
Closed

Scale up delayed by Cluster Autoscaler for large request #3835

nshekhar221 opened this issue Jan 21, 2021 · 20 comments
Labels
area/cluster-autoscaler kind/bug Categorizes issue or PR as related to a bug. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed.

Comments

@nshekhar221
Copy link

Which component are you using?:

cluster-autoscaler

What version of the component are you using?:

1.18.2

Component version:

What k8s version are you using (kubectl version)?:

1.18.6

What environment is this in?:

AWS

What did you expect to happen?:

Cluster Autoscaler to scale the nodes on the cluster when unschedulable pods are found on the cluster.

What happened instead?:

Scaling happened by increasing the number of nodes in the AWS ASG(AutoScaling Group) after almost 4 hours from the time when unschedulable pods are detected on the cluster.

Anything else we need to know?:

  • Scaling request that gets delayed is somewhat on the larger side (from 76 nodes to around 660+ nodes)

  • Cluster Autoscaler has logged "Start refreshing cloud provider node instances cache" & "Refresh cloud provider node instances cache finished" types of logs between the time unschedulable pods detected on the cluster and the time when scaling actually happened(i.e 4 hours later).

  • No error logs are reported.

  • Scaling happened as expected before and after this 4 hours interval.
@nshekhar221 nshekhar221 added the kind/bug Categorizes issue or PR as related to a bug. label Jan 21, 2021
@alexcristi
Copy link

alexcristi commented Jan 21, 2021 •
edited
Loading

Hi! I'd like to add some more logs here. So this is what we've noticed:

  • scaled out a deployment from 1 replica to 2000
  • the cluster-autoscaler attempted to scale-out all ASGs in batches (important: we use single-az ASGs with balance-similar-node-groups flag enabled):
I0121 12:18:15.710160       1 scale_up.go:569] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 18->39 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 18->38 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 19->38 (max: 200)}]

I0121 12:20:47.911289       1 scale_up.go:569] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 39->43 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 39->42 (max: 200)}]

I0121 12:39:07.309542       1 scale_up.go:569] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 42->77 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 42->76 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 43->76 (max: 200)}]
  • after that nothing happens, the CA is just "freezing", while there are plenty of Pending pods:
$ k -n ns-personal-bunduc get pods | grep Pending | wc -l
    1732

I0121 12:39:52.010974       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-9dcgn is unschedulable
I0121 12:39:52.011052       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-s4wt8 is unschedulable
I0121 12:39:52.011057       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-hcd6f is unschedulable
I0121 12:39:52.011061       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-mr7s8 is unschedulable
I0121 12:39:52.011065       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-sp5g6 is unschedulable
I0121 12:39:52.011070       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-t779r is unschedulable
I0121 12:39:52.011075       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-gtd7g is unschedulable
I0121 12:39:52.011080       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-wqqph is unschedulable
I0121 12:39:52.011085       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-cbcd4 is unschedulable
I0121 12:39:52.011089       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-8mznw is unschedulable
I0121 12:39:52.011098       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-hfdkt is unschedulable
I0121 12:39:52.011103       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-2plp9 is unschedulable
I0121 12:39:52.011108       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-jldb5 is unschedulable
I0121 12:39:52.011112       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-chwf2 is unschedulable
I0121 12:39:52.011117       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-4kkxs is unschedulable
I0121 12:39:52.011122       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-cdm2z is unschedulable
I0121 12:39:52.011130       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-x6s7m is unschedulable
I0121 12:39:52.011641       1 scale_up.go:324] 1679 other pods are also unschedulable
I0121 12:41:07.913287       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:41:07.913327       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 21.511µs
I0121 12:42:46.313368       1 trace.go:116] Trace[1062348151]: "Reflector ListAndWatch" name:k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:212 (started: 2021-01-21 12:42:09.507581528 +0000 UTC m=+9339.499947060) (total time: 36.805761758s):
Trace[1062348151]: [36.801415686s] [36.801415686s] Objects listed
I0121 12:43:07.913424       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:43:07.913465       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 25.576µs
I0121 12:43:19.709473       1 trace.go:116] Trace[254150041]: "Reflector ListAndWatch" name:k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:212 (started: 2021-01-21 12:42:48.22763037 +0000 UTC m=+9378.219995956) (total time: 31.481805859s):
Trace[254150041]: [31.281336446s] [31.281336446s] Objects listed
I0121 12:45:08.007628       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:45:08.007722       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 56.694µs
I0121 12:47:08.007827       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:47:08.007877       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 30.698µs
I0121 12:49:08.009590       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:49:08.009645       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 31.746µs
I0121 12:51:08.009741       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:51:08.009782       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 25.281µs
I0121 12:53:08.009869       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:53:08.009914       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 25.828µs
I0121 12:55:08.010017       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:55:08.010056       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 22.818µs
I0121 12:57:08.210177       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:57:08.210215       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 24.74µs
I0121 12:59:08.307925       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 12:59:08.308008       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 58.506µs
I0121 13:01:08.308147       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 13:01:08.308196       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 31.684µs
I0121 13:03:08.308292       1 node_instances_cache.go:156] Start refreshing cloud provider node instances cache
I0121 13:03:08.308331       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 23.188µs
  • there is no 'NotTriggerScaleUp' log event on the cluster-autoscaler
$ ks logs cluster-autoscaler-574657664-hfxjj -c cluster-autoscaler | grep NotTriggerScaleUp
$

@alexcristi
Copy link

Here is a screenshot of the cluster_autoscaler_last_activity metric; as you can notice, there is no activity for hours
image

@MaciekPytel
Copy link
Contributor

Interesting. First of all, CA exposes health check endpoint based on last activity - I recommend configuring livenessProbe so that CA is automatically restarted if it gets stuck.

That being said - this looks like scale-up logic getting stuck calculating different options for scale-up, which is a fairly typical performance problem for CA. Can you share some more details about your config? The relevant information would be:

  • How many ASGs do you have in the cluster? Scale-up calculation is done sequentially for each ASG (ie. if you have 2x as many ASGs CA will take 2x time to calculate scale-up).
  • Do you use requiredDuringScheduling podAffinity or podAntiAffinity? Those are terrible for CA performance.
  • Can you share logs from when the scale-up finally happened? Or even better logs for the entire period with node instances cache, leaderelection, reflectors and other repetitive logs filtered out?

Some general thoughts:

  • Use FitsAnyNode in binpacking #3429 was not picked onto 1.18 and the issue it fixed would look very much like what you describe. So I think it's very likely this is the culprit (having more logs would help confirm this).
  • CA performance in large clusters massively depends on the implementation of a given cloud provider. We test CA at this kind of scale on GCP and it works, but that doesn't mean it works for other providers. I think AWS may be also testing their provider, but I'm not familiar with the results.

@alexcristi
Copy link

alexcristi commented Jan 22, 2021 •
edited
Loading

Thank you @MaciekPytel!

  • These are the flags we start the CA with:
$ ks logs cluster-autoscaler-574657664-bbg49 -c cluster-autoscaler
I0122 13:45:26.302044       1 flags.go:52] FLAG: --add-dir-header="false"
I0122 13:45:26.302102       1 flags.go:52] FLAG: --address=":8085"
I0122 13:45:26.302107       1 flags.go:52] FLAG: --alsologtostderr="false"
I0122 13:45:26.302112       1 flags.go:52] FLAG: --aws-use-static-instance-list="false"
I0122 13:45:26.302116       1 flags.go:52] FLAG: --balance-similar-node-groups="true"
I0122 13:45:26.302121       1 flags.go:52] FLAG: --cloud-config=""
I0122 13:45:26.302148       1 flags.go:52] FLAG: --cloud-provider="aws"
I0122 13:45:26.302152       1 flags.go:52] FLAG: --cloud-provider-gce-l7lb-src-cidrs="130.211.0.0/22,35.191.0.0/16"
I0122 13:45:26.302159       1 flags.go:52] FLAG: --cloud-provider-gce-lb-src-cidrs="130.211.0.0/22,209.85.152.0/22,209.85.204.0/22,35.191.0.0/16"
I0122 13:45:26.302166       1 flags.go:52] FLAG: --cluster-name=""
I0122 13:45:26.302170       1 flags.go:52] FLAG: --cores-total="0:320000"
I0122 13:45:26.302175       1 flags.go:52] FLAG: --estimator="binpacking"
I0122 13:45:26.302180       1 flags.go:52] FLAG: --expander="least-waste"
I0122 13:45:26.302184       1 flags.go:52] FLAG: --expendable-pods-priority-cutoff="-10"
I0122 13:45:26.302188       1 flags.go:52] FLAG: --gpu-total="[]"
I0122 13:45:26.302193       1 flags.go:52] FLAG: --ignore-daemonsets-utilization="true"
I0122 13:45:26.302197       1 flags.go:52] FLAG: --ignore-mirror-pods-utilization="false"
I0122 13:45:26.302201       1 flags.go:52] FLAG: --ignore-taint="[]"
I0122 13:45:26.302206       1 flags.go:52] FLAG: --kubeconfig=""
I0122 13:45:26.302210       1 flags.go:52] FLAG: --kubernetes=""
I0122 13:45:26.302214       1 flags.go:52] FLAG: --leader-elect="true"
I0122 13:45:26.302220       1 flags.go:52] FLAG: --leader-elect-lease-duration="15s"
I0122 13:45:26.302226       1 flags.go:52] FLAG: --leader-elect-renew-deadline="10s"
I0122 13:45:26.302231       1 flags.go:52] FLAG: --leader-elect-resource-lock="leases"
I0122 13:45:26.302236       1 flags.go:52] FLAG: --leader-elect-resource-name=""
I0122 13:45:26.302241       1 flags.go:52] FLAG: --leader-elect-resource-namespace=""
I0122 13:45:26.302245       1 flags.go:52] FLAG: --leader-elect-retry-period="2s"
I0122 13:45:26.302249       1 flags.go:52] FLAG: --log-backtrace-at=":0"
I0122 13:45:26.302256       1 flags.go:52] FLAG: --log-dir=""
I0122 13:45:26.302261       1 flags.go:52] FLAG: --log-file=""
I0122 13:45:26.302266       1 flags.go:52] FLAG: --log-file-max-size="1800"
I0122 13:45:26.302270       1 flags.go:52] FLAG: --logtostderr="true"
I0122 13:45:26.302274       1 flags.go:52] FLAG: --max-autoprovisioned-node-group-count="15"
I0122 13:45:26.302278       1 flags.go:52] FLAG: --max-bulk-soft-taint-count="10"
I0122 13:45:26.302283       1 flags.go:52] FLAG: --max-bulk-soft-taint-time="3s"
I0122 13:45:26.302287       1 flags.go:52] FLAG: --max-empty-bulk-delete="10"
I0122 13:45:26.302291       1 flags.go:52] FLAG: --max-failing-time="15m0s"
I0122 13:45:26.302296       1 flags.go:52] FLAG: --max-graceful-termination-sec="600"
I0122 13:45:26.302300       1 flags.go:52] FLAG: --max-inactivity="10m0s"
I0122 13:45:26.302305       1 flags.go:52] FLAG: --max-node-provision-time="15m0s"
I0122 13:45:26.302309       1 flags.go:52] FLAG: --max-nodes-total="0"
I0122 13:45:26.302313       1 flags.go:52] FLAG: --max-total-unready-percentage="45"
I0122 13:45:26.302318       1 flags.go:52] FLAG: --memory-total="0:6400000"
I0122 13:45:26.302323       1 flags.go:52] FLAG: --min-replica-count="0"
I0122 13:45:26.302327       1 flags.go:52] FLAG: --namespace="kube-system"
I0122 13:45:26.302331       1 flags.go:52] FLAG: --new-pod-scale-up-delay="0s"
I0122 13:45:26.302335       1 flags.go:52] FLAG: --node-autoprovisioning-enabled="false"
I0122 13:45:26.302339       1 flags.go:52] FLAG: --node-deletion-delay-timeout="2m0s"
I0122 13:45:26.302344       1 flags.go:52] FLAG: --node-group-auto-discovery="[asg:tag=k8s.io/cluster-autoscaler/enabled,kubernetes.io/cluster/ethos51-va6-master-1]"
I0122 13:45:26.302355       1 flags.go:52] FLAG: --nodes="[]"
I0122 13:45:26.302360       1 flags.go:52] FLAG: --ok-total-unready-count="3"
I0122 13:45:26.302364       1 flags.go:52] FLAG: --profiling="false"
I0122 13:45:26.302368       1 flags.go:52] FLAG: --regional="false"
I0122 13:45:26.302372       1 flags.go:52] FLAG: --scale-down-candidates-pool-min-count="50"
I0122 13:45:26.302377       1 flags.go:52] FLAG: --scale-down-candidates-pool-ratio="0.1"
I0122 13:45:26.302382       1 flags.go:52] FLAG: --scale-down-delay-after-add="30m0s"
I0122 13:45:26.302387       1 flags.go:52] FLAG: --scale-down-delay-after-delete="0s"
I0122 13:45:26.302391       1 flags.go:52] FLAG: --scale-down-delay-after-failure="3m0s"
I0122 13:45:26.302395       1 flags.go:52] FLAG: --scale-down-enabled="true"
I0122 13:45:26.302399       1 flags.go:52] FLAG: --scale-down-gpu-utilization-threshold="0.5"
I0122 13:45:26.302403       1 flags.go:52] FLAG: --scale-down-non-empty-candidates-count="30"
I0122 13:45:26.302408       1 flags.go:52] FLAG: --scale-down-unneeded-time="10m0s"
I0122 13:45:26.302412       1 flags.go:52] FLAG: --scale-down-unready-time="20m0s"
I0122 13:45:26.302416       1 flags.go:52] FLAG: --scale-down-utilization-threshold="0.85"
I0122 13:45:26.302421       1 flags.go:52] FLAG: --scale-up-from-zero="true"
I0122 13:45:26.302425       1 flags.go:52] FLAG: --scan-interval="10s"
I0122 13:45:26.302429       1 flags.go:52] FLAG: --skip-headers="false"
I0122 13:45:26.302433       1 flags.go:52] FLAG: --skip-log-headers="false"
I0122 13:45:26.302437       1 flags.go:52] FLAG: --skip-nodes-with-local-storage="false"
I0122 13:45:26.302442       1 flags.go:52] FLAG: --skip-nodes-with-system-pods="true"
I0122 13:45:26.302446       1 flags.go:52] FLAG: --stderrthreshold="2"
I0122 13:45:26.302451       1 flags.go:52] FLAG: --unremovable-node-recheck-timeout="5m0s"
I0122 13:45:26.302455       1 flags.go:52] FLAG: --v="2"
I0122 13:45:26.302460       1 flags.go:52] FLAG: --vmodule=""
I0122 13:45:26.302464       1 flags.go:52] FLAG: --write-status-configmap="true"
I0122 13:45:26.302471       1 main.go:367] Cluster Autoscaler 1.18.2
  • We have 15 different ASGs (5 groups * 3 AZs):
I0122 13:46:02.300294       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF
I0122 13:46:02.300322       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51
I0122 13:46:02.300333       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC
I0122 13:46:02.300343       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCrio1AutoScalingGroup-155CVQQ3N0QKN
I0122 13:46:02.300348       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCrio2AutoScalingGroup-RQIP441DY0Z2
I0122 13:46:02.300353       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCrio3AutoScalingGroup-9ZPTVKSF6YE0
I0122 13:46:02.300358       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCustomVip1AutoScalingGroup-4WV3BD9ZMG9F
I0122 13:46:02.300364       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCustomVip2AutoScalingGroup-12KX2RIOEV1LN
I0122 13:46:02.300369       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerCustomVip3AutoScalingGroup-14JKFS36RF8C
I0122 13:46:02.300379       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerMemoryOptimized1AutoScalingGroup-HZ29CDLXR4RD
I0122 13:46:02.300383       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerMemoryOptimized2AutoScalingGroup-F13YHGVDWOLL
I0122 13:46:02.300387       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerMemoryOptimized3AutoScalingGroup-10UGL6V4N6EC6
I0122 13:46:02.300391       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerSpot1AutoScalingGroup-1KE5A4XEB8JZ7
I0122 13:46:02.300399       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerSpot2AutoScalingGroup-A8JKXRNTWNZU
I0122 13:46:02.300404       1 auto_scaling_groups.go:136] Registering ASG ethos51-sbx-va6-k8s-compute-1-workerSpot3AutoScalingGroup-1K0ZATX06WA1I
I0122 13:46:02.300410       1 aws_manager.go:269] Refreshed ASG list, next refresh after 2021-01-22 13:47:02.300407758 +0000 UTC m=+96.696784539
  • for the deployment that we massively scaled out we did not use any of the affinity settings, and there were not that many other deployments on the cluster (this is out of a reproduction/exercise cluster). But in production, we do use pod topology spread constraints.
  • I will reproduce the behavior again and will come back with additional logging as soon as I have it.

About #3429, thank you for sharing it! Do you have an ETA for when will it be released?

L.E. - I am repro-ing this again, and what I notice is a spike in the number of unregistered nodes:
image

Only 54 nodes out of 146 are considered ready by CA

$ kn | grep worker | grep Ready | wc -l
     146

image

@alexcristi
Copy link

alexcristi commented Jan 22, 2021 •
edited
Loading

Also, I don't think the liveness probe will help here as restarting the CA does not recover it from the "freeze" state. Here are the logs after restart:

$ ks logs cluster-autoscaler-574657664-hffl2  -c cluster-autoscaler | grep -v "Refresh cloud" | grep -v "Start refreshing"
I0122 14:41:32.813712       1 aws_manager.go:269] Refreshed ASG list, next refresh after 2021-01-22 14:42:32.813709708 +0000 UTC m=+106.895399108
I0122 14:41:32.813925       1 main.go:274] Registered cleanup signal handler
W0122 14:41:42.911503       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911518       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911521       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911524       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911526       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911528       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911531       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911533       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911548       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911550       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911553       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911557       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911560       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911564       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
W0122 14:41:42.911567       1 clusterstate.go:436] AcceptableRanges have not been populated yet. Skip checking
I0122 14:41:42.912100       1 static_autoscaler.go:311] 6 unregistered nodes present
I0122 14:41:52.707141       1 scale_up.go:322] Pod canary/canary-gpu-5bdbf4f5c-sq4zl is unschedulable
I0122 14:41:52.707159       1 scale_up.go:322] Pod canary/canary-gpu-5bdbf4f5c-8s9j9 is unschedulable
I0122 14:41:52.707162       1 scale_up.go:322] Pod canary/canary-gpu-5bdbf4f5c-rpx9z is unschedulable
I0122 14:41:52.707165       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-7qq2m is unschedulable
I0122 14:41:52.707168       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-xx7rt is unschedulable
I0122 14:41:52.707170       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-w9zw8 is unschedulable
I0122 14:41:52.707173       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-fpf6v is unschedulable
I0122 14:41:52.707176       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-5vj5m is unschedulable
I0122 14:41:52.707179       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-hbp92 is unschedulable
I0122 14:41:52.707182       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-9wmpb is unschedulable
I0122 14:41:52.707185       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-bmkrx is unschedulable
I0122 14:41:52.707187       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-tzv8m is unschedulable
I0122 14:41:52.707192       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-2j9wr is unschedulable
I0122 14:41:52.707196       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-kbwvh is unschedulable
I0122 14:41:52.707200       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-c42d4 is unschedulable
I0122 14:41:52.707204       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-slsdc is unschedulable
I0122 14:41:52.707208       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-4krdb is unschedulable
I0122 14:41:52.707212       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-7r9dp is unschedulable
I0122 14:41:52.707216       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-m6zhw is unschedulable
I0122 14:41:52.707220       1 scale_up.go:322] Pod ns-personal-bunduc/openjdk-557d7cfb8f-pn4c6 is unschedulable
I0122 14:41:52.707357       1 scale_up.go:324] 633 other pods are also unschedulable
I0122 14:41:52.913199       1 scale_up.go:284] Pod canary-gpu-5bdbf4f5c-sq4zl can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF, predicate checking error: Insufficient nvidia.com/gpu; predicateName=NodeResourcesFit; reasons: Insufficient nvidia.com/gpu; debugInfo=
I0122 14:41:52.913215       1 scale_up.go:286] 2 other pods similar to canary-gpu-5bdbf4f5c-sq4zl can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF
I0122 14:41:52.913770       1 scale_up.go:284] Pod aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59 can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF, predicate checking error: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59": pod has unbound immediate PersistentVolumeClaims; predicateName=VolumeBinding; reasons: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59": pod has unbound immediate PersistentVolumeClaims; debugInfo=
I0122 14:41:52.914315       1 scale_up.go:284] Pod aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF, predicate checking error: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw": pod has unbound immediate PersistentVolumeClaims; predicateName=VolumeBinding; reasons: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw": pod has unbound immediate PersistentVolumeClaims; debugInfo=
I0122 14:41:53.006858       1 scale_up.go:284] Pod spotapp2-5bd95fdffd-vnkfk can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF, predicate checking error: node(s) didn't match node selector; predicateName=NodeAffinity; reasons: node(s) didn't match node selector; debugInfo=
I0122 14:57:01.009265       1 scale_up.go:284] Pod canary-gpu-5bdbf4f5c-sq4zl can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51, predicate checking error: Insufficient nvidia.com/gpu; predicateName=NodeResourcesFit; reasons: Insufficient nvidia.com/gpu; debugInfo=
I0122 14:57:01.009281       1 scale_up.go:286] 2 other pods similar to canary-gpu-5bdbf4f5c-sq4zl can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51
I0122 14:57:01.009793       1 scale_up.go:284] Pod aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59 can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51, predicate checking error: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59": pod has unbound immediate PersistentVolumeClaims; predicateName=VolumeBinding; reasons: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestszxd59": pod has unbound immediate PersistentVolumeClaims; debugInfo=
I0122 14:57:01.010337       1 scale_up.go:284] Pod aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51, predicate checking error: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw": pod has unbound immediate PersistentVolumeClaims; predicateName=VolumeBinding; reasons: running "VolumeBinding" filter plugin for pod "aivtsan-test--kd-test-space-the-final-frontier-dev-kdtestscbhpw": pod has unbound immediate PersistentVolumeClaims; debugInfo=
I0122 14:57:01.106881       1 scale_up.go:284] Pod spotapp2-5bd95fdffd-vnkfk can't be scheduled on ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51, predicate checking error: node(s) didn't match node selector; predicateName=NodeAffinity; reasons: node(s) didn't match node selector; debugInfo=

$ ks logs cluster-autoscaler-574657664-hffl2  -c cluster-autoscaler | tail -n 1
I0122 15:05:33.107841       1 node_instances_cache.go:168] Refresh cloud provider node instances cache finished, refresh took 30.525µs

@MaciekPytel
Copy link
Contributor

This looks very much like CA stuck in binpacking simulation. Binpacking itself doesn't write any logs and the ~15m delay between evaluating 2 ASGs visible in logs fits well with this theory. I'm now almost sure #3429 should help a lot.

Regarding timeline - it was included in 1.20 release. Would you mind you retrying your test using CA 1.20.0? If it performs better I think it will be a good justification to cherry-pick #3429 to older releases (note: there were also other scalability improvements in 1.20, so technically I'm just making an educated guess as to which one is relevant for your case, but based on where the time is spent I'm fairly confident).

@alexcristi
Copy link

Thank you @MaciekPytel! This is very helpful! I will test with CA 1.20.0 and will get back with some results.

@nshekhar221
Copy link
Author

CA 1.20.0 seems to have helped.

I scaled out a deployment from 1 replica to 1000 with CA image v1.20.0

I0125 07:58:08.013350       1 flags.go:52] FLAG: --add-dir-header="false"
I0125 07:58:08.013391       1 flags.go:52] FLAG: --address=":8085"
I0125 07:58:08.013395       1 flags.go:52] FLAG: --alsologtostderr="false"
I0125 07:58:08.013398       1 flags.go:52] FLAG: --aws-use-static-instance-list="false"
I0125 07:58:08.013400       1 flags.go:52] FLAG: --balance-similar-node-groups="true"
I0125 07:58:08.013403       1 flags.go:52] FLAG: --balancing-ignore-label="[]"
I0125 07:58:08.013405       1 flags.go:52] FLAG: --cloud-config=""
I0125 07:58:08.013408       1 flags.go:52] FLAG: --cloud-provider="aws"
I0125 07:58:08.013410       1 flags.go:52] FLAG: --cloud-provider-gce-l7lb-src-cidrs="130.211.0.0/22,35.191.0.0/16"
I0125 07:58:08.013414       1 flags.go:52] FLAG: --cloud-provider-gce-lb-src-cidrs="130.211.0.0/22,209.85.152.0/22,209.85.204.0/22,35.191.0.0/16"
I0125 07:58:08.013418       1 flags.go:52] FLAG: --cluster-name=""
I0125 07:58:08.013420       1 flags.go:52] FLAG: --clusterapi-cloud-config-authoritative="false"
I0125 07:58:08.013422       1 flags.go:52] FLAG: --cores-total="0:320000"
I0125 07:58:08.013425       1 flags.go:52] FLAG: --estimator="binpacking"
I0125 07:58:08.013428       1 flags.go:52] FLAG: --expander="least-waste"
I0125 07:58:08.013430       1 flags.go:52] FLAG: --expendable-pods-priority-cutoff="-10"
I0125 07:58:08.013433       1 flags.go:52] FLAG: --gpu-total="[]"
I0125 07:58:08.013436       1 flags.go:52] FLAG: --ignore-daemonsets-utilization="true"
I0125 07:58:08.013438       1 flags.go:52] FLAG: --ignore-mirror-pods-utilization="false"
I0125 07:58:08.013441       1 flags.go:52] FLAG: --ignore-taint="[]"
I0125 07:58:08.013444       1 flags.go:52] FLAG: --kubeconfig=""
I0125 07:58:08.013446       1 flags.go:52] FLAG: --kubernetes=""
I0125 07:58:08.013448       1 flags.go:52] FLAG: --leader-elect="true"
I0125 07:58:08.013452       1 flags.go:52] FLAG: --leader-elect-lease-duration="15s"
I0125 07:58:08.013456       1 flags.go:52] FLAG: --leader-elect-renew-deadline="10s"
I0125 07:58:08.013458       1 flags.go:52] FLAG: --leader-elect-resource-lock="leases"
I0125 07:58:08.013467       1 flags.go:52] FLAG: --leader-elect-resource-name=""
I0125 07:58:08.013469       1 flags.go:52] FLAG: --leader-elect-resource-namespace=""
I0125 07:58:08.013472       1 flags.go:52] FLAG: --leader-elect-retry-period="2s"
I0125 07:58:08.013474       1 flags.go:52] FLAG: --log-backtrace-at=":0"
I0125 07:58:08.013480       1 flags.go:52] FLAG: --log-dir=""
I0125 07:58:08.013484       1 flags.go:52] FLAG: --log-file=""
I0125 07:58:08.013486       1 flags.go:52] FLAG: --log-file-max-size="1800"
I0125 07:58:08.013489       1 flags.go:52] FLAG: --logtostderr="true"
I0125 07:58:08.013492       1 flags.go:52] FLAG: --max-autoprovisioned-node-group-count="15"
I0125 07:58:08.013495       1 flags.go:52] FLAG: --max-bulk-soft-taint-count="10"
I0125 07:58:08.013497       1 flags.go:52] FLAG: --max-bulk-soft-taint-time="3s"
I0125 07:58:08.013500       1 flags.go:52] FLAG: --max-empty-bulk-delete="10"
I0125 07:58:08.013503       1 flags.go:52] FLAG: --max-failing-time="15m0s"
I0125 07:58:08.013505       1 flags.go:52] FLAG: --max-graceful-termination-sec="600"
I0125 07:58:08.013508       1 flags.go:52] FLAG: --max-inactivity="10m0s"
I0125 07:58:08.013511       1 flags.go:52] FLAG: --max-node-provision-time="15m0s"
I0125 07:58:08.013514       1 flags.go:52] FLAG: --max-nodes-total="0"
I0125 07:58:08.013516       1 flags.go:52] FLAG: --max-total-unready-percentage="45"
I0125 07:58:08.013519       1 flags.go:52] FLAG: --memory-total="0:6400000"
I0125 07:58:08.013522       1 flags.go:52] FLAG: --min-replica-count="0"
I0125 07:58:08.013525       1 flags.go:52] FLAG: --namespace="kube-system"
I0125 07:58:08.013527       1 flags.go:52] FLAG: --new-pod-scale-up-delay="0s"
I0125 07:58:08.013530       1 flags.go:52] FLAG: --node-autoprovisioning-enabled="false"
I0125 07:58:08.013533       1 flags.go:52] FLAG: --node-deletion-delay-timeout="2m0s"
I0125 07:58:08.013536       1 flags.go:52] FLAG: --node-group-auto-discovery="[asg:tag=k8s.io/cluster-autoscaler/enabled,kubernetes.io/cluster/ethos51-va6-master-1]"
I0125 07:58:08.013544       1 flags.go:52] FLAG: --nodes="[]"
I0125 07:58:08.013548       1 flags.go:52] FLAG: --ok-total-unready-count="3"
I0125 07:58:08.013550       1 flags.go:52] FLAG: --one-output="false"
I0125 07:58:08.013553       1 flags.go:52] FLAG: --profiling="false"
I0125 07:58:08.013555       1 flags.go:52] FLAG: --regional="false"
I0125 07:58:08.013558       1 flags.go:52] FLAG: --scale-down-candidates-pool-min-count="50"
I0125 07:58:08.013576       1 flags.go:52] FLAG: --scale-down-candidates-pool-ratio="0.1"
I0125 07:58:08.013582       1 flags.go:52] FLAG: --scale-down-delay-after-add="30m0s"
I0125 07:58:08.013585       1 flags.go:52] FLAG: --scale-down-delay-after-delete="0s"
I0125 07:58:08.013587       1 flags.go:52] FLAG: --scale-down-delay-after-failure="3m0s"
I0125 07:58:08.013590       1 flags.go:52] FLAG: --scale-down-enabled="true"
I0125 07:58:08.013592       1 flags.go:52] FLAG: --scale-down-gpu-utilization-threshold="0.5"
I0125 07:58:08.013595       1 flags.go:52] FLAG: --scale-down-non-empty-candidates-count="30"
I0125 07:58:08.013598       1 flags.go:52] FLAG: --scale-down-unneeded-time="10m0s"
I0125 07:58:08.013601       1 flags.go:52] FLAG: --scale-down-unready-time="20m0s"
I0125 07:58:08.013603       1 flags.go:52] FLAG: --scale-down-utilization-threshold="0.85"
I0125 07:58:08.013606       1 flags.go:52] FLAG: --scale-up-from-zero="true"
I0125 07:58:08.013610       1 flags.go:52] FLAG: --scan-interval="10s"
I0125 07:58:08.013612       1 flags.go:52] FLAG: --skip-headers="false"
I0125 07:58:08.013615       1 flags.go:52] FLAG: --skip-log-headers="false"
I0125 07:58:08.013618       1 flags.go:52] FLAG: --skip-nodes-with-local-storage="false"
I0125 07:58:08.013620       1 flags.go:52] FLAG: --skip-nodes-with-system-pods="true"
I0125 07:58:08.013623       1 flags.go:52] FLAG: --stderrthreshold="2"
I0125 07:58:08.013625       1 flags.go:52] FLAG: --unremovable-node-recheck-timeout="5m0s"
I0125 07:58:08.013628       1 flags.go:52] FLAG: --v="2"
I0125 07:58:08.013631       1 flags.go:52] FLAG: --vmodule=""
I0125 07:58:08.013634       1 flags.go:52] FLAG: --write-status-configmap="true"
I0125 07:58:08.013641       1 main.go:379] Cluster Autoscaler 1.20.0
I0125 07:58:08.320061       1 leaderelection.go:243] attempting to acquire leader lease kube-system/cluster-autoscaler...
I0125 07:58:25.720555       1 leaderelection.go:253] successfully acquired lease kube-system/cluster-autoscaler

Observed CA scale up logs:

$ kubectl logs cluster-autoscaler-74449cd7b8-n9fl7 -n kube-system cluster-autoscaler | grep "Final scale-up plan"
I0125 05:39:17.111137       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 1->7 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 6->7 (max: 200)}]
I0125 05:39:28.112155       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 7->19 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 7->19 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 10->18 (max: 200)}]
I0125 05:39:41.005606       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 18->31 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 19->30 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 19->30 (max: 200)}]
I0125 05:39:55.010716       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 30->45 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 30->44 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 31->44 (max: 200)}]
I0125 05:40:09.009232       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 44->61 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 44->60 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 45->60 (max: 200)}]
I0125 05:40:22.508583       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 60->75 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 60->74 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 61->74 (max: 200)}]
I0125 05:40:38.911902       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 74->89 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 74->88 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 75->88 (max: 200)}]
I0125 05:40:56.706313       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 88->102 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 88->102 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 89->101 (max: 200)}]
I0125 05:41:24.110180       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 101->114 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 102->114 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 102->113 (max: 200)}]
I0125 05:41:53.706295       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 114->119 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 114->118 (max: 200)}]
I0125 05:42:20.806896       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 118->120 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 119->120 (max: 200)}]
I0125 05:44:32.409209       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 113->122 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 120->121 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 120->121 (max: 200)}]
I0125 05:44:51.808280       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 121->154 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 122->153 (max: 200)}]
I0125 05:45:16.707751       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 153->155 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 154->155 (max: 200)}]
I0125 05:45:41.311157       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 155->173 (max: 200)}]
I0125 05:46:17.406810       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker2AutoScalingGroup-IDHHPMVTXE51 155->200 (max: 200)} {ethos51-sbx-va6-k8s-compute-1-worker3AutoScalingGroup-1F8XJE0VB64EC 173->200 (max: 200)}]
I0125 05:46:42.605735       1 scale_up.go:574] Final scale-up plan: [{ethos51-sbx-va6-k8s-compute-1-worker1AutoScalingGroup-1B6NM290ZLLSF 121->183 (max: 200)}]

No pending pods:

$ kubectl get  pods -n ns-personal-nshekhar | grep "Pending" | wc -l
       0

@nshekhar221
Copy link
Author

Also, with respect to v1.20.0, I came across one of the comment #3721 (comment).

When I try to scale app (with defined zone based DoNotSchedule topology constraint) from 1 to 1000 replicas the cluster scale up does not happen one node at a time as mentioned in the #3721 (comment). Although the scale did happen in several stages as can be seen above logs.

Are there any possible impact on scaling time etc. that we will observe for applications with zone based topology constraint defined with maxSkew: 1 ?

@alexcristi
Copy link

alexcristi commented Jan 26, 2021 •
edited
Loading

Thank you @nshekhar221 for validating it!
@MaciekPytel, as proven by Nishant, the v1.20.0 seems to produce a real improvement to our situation. Without trying to be pushy here, is there a chance for the fix to be cherry-picked for v1.18 and v1.19, please?

@nshekhar221
Copy link
Author

@MaciekPytel Gentle enquiry on the possibility of getting the fix cherry-picked for v1.18 and v1.19 ?

@nshekhar221
Copy link
Author

@MaciekPytel Can you please confirm if there is a possibility to cherry-pick the fix for v1.18 and v1.19 ?

@djsly
Copy link

djsly commented Apr 9, 2021

Also got it by this on 1.18, would love to see this cherry picked to at least 1.19!

@marwanad
Copy link
Member

Opened #4026 and #4027.

@varkey varkey mentioned this issue May 18, 2021
Merged
@fejta-bot
Copy link

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-contributor-experience at kubernetes/community.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Jul 21, 2021
@varkey
Copy link

varkey commented Aug 18, 2021

/remove-lifecycle stale

@k8s-ci-robot k8s-ci-robot removed the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Aug 18, 2021
@k8s-triage-robot
Copy link

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle stale
  • Mark this issue or PR as rotten with /lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Dec 14, 2021
@k8s-triage-robot
Copy link

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle rotten

@k8s-ci-robot k8s-ci-robot added lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. and removed lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. labels Jan 13, 2022
@k8s-triage-robot
Copy link

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Reopen this issue or PR with /reopen
  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

@k8s-ci-robot
Copy link
Contributor

@k8s-triage-robot: Closing this issue.

In response to this:

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Reopen this issue or PR with /reopen
  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/cluster-autoscaler kind/bug Categorizes issue or PR as related to a bug. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
10 participants
@jbartosik @varkey @alexcristi @djsly @marwanad @MaciekPytel @k8s-ci-robot @fejta-bot @nshekhar221 @k8s-triage-robot