Tasks waiting to run are silently aborted if a later task fails compile stage, with async policy

[sleak-lbl]

This might be related to #1121 and/or #507

When using the AsynchronousExecutionPolicy, a task failure at the compile if a tasks fails at the compile_wait step can lead to reframe exiting while earlier queued jobs are still waiting to run.

I think the root cause is in reframe/frontend/executors/policies.py -> class AsynchronousExecutionPolicy(ExecutionPolicy, TaskEventListener) -> def _reschedule(self, task):, compile_wait can throw a variety of compile-time errors that should fail the task, but not abort the reframe run.

I have a patch that I think fixes this, will post an PR shortly

[vkarak]

Hi @sleak-lbl, do you have a reproducer? Or have you identified a sequence of execution that would trigger that? I'll have a look into your PR and get back to you.

[sleak-lbl]

sort of, but it's complicated and depends on the UPC support that I've made a separate PR for (#1333) .. the error occurred with a combination of circumstances:

• a large number of tests being run compared to the max_jobs setting in ReframeSettings
• some of the later tests failing at compile time
• the (NERSC Cori) job queue being slow enough that "run" stage jobs that had been submitted were still waiting in the queue when the later tests failed

(it doesn't happen every time, but on Cori with enough tests backed up it happened most runs. Colleages commented that they had seem the same thing and worked around it but using the serial policy)

I littered my clone of Reframe with traceback dumps, and identified that one of my compile fails was because of a Environment Modules module conflict, but it was causing RegressionTask._safe_call to raise a TaskExit:

    def _safe_call(self, fn, *args, **kwargs):
        if fn.__name__ != 'poll':
            self._current_stage = fn.__name__

        try:
            with logging.logging_context(self.check) as logger:
                logger.debug('entering stage: %s' % self._current_stage)
                return fn(*args, **kwargs)
        except ABORT_REASONS:
            self.fail()
            raise
        except BaseException as e:
            self.fail()
            raise TaskExit from e

which bubbled up through AsynchronousExecutionPolicy._reschedule but wasn't caught, so continued to Runner._runall which calls policy.exit(). It seemed to reach a loop that calls _reschedule_all, but skipped to the end of the loop and exited Reframe, despite jobs still being in the queue.

For a while I suspected this block of core/pipeline.py in RegressionTest:

    @_run_hooks('post_compile')
    def compile_wait(self):
        '''Wait for compilation phase to finish.

        .. versionadded:: 2.13
        '''
        self._build_job.wait()
        self.logger.debug('compilation finished')

        # FIXME: this check is not reliable for certain scheduler backends
        if self._build_job.exitcode != 0:
            raise BuildError(self._build_job.stdout, self._build_job.stderr)

.. and it turned out not to be the source of my problem, but I'm pretty sure it's capable of the same thing, because nothing catches that BuildError, that I could find

Catching the exceptions at compile_wait seems to fix it, I've had no early aborts since then

[vkarak]

Hi @sleak-lbl, did you check in which call of reschedule was the error missed? There are two places where the rescheduling happens. In the main loop that spawns the jobs of new tests as they come and at the busy-wait loop at the end. In order for the reschedule to happen in the first place, ReFrame should have reached the job limit for a partition, in which case, it will poll the running tasks and try to free execution slots, putting new ready tasks to run through the _reschedule_all().

[vkarak]

Another key concept of the async policy that might help you in identifying the problem (I'm also looking into it) is that it's event-based. When a task changes to an interesting state (e.g., enters/exits run phase, finishes with failure or success), it notifies its listeners. There is only one listener in our implementation, which is again the concrete execution policy class. The event callback functions (on_task_xxx()) are responsible for updating the different task queues. Finally, the purpose of TaskExit is to serve as a "continue-with-the-next-task" signal.

[vkarak]

Colleages commented that they had seem the same thing and worked around it but using the serial policy

Could you check whether this was always the case or appeared after a certain version?

[vkarak]

I think the problem comes either from here or here. The problem I see there is that if the task that is being rescheduled fails due to a non-fatal reason, then although it will be marked nicely as a failure, a new TaskExit will be raised (while you're addressing one already) and this will be propagated up unhandled causing ReFrame to crash. Can you try suppressing TaskExit in this context? E.g.,

with contextlib.suppress(TaskExit):
    self._reschedule(task)

[vkarak]

@sleak-lbl I was able to reproduce the problem with three synthetic tests and it seems that the solution I proposed above fixes the problem. I will push to your PR soon.