Hi,

>error: slurmd error running JobId=32856108 on node(s)=bos-rndclus12: Kill task failed
Looks like some nodes were not able to successfully kill running tasks. Since the controller detected them as problematic nodes, it drained them to avoid allocating new jobs there.

It is difficult to guess the reason without more details. Could you share the slurmd.log of node bos-rndclus12 since yesterday?

Are nodes still drained?

Kind regards,
Oscar

Created attachment 30656 [details]
slurmd.log.06.06

Attached.

From: bugs@schedmd.com <bugs@schedmd.com>
Sent: Wednesday, June 7, 2023 10:49 AM
To: J.P. Waller <jwaller@Acadian-Asset.com>
Subject: [Bug 16911] Worker nodes drained

Oscar Hernández<mailto:oscar.hernandez@schedmd.com> changed bug 16911<https://bugs.schedmd.com/show_bug.cgi?id=16911>
What
Removed
Added
CC

oscar.hernandez@schedmd.com<mailto:oscar.hernandez@schedmd.com>
Comment # 1<https://bugs.schedmd.com/show_bug.cgi?id=16911#c1> on bug 16911<https://bugs.schedmd.com/show_bug.cgi?id=16911> from Oscar Hernández<mailto:oscar.hernandez@schedmd.com>

Hi,



>error: slurmd error running JobId=32856108 on node(s)=bos-rndclus12: Kill task failed

Looks like some nodes were not able to successfully kill running tasks. Since

the controller detected them as problematic nodes, it drained them to avoid

allocating new jobs there.



It is difficult to guess the reason without more details. Could you share the

slurmd.log of node bos-rndclus12 since yesterday?



Are nodes still drained?



Kind regards,

Oscar

________________________________
You are receiving this mail because:

  *   You reported the bug.



________________________________

This e-Mail and any attachments may contain privileged and confidential information. If you are not the intended recipient or have received this e-mail in error, please notify the sender immediately and destroy/delete this e-mail. You are hereby notified that any unauthorized copying, disclosure or distribution of the material in this e-mail is strictly prohibited. Confidentiality and privilege are not lost by this transmission having been sent or passed on to you in error. Acadian is not liable for any damage that may be caused by viruses or transmission errors.

This communication is for informational purposes only. It is not intended as an offer or solicitation for the purchase or sale of any security or an offer to establish an account. All information contained in this communication is not warranted as to completeness or accuracy and is subject to change without notice.

Acadian Asset Management LLC is registered as an investment adviser with the U.S. Securities and Exchange Commission. Registered Office: 260 Franklin Street, Boston, Massachusetts 02110. Our Data Protection Notice can be found at www.acadian-asset.com. Should you no longer wish to receive marketing-related materials from Acadian please email OptOut@acadian-asset.com.

________________________________

Thanks for the extra log.

This log shows that the DRAINED nodes had some jobs cancelled just before being set to DRAIN:

>[2023-06-06T22:11:08.229] [32856164.batch] error: *** JOB 32856164 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:07 ***
>[2023-06-06T22:11:08.472] [32856139.batch] error: *** JOB 32856139 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***
>[2023-06-06T22:11:08.486] [32856161.batch] error: *** JOB 32856161 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***
>[2023-06-06T22:11:08.498] [32856138.batch] error: *** JOB 32856138 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***
>[2023-06-06T22:11:09.254] [32856108.batch] error: *** JOB 32856108 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***
>[2023-06-06T22:11:09.903] [32856067.batch] error: *** JOB 32856067 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***
>[2023-06-06T22:11:10.311] [32856050.batch] error: *** JOB 32856050 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***
>[2023-06-06T22:11:10.323] [32856051.batch] error: *** JOB 32856051 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***
>[2023-06-06T22:11:10.333] [32856053.batch] error: *** JOB 32856053 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***
>[2023-06-06T22:11:10.380] [32856055.batch] error: *** JOB 32856055 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***
>[2023-06-06T22:11:10.380] [32856059.batch] error: *** JOB 32856059 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

A cluster user might have cancelled a bunch of jobs for some reason. Maybe because they were not performing as expected, or they were just stuck.

Afterwards, after aprox 90s (which I supose is your configured UnkillableStepTimeout), we can see in the log how the cancelled jobs could not be successfully killed:

>[2023-06-06T22:12:38.163] [32856164.batch] error: *** JOB 32856164 STEPD TERMINATED ON bos-rndclus12 AT 2023-06-06T22:12:37 DUE TO JOB NOT ENDING WITH SIGNALS ***

As stated in the documentation. If the process running in the jobs cannot be successfully terminated within UnkillableStepTimeout[1], the node is set to DRAIN.

So I am thinking on 2 possible reasons for that DRAINS.

1. There was some general event/problem on Tuesday, maybe affecting the shared FS, that caused running jobs in the nodes to get stuck. Making it impossible for slurmd to kill the processes.

2. There is a particular workflow from some user that gets processes stuck in some way. 

Are nodes still drained? Have they been rebooted?

If nodes have not been rebooted yet, you could try to ssh into one of the affected compute nodes, and search for active user processes. Since the process could not be killed by slurmd, it should still be running/stuck in some of the nodes, and could help us understand reason for failure.

Another idea would be to check what were the cancelled jobs actually doing. Jobs in this particular node are the ones shown in the error above. If all jobs are from the same user and executed the same program/pipeline, it could be worth investigating a bit on it.

In any case, while we investigate the possible causes, in order to get the nodes back to production. I would suggest to reboot (check for running processes first as mentioned before), and if there is no faulty hardware detected, then resume nodes so they can be allocated again. I would recommend to do a first test with just one node, and if it runs a job properly, do the rest in a bunch.

Kind regards,
Oscar

[1]https://slurm.schedmd.com/slurm.conf.html#OPT_UnkillableStepTimeout

Hi 2 more drained last night, 03 and 10.  This happened at 3AM so very unlikely it is a user cancelling jobs.  I've brought all back online.  Is there any way we can get more details on what exactly slurm doesn't like trying to kill the jobs?

From: bugs@schedmd.com <bugs@schedmd.com>
Sent: Thursday, June 8, 2023 5:09 AM
To: J.P. Waller <jwaller@Acadian-Asset.com>
Subject: [Bug 16911] Worker nodes drained

Comment # 3<https://bugs.schedmd.com/show_bug.cgi?id=16911#c3> on bug 16911<https://bugs.schedmd.com/show_bug.cgi?id=16911> from Oscar Hernández<mailto:oscar.hernandez@schedmd.com>

Thanks for the extra log.



This log shows that the DRAINED nodes had some jobs cancelled just before being

set to DRAIN:



>[2023-06-06T22:11:08.229] [32856164.batch] error: *** JOB 32856164 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:07 ***

>[2023-06-06T22:11:08.472] [32856139.batch] error: *** JOB 32856139 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***

>[2023-06-06T22:11:08.486] [32856161.batch] error: *** JOB 32856161 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***

>[2023-06-06T22:11:08.498] [32856138.batch] error: *** JOB 32856138 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***

>[2023-06-06T22:11:09.254] [32856108.batch] error: *** JOB 32856108 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:08 ***

>[2023-06-06T22:11:09.903] [32856067.batch] error: *** JOB 32856067 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

>[2023-06-06T22:11:10.311] [32856050.batch] error: *** JOB 32856050 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

>[2023-06-06T22:11:10.323] [32856051.batch] error: *** JOB 32856051 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

>[2023-06-06T22:11:10.333] [32856053.batch] error: *** JOB 32856053 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

>[2023-06-06T22:11:10.380] [32856055.batch] error: *** JOB 32856055 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***

>[2023-06-06T22:11:10.380] [32856059.batch] error: *** JOB 32856059 ON bos-rndclus12 CANCELLED AT 2023-06-06T22:11:09 ***



A cluster user might have cancelled a bunch of jobs for some reason. Maybe

because they were not performing as expected, or they were just stuck.



Afterwards, after aprox 90s (which I supose is your configured

UnkillableStepTimeout), we can see in the log how the cancelled jobs could not

be successfully killed:



>[2023-06-06T22:12:38.163] [32856164.batch] error: *** JOB 32856164 STEPD TERMINATED ON bos-rndclus12 AT 2023-06-06T22:12:37 DUE TO JOB NOT ENDING WITH SIGNALS ***



As stated in the documentation. If the process running in the jobs cannot be

successfully terminated within UnkillableStepTimeout[1], the node is set to

DRAIN.



So I am thinking on 2 possible reasons for that DRAINS.



1. There was some general event/problem on Tuesday, maybe affecting the shared

FS, that caused running jobs in the nodes to get stuck. Making it impossible

for slurmd to kill the processes.



2. There is a particular workflow from some user that gets processes stuck in

some way.



Are nodes still drained? Have they been rebooted?



If nodes have not been rebooted yet, you could try to ssh into one of the

affected compute nodes, and search for active user processes. Since the process

could not be killed by slurmd, it should still be running/stuck in some of the

nodes, and could help us understand reason for failure.



Another idea would be to check what were the cancelled jobs actually doing.

Jobs in this particular node are the ones shown in the error above. If all jobs

are from the same user and executed the same program/pipeline, it could be

worth investigating a bit on it.



In any case, while we investigate the possible causes, in order to get the

nodes back to production. I would suggest to reboot (check for running

processes first as mentioned before), and if there is no faulty hardware

detected, then resume nodes so they can be allocated again. I would recommend

to do a first test with just one node, and if it runs a job properly, do the

rest in a bunch.



Kind regards,

Oscar



[1]https://slurm.schedmd.com/slurm.conf.html#OPT_UnkillableStepTimeout

________________________________
You are receiving this mail because:

  *   You reported the bug.



________________________________

This e-Mail and any attachments may contain privileged and confidential information. If you are not the intended recipient or have received this e-mail in error, please notify the sender immediately and destroy/delete this e-mail. You are hereby notified that any unauthorized copying, disclosure or distribution of the material in this e-mail is strictly prohibited. Confidentiality and privilege are not lost by this transmission having been sent or passed on to you in error. Acadian is not liable for any damage that may be caused by viruses or transmission errors.

This communication is for informational purposes only. It is not intended as an offer or solicitation for the purchase or sale of any security or an offer to establish an account. All information contained in this communication is not warranted as to completeness or accuracy and is subject to change without notice.

Acadian Asset Management LLC is registered as an investment adviser with the U.S. Securities and Exchange Commission. Registered Office: 260 Franklin Street, Boston, Massachusetts 02110. Our Data Protection Notice can be found at www.acadian-asset.com. Should you no longer wish to receive marketing-related materials from Acadian please email OptOut@acadian-asset.com.

________________________________

I am sorry to hear that.

Next time this happens, could you check if there is any user process still running on the DRAINED nodes, before putting them back online?

In order to check what is triggering the job cancellation, could you share the slurmctld.log also from the 6th of June? It would be great if you clould also share slurm.conf.

If I cannot see anything, I might ask you to raise debug flags for a while, until this happens again. So that we can get a bit more debugging info. But for the moment with that will be enough.

Were you able to check if jobs: 32856164, 32856139, 32856161, 32856138, 32856108.. had anything in common? In the slurmd logs I can appreciate how this ones fail, but there are others which are completed without issues. Could you share the output of:

sacct -j  32856164,32856139,32856161,32856138,32856108 -o job,user,start,node,alloccpus

and then the ouput of:

sacct -j  32860531,32860666 -o job,user,start,node,alloccpus

The first ones are the jobs that could not get killed, and the second ones are jobs that finished successfully in the same node and at the same time.

Kind regards,
Oscar

Hi!

Did you notice any other problem overnight? Were you able to get any of the data requested in the previous comment?

Kind regards,
Oscar

I see a lot of processes that look like this:  

Could this be related?


root     1093125       2  0 10:29 ?        00:00:00 [kworker/53:1-cgroup_pidlist_destroy]                                                                                                    root     1093126       2  0 10:29 ?        00:00:00 [kworker/5:1-cgroup_pidlist_destroy]                                                                                                     root     1093128       2  0 10:29 ?        00:00:00 [kworker/21:2-cgroup_pidlist_destroy]                                                                                                    root     1093243       2  0 10:29 ?        00:00:00 [kworker/17:2-cgroup_pidlist_destroy]                                                                                                    root     1093245       2  0 10:29 ?        00:00:00 [kworker/51:2-cgroup_pidlist_destroy]                                                                                                    root     1093481       2  0 10:30 ?        00:00:00 [kworker/58:1-cgroup_pidlist_destroy]                                                                                                    root     1093602       2  0 10:30 ?        00:00:00 [kworker/24:2-cgroup_pidlist_destroy]                                                                                                    root     1093709       2  0 10:30 ?        00:00:00 [kworker/4:2-cgroup_pidlist_destroy]                                                                                                     root     1093912       2  0 10:30 ?        00:00:00 [kworker/16:1-cgroup_pidlist_destroy]                                                                                                    root     1093994       2  0 10:30 ?        00:00:00 [kworker/1:2-cgroup_pidlist_destroy]                                                                                                     root     1094172       2  0 10:30 ?        00:00:00 [kworker/72:1-cgroup_pidlist_destroy]                                                                                                    root     1094362       2  0 10:30 ?        00:00:00 [kworker/48:2-cgroup_pidlist_destroy]                                                                                                    root     1094402       2  0 10:30 ?        00:00:00 [kworker/9:2-cgroup_pidlist_destroy]                                                                                                     root     1094417       2  0 10:30 ?        00:00:00 [kworker/10:1-events]                                                                                                                    root     1094419       2  0 10:30 ?        00:00:00 [kworker/64:0-cgroup_pidlist_destroy]                                                                                                    root     1094468       2  0 10:30 ?        00:00:00 [kworker/7:0-cgroup_pidlist_destroy]                                                                                                     root     1094471       2  0 10:30 ?        00:00:00 [kworker/49:2-cgroup_pidlist_destroy]                                                                                                    root     1094472       2  0 10:30 ?        00:00:00 [kworker/42:2-cgroup_pidlist_destroy]                                                                                                    root     1094605       2  0 10:30 ?        00:00:00 [kworker/45:2-cgroup_pidlist_destroy]                                                                                                    root     1094686       2  0 10:30 ?        00:00:00 [kworker/88:2-cgroup_pidlist_destroy]                                                                                                    root     1094891       2  0 10:30 ?        00:00:00 [kworker/12:2-cgroup_pidlist_destroy]

Is this from a node currently running jobs, or from a drained node?
I think this could be expected in a busy node (running multiple jobs at the same time), since there could be many cgroups being destroyed. But will investigate a bit around that. 

Did you get that info at 10:30? That would mean these processes do not run for much time.

Any chance you could also share the slurmctld.log from 6/6/2023? Would like to have a reference for the slurmd I already have.

Kind regards,
Oscar

Hi,

I have been thinking about that. There is actually a way to know why nodes were set to drain. There is a slurm.conf configuration parameter UnkillableStepProgram[1]. This allows to configure a script that will be executed in a node where slurm is not able to successfully terminate some processes.

I am attaching a valid example for a script to put there (but feel free to put any commands you consider interesting there). The idea with it is to detect the job processes currently running into the node. And execute some forensics commands like: ps, lsof, strace... this information should help us figure out what were the actual processes that caused trouble.

So, in order to configure it, you should set the following in slurm.conf:

UnkillableStepProgram=/path/to/script

Note that this script must executable, and present or accessible in this path by all compute nodes in the cluster. After setting it in all nodes slurm.conf, it is enough to run: "scontrol reconfigure".

If you configure it, some file should be generated in the nodes /tmp directory when a node is automatically drained. So, next time you see a node set to drain, please, share this generated log, so we can investigate further on that.

[1]https://slurm.schedmd.com/slurm.conf.html#OPT_UnkillableStepProgram

Created attachment 30746 [details]
Unkillable script example

Attaching here the unkillable script example. Feel free to use or tune it.

Also, could you share your slurm.conf. I would like to check some other parameters.

Cheers,
Oscar

Hi,

Just checking the status of this issue. Has the situation been repeated recently?

Since things seem to be under control, I am dropping severity to 3. Feel free to increase it if necessary.

Cheers,
Oscar

Hi Oscar, the issue seems to have gone away so feel free to close out this ticket.

Good!

Closing the issue then. 

Nevertheless, I would suggest to implement an UnkillabaleStepProgram as mentioned in comment 9. It will be pretty useful if the situation of unexpectedly drained nodes appears in the future.

Kind regards,
Oscar