Commit ea3c31fe authored by Morris Jette's avatar Morris Jette
Browse files

select/cray: fix race condition

select/cray: fix race condition when canceling job during batch launch

This fixes a race condition which occurs when a job is cancelled during batch launch.
It is a bug since the condition causes the frontend node to be set in state DRAINING.

The fix is in catching this particular condition and isolating it as a non-fatal
error. This ensures continued robustness of operation, by not draining the entire
frontend node.

Short logfile dump of condition:
================================
 [2011-05-19T17:20:41] ALPS RESERVATION #2878, JobId 76343: BASIL -n 60 -N 0 -d 1 -m 1333
 [2011-05-19T17:20:41] backfill: Started JobId=76343 on nid0[1037,1549,1805,2061,2317]
 [2011-05-19T17:20:43] sched: Cancel of JobId=76343 by UID=21329, usec=389791
 [2011-05-19T17:20:45] error: slurmd error 4014 running JobId=76343 on front_end=rosa2: Slurmd could not set up environment for batch job
 [2011-05-19T17:20:45] update_front_end: set state of rosa2 to DRAINING

 apsched0519:
 17:20:41: File new reservation resId 2878 pagg 0
 17:20:41: Confirmed apid 125156 resId 2878 pagg 0 nids: 1037,1549,1805,2061,2317
 17:20:43: ...cancel_msg:249: cancel reservation resId 2878
 17:20:43: Canceled apid 125156 resId 2878 pagg 0
 17:20:45: type bind uid 0 gid 0 apid 0 pagg 13516639560892680485 resId 2878 numCmds 0
 17:20:45: placeApp message:0x1 cannot find resId 2878

 frontend node: rosa2.log
 [2011-05-19T17:20:41] Launching batch job 76343 for UID 21329
 [2011-05-19T17:20:45] Job 76343 killed while launch was in progress
 [2011-05-19T17:20:45] [76343] *** JOB 76343 CANCELLED AT 2011-05-19T17:20:45 ***
 [2011-05-19T17:20:45] [76343] PERMANENT ALPS BACKEND error: ALPS error: cannot find resId 2878
 [2011-05-19T17:20:45] [76343] confirming ALPS resId 2878 of JobId 76343 FAILED: ALPS backend error
 [2011-05-19T17:20:45] [76343] could not confirm ALPS reservation #2878
 [2011-05-19T17:20:45] [76343] job_manager exiting abnormally, rc = 4014

Detailed analysis:
==================
The slurmctld first created a reservation in select_nodes() -> select_g_job_begin() -> do_basil_reserve():
 [2011-05-19T10:56:19] ALPS RESERVATION #2511, JobId 74991: BASIL -n 12 -N 0 -d 1 -m 1333
 [2011-05-19T10:56:19] backfill: Started JobId=74991 on nid01347

 10:56:19: File new reservation resId 2511 pagg 0
 10:56:19: Confirmed apid 123762 resId 2511 pagg 0 nids: 1347

The next call after select_nodes() in backfill.c:_start_job() was launch_job(), which on the
slurmd node rosa12 produced the following message in _rpc_batch_job() upon receipt
of REQUEST_BATCH_JOB_LAUNCH:

 [2011-05-19T10:56:19] Launching batch job 74991 for UID 21487

This caused the launch_mutex to be taken and then the subsequent rc = _forkexec_slurmstepd().
While this was in operation, the user decided to scancel his job, apparently with the default SIGTERM:

 [2011-05-19T10:56:20] sched: Cancel of JobId=74991 by UID=21487, usec=358632
 [2011-05-19T10:56:20] sched: Cancel of JobId=74994 by UID=21487, usec=783954

This was in _slurm_rpc_job_step_kill() upon receiving REQUEST_CANCEL_JOB_STEP from scancel.
While the slurmstepd was preparing the job steps, it signalled cancellation

 [2011-05-19T10:56:20] [74991] *** JOB 74991 CANCELLED AT 2011-05-19T10:56:20 ***

via _rpc_signal_tasks() of the slurmd. Most likely this was from slurmctld:job_signal() -> _signal_batch_job(),
which means that the reservation had already been cancelled via select_g_job_signal() -> do_basil_release():

 10:56:20: ...cancel_msg:249: cancel reservation resId 2511
 10:56:20: type cancel uid 0 gid 0 apid 0 pagg 0 resId 2511 numCmds 0
 10:56:20: Canceled apid 123762 resId 2511 pagg 0

Meanwhile the slurmstepd continued to run by starting job_manager():
 [2011-05-19T10:56:20] [74991] PERMANENT ALPS BACKEND error: ALPS error: cannot find resId 2511
 [2011-05-19T10:56:20] [74991] confirming ALPS resId 2511 of JobId 74991 FAILED: ALPS backend error
 [2011-05-19T10:56:20] [74991] could not confirm ALPS reservation #2511
 [2011-05-19T10:56:20] [74991] job_manager exiting abnormally, rc = 4014

where the ALPS BACKEND error happened at the begin of job_manager(), in  rc = _select_cray_plugin_job_ready(job),
which returned the result from select_g_job_ready() -> do_basil_confirm(). The return result was READY_JOB_FATAL,
since the ALPS error was not a transient error.

Back in slurmstepd, the READY_JOB_FATAL was translated into ESLURMD_SETUP_ENVIRONMENT_ERROR, which then caused
the node to drain.

Detailed description of fix
===========================
The fix is by
 * catching the condition "reservation ID not found" in the BasilResponse as 'BE_NO_RESID'
   (which is already used to catch errors calling RELEASE more than 1 time);
 * interpreting the return of BE_NO_RESID as non-serious error condition during CONFIRM.

If the "reservation ID not found" was indeed caused due to the race condition, the fix will prevent ALPS
from introducing further complications (such as draining the node). If there is a separate ALPS problem
behind it (which is not expected), jobs will continue to run, but without ALPS support (all aprun
requests would fail). Such a condition (fixing ALPS issues) would need to be handled separately.
Based upon 03_Cray_BUG-Fix_race-condition-on-job-cancel.diff by Gerrit Renker, CSCS
parent 0d9f3480
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment