Ticket 2235

Can you describe the problem in a bit more detail? 

It's not clear to me what may be happening - from the description and snippets of log it looks like those jobs are simply backfilling as intended ahead of other jobs on the system?

Can you attach output from sinfo, squeue, and your slurm.conf file? sdiag doesn't tell me much here, and the reading through log without the slurm.conf and squeue status to refer to is difficult.

cheers,
- Tim

(In reply to Tim Wickberg from comment #1)
> Can you describe the problem in a bit more detail? 
> 
> It's not clear to me what may be happening - from the description and
> snippets of log it looks like those jobs are simply backfilling as intended
> ahead of other jobs on the system?

Well, it may simply be backfill behaviour.  Indeed, I have long believed that backfill is totally broken as designed.  I will explain.

My understanding is that the backfill scheduler is basically continuously walking the queue, trying every task to see if it can be scheduled yet.  If a node becomes available while it's halfway through the queue, it will schedule the next task -- even if it's nowhere near the top priority.  This is, I think we can all agree, broken behaviour for a queueing system.

You might then argue "Then you don't want backfill!  Stop using it!"

The problem with that argument is that without backfill, a single task at the top of the queue that can't be scheduled -- e.g. because it requires a licence or feature or amount of memory not currently available -- will prevent anything else from being scheduled.  Even if there are 100s of available nodes, and 100s of tasks that _can_ run, the high-priority task waiting for a specific resource blocks them all.

So with a heterogeneous cluster, where some tasks can only run on certain nodes, we need backfill (or something like it).

Normally I'm willing to put up with backfill's nonsense, because it tends to be fairly rare.  The problem that Akmal described in comment 0, however, was that it was happening A LOT.  Way more than I've ever seen.  Fully 50% of my nodes were consumed by low-priority tasks!

And it's not like those 50% of nodes all came available at once, and were scheduled in one giant backfill orgasm.  It was one at a time, the same backfill queue-jumping behaviour replayed in single file, over and over.

Furthermore, I would expect the backfill queue-jumping to be largely random: i.e. at whatever point in the queue it's reached when the node comes available, that's the task that get scheduled.  But that's not what we see in Akmal's data.  Despite there being dozens of jobs in the queue, it was always choosing consecutive tasks from the same job to jump the queue.

This suggested to me that something worse than its normal misbehaviour was at play.

> Can you attach output from sinfo, squeue, and your slurm.conf file? sdiag
> doesn't tell me much here, and the reading through log without the
> slurm.conf and squeue status to refer to is difficult.

Normally yes; I would have this all in my copious scrollback, but something crashed my machine yesterday.

I can tell you that all partitions were full (no idle nodes), and that as nodes finished these 5-10 minute tasks, they were either scheduling from a priority-600 job (correctly) or from this priority-190 job (incorrectly).

I'm willing to accept that there's not enough information at this point to pursue this with fervor, and simply note it as a data point for the future.  I'd also like to embark on a longer conversation about why backfill's design doesn't work for us, but that's probably not best done in bugzilla.

(In reply to Phil Schwan from comment #2)
> My understanding is that the backfill scheduler is basically continuously
> walking the queue, trying every task to see if it can be scheduled yet.  If
> a node becomes available while it's halfway through the queue, it will
> schedule the next task -- even if it's nowhere near the top priority.  This
> is, I think we can all agree, broken behaviour for a queueing system.

That's not how backfill works, at least not with Slurm. (I can't speak for other schedulers, but if they do such a thing I would agree that it is broken behavior.)

There's a set of locks used while running through the backfill scheduling pass. While running through node and job changes are seen by the backfill scheduler - there's no "jumping" the queue if a node was returned in the middle of schedule planning.

The bf_continue setting can lead to something vaguely related to what you suggest, but that would only be for high-priority jobs submitted while the backfill scheduler is going through the schedule plan, and would be unlikely in most circumstances.

The backfill scheduler specifically will never schedule a lower priority job if that job would impact the scheduled start time of a higher priority job.

My guess is that you may be running either with very high default time limits (or worse, no time limit), and this is leading to the backfill scheduler opportunistically running anything with a relatively short time limit. With high, or no limits, it may be that the expected start time for most of your jobs is significantly far out in the future.

> You might then argue "Then you don't want backfill!  Stop using it!"
> 
> The problem with that argument is that without backfill, a single task at
> the top of the queue that can't be scheduled -- e.g. because it requires a
> licence or feature or amount of memory not currently available -- will
> prevent anything else from being scheduled.  Even if there are 100s of
> available nodes, and 100s of tasks that _can_ run, the high-priority task
> waiting for a specific resource blocks them all.
> 
> So with a heterogeneous cluster, where some tasks can only run on certain
> nodes, we need backfill (or something like it).
> 
> Normally I'm willing to put up with backfill's nonsense, because it tends to
> be fairly rare.  The problem that Akmal described in comment 0, however, was
> that it was happening A LOT.  Way more than I've ever seen.  Fully 50% of my
> nodes were consumed by low-priority tasks!
> 
> And it's not like those 50% of nodes all came available at once, and were
> scheduled in one giant backfill orgasm.  It was one at a time, the same
> backfill queue-jumping behaviour replayed in single file, over and over.
> 
> Furthermore, I would expect the backfill queue-jumping to be largely random:
> i.e. at whatever point in the queue it's reached when the node comes
> available, that's the task that get scheduled.  But that's not what we see
> in Akmal's data.  Despite there being dozens of jobs in the queue, it was
> always choosing consecutive tasks from the same job to jump the queue.
> 
> This suggested to me that something worse than its normal misbehaviour was
> at play.

Again, this would be best described by some other mix of settings. The "queue-jumping" behavior you describe does not exist in Slurm.

> > Can you attach output from sinfo, squeue, and your slurm.conf file? sdiag
> > doesn't tell me much here, and the reading through log without the
> > slurm.conf and squeue status to refer to is difficult.
> 
> Normally yes; I would have this all in my copious scrollback, but something
> crashed my machine yesterday.
> 
> I can tell you that all partitions were full (no idle nodes), and that as
> nodes finished these 5-10 minute tasks, they were either scheduling from a
> priority-600 job (correctly) or from this priority-190 job (incorrectly).
> 
> I'm willing to accept that there's not enough information at this point to
> pursue this with fervor, and simply note it as a data point for the future. 
> I'd also like to embark on a longer conversation about why backfill's design
> doesn't work for us, but that's probably not best done in bugzilla.

If you can provide better data to look through I'm happy to verify the behavior you're seeing. Otherwise I'll go ahead and mark this as resolved/infogiven for now - you can always reopen or submit a new bug later with further details.

If you'd like to discuss some potential alternative scheduling logic here is fine, or you're welcome to email me directly (tim@schedmd.com).

- Tim

Thanks, Tim, for your detailed reply.

(In reply to Tim Wickberg from comment #3)
> 
> The bf_continue setting can lead to something vaguely related to what you
> suggest, but that would only be for high-priority jobs submitted while the
> backfill scheduler is going through the schedule plan, and would be unlikely
> in most circumstances.

Good to know; that's definitely not this situation.

> The backfill scheduler specifically will never schedule a lower priority job
> if that job would impact the scheduled start time of a higher priority job.
> 
> My guess is that you may be running either with very high default time
> limits (or worse, no time limit), and this is leading to the backfill
> scheduler opportunistically running anything with a relatively short time
> limit. With high, or no limits, it may be that the expected start time for
> most of your jobs is significantly far out in the future.

Our time limits are 1 hour for all jobs.  We can't estimate how long a task will actually take, if for no other reason than because we have a heterogeneous cluster -- i.e. runtime strongly depends on which node gets assigned!  As we're unwilling to terminate tasks after a fixed arbitrary time, it means that everything ends up set to 1h.

Would this lead to the behaviour that I describe?

I had it happen again just now -- literally as I was writing this -- albeit in a much more limited form than in comment 0.  Fortunately, the situation was fairly static at the time, with relatively few jobs on the system, and no new ones being submitted.

The three nodes onto which tasks end up incorrectly scheduled (pnod0813, pnod0815, pnod0817) are covered by two partitions (teamswanGpu and idleGpu).  teamswanGpu has a higher priority (21) than idleGpu (11).

There are three relevant jobs in this example:

100_job - priority 100 on partitions teamswanGpu,idleGpu
150_job - priority 150 on idleGpu
 50_job - priority  50 on idleGpu

In this situation, with teamswanGpu being the partition of higher priority, I would expect three tasks from the 100_job to be scheduled when those three nodes came available.

The teamswanGpu job:

> JobId=17249010 ArrayJobId=17249010 ArrayTaskId=2190 JobName=100_job
>    Priority=100 Nice=0 Account=user QOS=normal
>    JobState=PENDING Reason=Resources Dependency=(null)
>    Requeue=1 Restarts=0 BatchFlag=1 Reboot=0 ExitCode=0:0
>    RunTime=00:00:00 TimeLimit=01:00:00 TimeMin=N/A
>    SubmitTime=2015-12-16T16:01:37 EligibleTime=2015-12-16T16:01:38
>    StartTime=2016-12-20T08:28:54 EndTime=2015-12-21T09:16:04
>    PreemptTime=None SuspendTime=None SecsPreSuspend=0
>    Partition=teamswan,teamswanGpu,idle,tomo AllocNode:Sid=pud178:29605

The high-priority idleGpu job:

> JobId=17305346 ArrayJobId=17305346 ArrayTaskId=2822 JobName=150_job
>    Priority=150 Nice=0 Account=user QOS=normal
>    JobState=PENDING Reason=Resources Dependency=(null)
>    Requeue=1 Restarts=0 BatchFlag=1 Reboot=0 ExitCode=0:0
>    RunTime=00:00:00 TimeLimit=01:00:00 TimeMin=N/A
>    SubmitTime=2015-12-19T11:33:42 EligibleTime=2015-12-19T11:33:45
>    StartTime=2016-12-20T08:14:36 EndTime=2015-12-21T09:14:36
>    PreemptTime=None SuspendTime=None SecsPreSuspend=0
>    Partition=idleGpu,teamcottGpu AllocNode:Sid=pud80:1348

The low-priority idleGpu job:

> JobId=17115775 ArrayJobId=17115775 ArrayTaskId=104 JobName=50_job
>    Priority=50 Nice=0 Account=user QOS=normal
>    JobState=PENDING Reason=Resources Dependency=(null)
>    Requeue=1 Restarts=0 BatchFlag=1 Reboot=0 ExitCode=0:0
>    RunTime=00:00:00 TimeLimit=01:00:00 TimeMin=N/A
>    SubmitTime=2015-12-09T18:57:19 EligibleTime=2015-12-09T18:57:19
>    StartTime=Unknown EndTime=2015-12-21T09:03:43
>    PreemptTime=None SuspendTime=None SecsPreSuspend=0
>    Partition=idleGpu AllocNode:Sid=pud155:2818

All were submitted more than a day ago.

When those three nodes came free, these three tasks were all scheduled out-of-order (and even within job 17115775, if it were operating in proper priority order, why would it not take 3 consecutive tasks?  93-101 remained pending.)

> idleGpu         50         50_job       user  R       0:08      1 pnod0813        17115775_92
> idleGpu         50         50_job       user  R       0:08      1 pnod0815        17115775_102
> idleGpu         50         50_job       user  R       0:08      1 pnod0817        17115775_103

When I requeued them, the nodes were then assigned to tasks from the 150_job:

> idleGpu         150        150_job      user  R      25:31      1 pnod0813        17305346_2036
> idleGpu         150        150_job      user  R      25:31      1 pnod0815        17305346_2037
> idleGpu         150        150_job      user  R      25:31      1 pnod0817        17305346_2038

From slurmctld.log:

> [2015-12-21T08:03:43.014] backfill: Started JobId=17115775_92 (17305337) on pnod0813
> [2015-12-21T08:03:43.017] backfill: Started JobId=17115775_102 (17317739) on pnod0815
> [2015-12-21T08:03:43.024] backfill: Started JobId=17115775_103 (17317740) on pnod0817
> ...
> [2015-12-21T08:04:02.313] Requeuing JobID=17115775_103(17317740) State=0x0 NodeCnt=0
> [2015-12-21T08:04:02.314] Requeuing JobID=17115775_92(17305337) State=0x0 NodeCnt=0
> [2015-12-21T08:04:02.314] Requeuing JobID=17115775_102(17317739) State=0x0 NodeCnt=0
> ...
> [2015-12-21T08:04:33.073] backfill: Started JobId=17305346_2036 (17317749) on pnod0813
> [2015-12-21T08:04:33.078] backfill: Started JobId=17305346_2037 (17317750) on pnod0815
> [2015-12-21T08:04:33.084] backfill: Started JobId=17305346_2038 (17317751) on pnod0817

I'm very happy to send sinfo, squeue, and slurm.conf, but as they contain some potentially-sensitive information about users and jobs, I'd prefer to send them outside of the public bugzilla.

Is there anything else I should gather while the event is fresh?

There are two DebugFlags that may shed some light - "backfill" and "backfillmap". Note that these will generate a considerable amount of output, you'd likely only want them on briefly using "scontrol setdebugflags +backfill" (then -backfill to disable).

If you see this happen again, output from `sinfo`, `squeue`, `scontrol show nodes`, `scontrol show jobs` plus the logs for slurmctld would be helpful. Emailing them to me is fine.

I'm checking back in on open bugs - has this recurred in the past few weeks?

It definitely has, but so unpredictably that I'm not sure yet how to capture it in the logs (short of enabling backfill{,map} full-time, which I'm not sure is practical...)

I may go ahead and enable them the next time our cluster is a little quieter.  It's chockablock right now.

If you have "group" limits by association or QOS (e.g. total number of running jobs by group), a heuristic in Slurm's backfills scheduler could have been responsible for this. The relevant patch is here:
https://github.com/SchedMD/slurm/commit/3ee1632f96e943227365429db4e58d5467bc1a2a.patch

(In reply to Moe Jette from comment #9)
> If you have "group" limits by association or QOS (e.g. total number of
> running jobs by group), a heuristic in Slurm's backfills scheduler could
> have been responsible for this.

A good one to fix, but nope, we're not doing any group limits.

I'll spend some time this week trying to reproduce it on one of our quieter clusters where I can turn the logging all the way up.

Any luck reproducing this?

I'm going to go ahead and mark this as infogiven for now. Please re-open when/if this reoccurs.

Yep, fair enough.  I wasn't able to reproduce on a different, more-idle cluster, so I suspect I'll just have to do it on our big one and cope with the massive log output.