Ticket 5633

Hi

Could you send me slurm.conf, output from "scontrol completing", backtrace from backup slurmctld when this problem occurs?
eg.: "gdb -batch -p $(pidof slurmctld) -ex 't a a bt'"
backtrace from one of the nodes in completing state:
eg.: "gdb -batch -p $(pidof slurmd) -ex 't a a bt'"
logs form both slurmctld and from example slurmd 

Dominik

Created attachment 7707 [details]
slurm.conf, backtraces, logs, scontrol completing command output

Requested information provided.  Thanks, Dominik.

Hi, Dominik.  Just reaching out to see if you had a chance
to look over the provided materials.  Did anything obvious
jump out at you or otherwise look unusual?  Thank you!

Hi


Sorry, I checked these materials and I am sure it is something new. It doesn’t look like any already resolved bug. Could you attach also output from sdiag? I forgot to ask for it earlier. 
Is there any reason to have TreeWidth=16 in slurm.conf?

Dominik

(In reply to Dominik Bartkiewicz from comment #6)
> Hi
> 
> 
> Sorry, I checked these materials and I am sure it is something new. It
> doesn’t look like any already resolved bug. Could you attach also output
> from sdiag? I forgot to ask for it earlier. 
> Is there any reason to have TreeWidth=16 in slurm.conf?
> 
> Dominik

Something new...darn, we were hoping for something old this
time.  :-)  

The 'TreeWidth=16' is leftover from when we were using the
topology/tree plugin.  We disabled that but forgot to remove
the TreeWidth parameter.  Thanks for pointing that out.  We
will be taking that out tomorrow morning.

We will upload sdiag output shortly.  Thanks!

Created attachment 7720 [details]
sdiag output

Hi

Has the change of TreeWidth made any difference in this behavior?
We have one similar problem with 17.11 but I am still not sure if it is related.

Dominik

We didn't notice any change after going back
to the default TreeWidth of 50.  Do you know
of any further debugging steps we can try to
uncover the problem?

Thank you!

Hi

I need more info.


Could you enable DebugFlags TraceJobs on backup slurmctld when it takes control?
Also increasing debug to debug2 on one of completing nodes will be useful.
Could you also grab series of outputs from this gdb commend generated on backup slurmctld (after it takes control and starts accumulating jobs )?
You must just replace <job_id> to one of affected jobs
(eg. 10 wit 1 sec sleep betwan)
gdb -p $(pidof slurmctld) --batch -ex 't a a bt' -ex 'call find_job_record(<job_id>)' -ex 'p *$1' >> $(date +%H_%M_%S)

Dominik

Created attachment 7767 [details]
slurm debug attachments

Hi, Dominik.

Please find attached the requested debug output.
Hope it helps shed some light.  Please let us know
if you find anything.  Nothing jumped out at me when
I looked at it (not that that amounts to anything).

Thank you!

Hi

Are you sure you have no firewall on the backup slurmctld?

Dominik

Yes, we're pretty sure no firewall is running.  I had thought
about that earlier and checked to be sure and also checked
again just now:

slurmbak# systemctl status firewalld.service  
* firewalld.service
   Loaded: masked (/dev/null; bad)
   Active: inactive (dead)

slurmbak# systemctl status iptables.service 
* iptables.service
   Loaded: masked (/dev/null; bad)
   Active: inactive (dead)

slurmbak# iptables --line-numbers -nv -L
Chain INPUT (policy ACCEPT 5357K packets, 851M bytes)
num   pkts bytes target     prot opt in     out     source               destination         

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
num   pkts bytes target     prot opt in     out     source               destination         

Chain OUTPUT (policy ACCEPT 3728K packets, 95G bytes)
num   pkts bytes target     prot opt in     out     source               destination

Hi

Like you already noticed, there is nothing really strange in logs and backtraces, but in slurmd.log there is no communication between slurmctld and slurmd.

Also, this is a little concerning
"Warning: Note very large processing time from set_slurmd_addr: usec=3651274 began=10:19:24.083"
I suspect that you already have done this,
did you check dns, routing, SELinux, sssd?
Is anything interesting in syslog on backup slurmctld host?

Could you try one more time to generate series of this backtrace for a longer period (~10s interval)?
If this is possible could you increase debug on backup slurmctld to debug2?

Dominik

Hi, Dominik.

> Also, this is a little concerning
> "Warning: Note very large processing time from set_slurmd_addr: usec=3651274 began=10:19:24.083"

Could you elaborate on why this message draws your attention?


> I suspect that you already have done this, did you check dns, routing, SELinux, sssd?

No DNS is used within the compute cluster (slurmctld's and slurmd's).
Routing appears fine as we can ping and ssh both ways between the slurmbak
host and compute nodes.
SELinux is disabled across the cluster.
No sssd is used within the compute cluster.


> Is anything interesting in syslog on backup slurmctld host?

We did not find anything interesting in the slurmbak syslog.


> Could you try one more time to generate series of this backtrace for a longer period (~10s interval)?
> If this is possible could you increase debug on backup slurmctld to debug2?

We will increase debugging to 'debug2' and generate another
series of backtraces per your suggestion.  Thank you!

Created attachment 7793 [details]
additional slurmctld debug output

Hi

Thanks for data.

The most part of set_slurmd_addr() is to call gethostbyname() for each slurmd host.
3.5  seconds for ~4000 nodes is not a critical value, but this is the reason why I asked about DNS config.


Dominik

Hi

I only want to inform you that I found something strange in bt (missing of _agent_init thread).
I still need to do more tests to understand what could cause this.

Dominik

Created attachment 7808 [details]
more debug info

Hi, Dominik.

Thanks for mentioning the absence of 'agent_init' thread.

We also have some additional information to share. We were
trying to think of ways to further test/debug the problem
and came up with the idea to sniff the network traffic 
between the slurmctld host and a compute node during a
job allocation and completion.  We did this twice:

- once running a job using the primary slurmctld (centos6)

- a second time running a job after 'scontrol takeover'
  to use the backup slurmctld (centos7)

We found that normal network communication appears to
take place between the primary slurmctld host and the
compute node.  However, in the second case, listening
for network traffic between the backup slurmctld host
and the compute node revealed no communication whatsoever.

Even stranger, the backup slurmctld eventually "allocates"
the job.  The reason the word allocates in within quotes
is because the backup slurmctld thinks it's allocated the
job to a node but when you login to the node and check
for jobs/processes or anything related to the job in the
slurmd.log, there is no trace of the job. 

We're still not exactly sure what this means but it
helps to further define the problem which hopefully
can guide us to the solution.

Thank you.

Created attachment 7809 [details]
patch

Hi

Could you try to apply this patch on backup slurmctld (it should be safe on the master too) and check if it solves this issue?

Dominik

Thank you, Dominik.  We have built a new slurmctld binary
using the patch and will be testing it on the slurmbak
host first thing in the morning.  We'll let you know how
it goes after we finish the test.

Thanks again!

Good morning, Dominik.

We'd like to let you know that the patch seems to be exactly
what was needed to get things working again, so THANK YOU!

We can now move forward with upgrading the primary controller
from a VM to bare metal.

One thing struck us as a little odd, however.  We checked the
build trees of our previous slurm versions that we used recently
and none of the controller.c files had the extra agent_init
function call; i.e., they all had a single call to agent_init.

The patch that fixed things introduced the second agent_init
function call within the 'if (!slurmctld_primary)' conditional.

The confusing part for us is that we have had several backup
controller takeovers in the past and we do not ever recall
the backup controller malfunctioning and not properly handling
the workload.  So we're curious as to why the backup controller
worked fine for all of our previous slurm builds but not this
one.  Is this something you would know?

Again, thanks for the bugfix!  :)

Hi

I'm glad to hear that.
Commit 0c3133a29287 contains this fix and it will be in 17.11.02.
https://github.com/SchedMD/slurm/commit/0c3133a29287e9cc

This is a bit tricky :)
_agent_init() is not always finished during taking over (there is some race).
But if read_slurm_conf() is taking more than 2 sec _agent_init thread will end.
 
You can also see this error "agent_init: thread already running", it means that _agent_init is still running, but this is OK.

I hardly encourage to upgrade to
17.11 or 18.08, since our support model requires customers to stay within the
last two major releases (currently 17.11 or 18.08).

If this is OK with you can we close this ticket now?

Dominik

sorry I made the typo in the last comment it should be 17.11.10, not 17.11.02.

Yes, we're definitely upgrading to a newer version now that
we can move forward with migrating the rest of our systems.
Glad to hear this patch will be in the 17.11.10 release as
that is the release we're targeting as next in line.

Also, thanks for explaining the agent_init problem.  I'd say
we can go ahead and close this ticket.

Thanks again for helping us get this resolved.

Hi

Okay, that's good to know.
I'm marking this ticket as resolved/fixed. 
As always, please feel free to reopen if you have
additional questions.

Dominik

*** Ticket 5511 has been marked as a duplicate of this ticket. ***

*** Ticket 6760 has been marked as a duplicate of this ticket. ***

*** Ticket 6767 has been marked as a duplicate of this ticket. ***