Aws-parallelcluster: cfnCluter 1.6.1 not honoring maintain_initial_size

[xzy3]

I recently updated to cfnCluster 1.6.1 and have noticed that the autoscaling is not honoring maintain_initial_size. This only seems to happen when the cluster is collapsing down from near its maximum size all the way to its minimum size. It overshoots and drops to no running nodes. Then I have to wait the several minutes for the cluster to grow back to it's intended size.

autoscale settings:

maintain_initial_size = true
initial_queue_size = 3
max_queue_size = 24

[mauri-melato]

Hi,
could you also share the scheduler and os you configured for the cluster?
Thanks

[xzy3]

Sun Grid Engine, Centos 7 with a custom AMI

[fnubalaj]

@xzy3: What does the custom_ami do? I mean, how long do you expect it to take to boot and come to a healthy state? Do you see this inordinate amount of time delay even with the amis that come with parallelcluster(cfncluster)

[xzy3]

I'm not entirely certain of everything the ami does, I didn't do the build out. It's was created to comply with the security policies of the agency I work for.

[xzy3]

This just happened again today. I also found a related/possibly different bug caused at
jobwatcher.py L177 for Grid Engine. If the cluster collapse to zero execution hosts you can no longer submit jobs. All tasks will be rejected with a "unknown queue all.q" (according to this). My production cluster got into this state and we redeployed to fix it.

[fnubalaj]

Thanks for reporting this issue.

Could you please verify that the when your cluster collapses to zero, it is actually preceded by a scale up operation. The only way we were able to reproduce this issue is when the cluster was scaling up (and there are no jobs in the queue), some nodes took it as a green signal to shutdown (hence causing the collapse).

This will heal itself since the ASG launches more nodes to keep the minimum size. The time taken to heal might be significant based on node startup costs, which is what we are currently addressing.

However, I would like to make sure that is indeed the issue with your cluster. Please post the contents of /var/log/jobwatcher from the master node. Also, please share the order of job submissions/deletions and how many nodes are expected to join the cluster and what is the status of the job queue when the nodes terminate.

In addition, what is the value of scaledown_idletime?

jobwatcher.py L177

This does not seem like a bug since ParallelCluster scales up only if there are pending jobs. If a job cannot be submitted due to some reason (scheduler constraints) and the job is not added to the pending queue, jobwatcher will not request ASG to scale up.

[xzy3]

Yes it is correlated with my scale ups. The root issue is that I have optimized my application significantly. To maximize parallelism I split the job into many independent sub pieces, each of which is much shorter than the scale up time of the system. That change reduced the makespan of my jobs to a fraction of what they originally were (5 days to 6 hours in one case on the older fixed sized cluster I had at the time). So by the time the cluster jumps to its final size the task arrays that caused it to scale up are gone. My largest tasks arrays are n^2 in the number of inputs and larger ones can have 10^6 subtasks to be run. Prerequisite tasks for these large task arrays can have 100s of subtasks which complete in during the scale-up time. But then the next step in the workflow finds a collapsed cluster and jobs are rejected.

Because of these I was much happier with the old evaluation periods algorithm of scale up/down since I could throttle the cluster scaling. We upgraded to 1.6.1 in an emergency downtime because the Chef/7zip bug from a few weeks ago brought our production cluster down.

scaledown_idletime is the default.

It is a bug if "maintain_initial_size" is false and the scheduler used is SGE. This isn't my problem since I have a min size. But once the cluster drops to zero running nodes an SGE cluster running autoscaling with 0 min size would be stuck there w/o manual intervention.

[xzy3]

jobwatcher log during a collapse

2018-12-03 16:47:14,499 INFO [jobwatcher:main] 22 jobs pending; 0 jobs running
2018-12-03 16:47:14,983 INFO [jobwatcher:main] min/desired/max 3/23/100
2018-12-03 16:47:14,983 INFO [jobwatcher:main] Nodes requested 22, Nodes running 0
2018-12-03 16:47:14,983 INFO [jobwatcher:main] 22 nodes desired 23 nodes in asg. Noop
2018-12-03 16:48:15,033 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:48:15,034 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:48:15,056 INFO [jobwatcher:main] 22 jobs pending; 0 jobs running
2018-12-03 16:48:15,648 INFO [jobwatcher:main] min/desired/max 3/23/100
2018-12-03 16:48:15,648 INFO [jobwatcher:main] Nodes requested 22, Nodes running 0
2018-12-03 16:48:15,648 INFO [jobwatcher:main] 22 nodes desired 23 nodes in asg. Noop
2018-12-03 16:49:15,709 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:49:15,709 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:49:15,732 INFO [jobwatcher:main] 22 jobs pending; 0 jobs running
2018-12-03 16:49:16,168 INFO [jobwatcher:main] min/desired/max 3/23/100
2018-12-03 16:49:16,168 INFO [jobwatcher:main] Nodes requested 22, Nodes running 0
2018-12-03 16:49:16,168 INFO [jobwatcher:main] 22 nodes desired 23 nodes in asg. Noop
2018-12-03 16:50:16,179 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:50:16,179 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:50:16,202 INFO [jobwatcher:main] 20 jobs pending; 2 jobs running
2018-12-03 16:50:16,542 INFO [jobwatcher:main] min/desired/max 3/23/100
2018-12-03 16:50:16,542 INFO [jobwatcher:main] Nodes requested 20, Nodes running 2
2018-12-03 16:50:16,542 INFO [jobwatcher:main] 22 nodes desired 23 nodes in asg. Noop
2018-12-03 16:51:16,599 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:51:16,600 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:51:16,624 INFO [jobwatcher:main] 0 jobs pending; 1 jobs running
2018-12-03 16:52:16,663 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:52:16,664 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:52:16,690 INFO [jobwatcher:main] 0 jobs pending; 15 jobs running
2018-12-03 16:53:16,732 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:53:16,733 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:53:16,759 INFO [jobwatcher:main] 0 jobs pending; 14 jobs running
2018-12-03 16:54:16,764 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:54:16,765 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:54:16,792 INFO [jobwatcher:main] 0 jobs pending; 10 jobs running
2018-12-03 16:55:16,797 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:55:16,798 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:55:16,823 INFO [jobwatcher:main] 0 jobs pending; 6 jobs running
2018-12-03 16:56:16,865 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:56:16,866 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:56:16,892 INFO [jobwatcher:main] 18 jobs pending; 0 jobs running
2018-12-03 16:56:17,250 INFO [jobwatcher:main] min/desired/max 3/23/100
2018-12-03 16:56:17,250 INFO [jobwatcher:main] Nodes requested 18, Nodes running 0
2018-12-03 16:56:17,250 INFO [jobwatcher:main] 18 nodes desired 23 nodes in asg. Noop
2018-12-03 16:57:17,271 INFO [jobwatcher:get_vcpus_from_pricing_file] Instance t2.medium has 2 vcpus.
2018-12-03 16:57:17,272 INFO [jobwatcher:get_instance_properties] Instance t2.medium will use number of vcpus as slots based on configuration.
2018-12-03 16:57:17,297 INFO [jobwatcher:main] 0 jobs pending; 0 jobs running

Job rejected during the collapse

Dec  3 16:51:17 ip-xxx-xxx-xxx-xxx stantz: drmaa.errors.DeniedByDrmException: code 17: Job was rejected because job requests unknown queue "all.q"

[xzy3]

For anyone facing this problem I implemented a fairly simple work around that keeps the jobs from being rejected while the root cause is worked on. Make the master/head node an execution host but give it zero slots so that nothing can schedule on it.

cd /opt/sge/
./install_execd 
qconf -mattr hostgroup hostlist $(hostname) @allhosts
qconf -mattr queue slots [$(hostname)=0] all.q

[fnubalaj]

Thank you for the workaround. Your issue seems to be in line with our understanding of the bug. We are working on this. We will also try and get a more permanent fix to schedule jobs with 0 compute nodes.

[enrico-usai]

We totally refactored the scaling logic starting from 2.4.0 so I'm going to close this old issue. Feel free to open a new one if you encounter similar issues.

Thanks