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

Autoscaler does nothing during the main loop #2396

Closed
wccsama opened this issue Sep 29, 2019 · 4 comments
Closed

Autoscaler does nothing during the main loop #2396

wccsama opened this issue Sep 29, 2019 · 4 comments

Comments

@wccsama
Copy link
Contributor

wccsama commented Sep 29, 2019 •
edited
Loading

Hi~
During a scaling up process, I find that Autoscaler just starts main loop with printing nothing.
After 8 minutes, it works again. Here is the log:

I0929 06:59:22.973759 1 static_autoscaler.go:187] Starting main loop
I0929 06:59:32.974630 1 static_autoscaler.go:187] Starting main loop
I0929 06:59:42.975598 1 static_autoscaler.go:187] Starting main loop
I0929 06:59:47.633903 1 node_instances_cache.go:155] Start refreshing cloud provider node instances cache
I0929 06:59:48.097049 1 node_instances_cache.go:167] Refresh cloud provider node instances cache finished, refresh took 463.098664ms
I0929 06:59:52.976641 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:02.977683 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:12.978935 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:22.979751 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:32.980702 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:32.981722 1 baiducloud_auto_scaling_groups.go:68] instancesNotInManagedAsg
I0929 07:00:42.982043 1 static_autoscaler.go:187] Starting main loop
I0929 07:00:52.993055 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:02.994114 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:13.001599 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:23.100220 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:33.101235 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:43.102403 1 static_autoscaler.go:187] Starting main loop
I0929 07:01:48.097296 1 node_instances_cache.go:155] Start refreshing cloud provider node instances cache
I0929 07:01:48.435864 1 node_instances_cache.go:167] Refresh cloud provider node instances cache finished, refresh took 338.525071ms
I0929 07:01:53.103639 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:03.104850 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:13.106017 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:23.196832 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:33.198433 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:43.199651 1 static_autoscaler.go:187] Starting main loop
I0929 07:02:53.204114 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:00.305937 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:312: Watch close - *v1.DaemonSet total 541 items received
I0929 07:03:03.205758 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:10.505242 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:348: Watch close - *v1.StatefulSet total 0 items received
I0929 07:03:13.208309 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:23.209712 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:27.401846 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:330: Watch close - *v1.Job total 0 items received
I0929 07:03:33.302956 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:43.693196 1 static_autoscaler.go:187] Starting main loop
I0929 07:03:47.596427 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Pod total 6568 items received
I0929 07:03:48.436181 1 node_instances_cache.go:155] Start refreshing cloud provider node instances cache
I0929 07:03:48.818744 1 node_instances_cache.go:167] Refresh cloud provider node instances cache finished, refresh took 382.514551ms
I0929 07:03:51.286564 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.ReplicaSet total 110 items received
I0929 07:03:52.501684 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.StorageClass total 0 items received
I0929 07:03:53.694915 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:03.696071 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:11.497306 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Service total 0 items received
I0929 07:04:11.604504 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:339: Watch close - *v1.ReplicaSet total 116 items received
I0929 07:04:13.793527 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:14.499987 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 0 items received
I0929 07:04:22.287500 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.StatefulSet total 0 items received
I0929 07:04:23.794901 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:33.796087 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:41.288539 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.PodDisruptionBudget total 0 items received
I0929 07:04:43.797513 1 static_autoscaler.go:187] Starting main loop
I0929 07:04:48.096677 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:301: Watch close - *v1beta1.PodDisruptionBudget total 0 items received
I0929 07:04:52.006982 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:246: Watch close - *v1.Node total 9383 items received
I0929 07:04:53.798666 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:03.799891 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:07.287089 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.ReplicationController total 0 items received
I0929 07:05:13.807473 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:15.600600 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:321: Watch close - *v1.ReplicationController total 0 items received
I0929 07:05:23.899576 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:33.900749 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:43.994047 1 static_autoscaler.go:187] Starting main loop
I0929 07:05:48.819002 1 node_instances_cache.go:155] Start refreshing cloud provider node instances cache
I0929 07:05:49.180945 1 node_instances_cache.go:167] Refresh cloud provider node instances cache finished, refresh took 361.900458ms
I0929 07:05:53.995766 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:00.006913 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:212: Watch close - *v1.Pod total 1526 items received
I0929 07:06:03.997080 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:07.296983 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:188: Watch close - *v1.Pod total 7684 items received
I0929 07:06:10.500948 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolumeClaim total 0 items received
I0929 07:06:14.099547 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:24.294730 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:34.395101 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:44.401021 1 static_autoscaler.go:187] Starting main loop
I0929 07:06:51.285908 1 reflector.go:385] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.Node total 11867 items received
I0929 07:06:54.497201 1 static_autoscaler.go:187] Starting main loop
I0929 07:07:04.501599 1 static_autoscaler.go:187] Starting main loop
I0929 07:07:14.506130 1 static_autoscaler.go:187] Starting main loop
I0929 07:07:23.000707 1 reflector.go:385] k8s.io/autoscaler/cluster-autoscaler/utils/kubernetes/listers.go:246: Watch close - *v1.Node total 12528 items received
I0929 07:07:24.594554 1 static_autoscaler.go:187] Starting main loop
I0929 07:07:34.596573 1 static_autoscaler.go:187] Starting main loop
I0929 07:07:44.598666 1 static_autoscaler.go:187] Starting main loop

environment:
kubernetes: 1.13.10
Autoscaler: 1.15 beta
the number of the workers: 200
just one Autoscaler pod works on the master.
@wccsama wccsama closed this as completed Sep 29, 2019
@wccsama wccsama reopened this Sep 30, 2019
@wccsama
Copy link
Contributor Author

wccsama commented Sep 30, 2019

It may be that the parameter "kube-api-qps" is setted to 5..

@seh
Copy link

seh commented Oct 2, 2019

This sounds like #2345, modulo the cluster autoscaler version difference.

@wccsama
Copy link
Contributor Author

wccsama commented Oct 28, 2019

I think this may caused by request restrictions. Version difference may also be the reason. I will continue to work on it.

@wccsama
Copy link
Contributor Author

wccsama commented Nov 7, 2019 •
edited
Loading

I have already find the reason. It has relationship with adding node time.

@wccsama wccsama closed this as completed Nov 7, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@seh @wccsama