Luigi: A task can run twice if it fails to create output (without error)

[lexman]

Hello,

working with your wonderfull tool, I've faced this issue : if for any reason the target should not be created (or if the task does not create any target), Luigi tries to re-run it :

#!/usr/bin/env python
#-*- coding: utf-8-*-0

import luigi

class BadlyCodedTask(luigi.Task):

    def output(self):
        return luigi.LocalTarget("BadlyCodedTask")

    def run(self):
        print "*" * 60
        print "BadlyCodedTask.run" 


class RunAll(luigi.Task):

    def requires(self):
        return BadlyCodedTask()

    def output(self):
        return luigi.LocalTarget("RunAll")

    def run(self):
        with self.output().open('w') as out_file:
            out_file.write("Done")


if __name__ == '__main__':
    luigi.run(main_task_cls=RunAll)

Produces :

lexman@dsksrv-13:~/dev/pano_forge/tests_luigi$ ./test_reduced.py --local-scheduler
DEBUG: Checking if RunAll() is complete
INFO: Scheduled RunAll() (PENDING)
DEBUG: Checking if BadlyCodedTask() is complete
INFO: Scheduled BadlyCodedTask() (PENDING)
INFO: Done scheduling tasks
DEBUG: Asking scheduler for work...
DEBUG: Pending tasks: 2
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) running   BadlyCodedTask()
************************************************************
BadlyCodedTask.run
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) done      BadlyCodedTask()
DEBUG: Asking scheduler for work...
DEBUG: Pending tasks: 1
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) running   RunAll()
ERROR: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) failed    RunAll()
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/luigi/worker.py", line 288, in _run_task
    raise RuntimeError('Unfulfilled %s at run time: %s' % (deps, ', '.join(missing)))
RuntimeError: Unfulfilled dependency at run time: BadlyCodedTask()
DEBUG: Checking if RunAll() is complete
INFO: Scheduled RunAll() (PENDING)
DEBUG: Checking if BadlyCodedTask() is complete
INFO: Scheduled BadlyCodedTask() (PENDING)
DEBUG: Asking scheduler for work...
DEBUG: Pending tasks: 2
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) running   BadlyCodedTask()
************************************************************
BadlyCodedTask.run
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) done      BadlyCodedTask()
DEBUG: Asking scheduler for work...
DEBUG: Pending tasks: 1
INFO: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) running   RunAll()
ERROR: [pid 10660] Worker Worker(salt=978716908, host=dsksrv-13, username=lexman, pid=10660) failed    RunAll()
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/luigi/worker.py", line 288, in _run_task
    raise RuntimeError('Unfulfilled %s at run time: %s' % (deps, ', '.join(missing)))
RuntimeError: Unfulfilled dependency at run time: BadlyCodedTask()
DEBUG: Asking scheduler for work...
INFO: Done

Should'nt Luigi ensure that the task is run only once, even if it fails ?

[erikbern]

No, this is expected behavior. If you have a long pipeline of tasks then if something crashes by design you should be able to resume where you left off.

[lexman]

Even without running Luigi again ? So this is an automatic retry ?

[freider]

It's an interesting problem. The task finishes successfully (without raising any exceptions), which luigi interprets as if the output should have been created. It then fails the subsequent task with "Unfulfilled dependencies" when it checks the existence of the input. I think we didn't an existence check after a task completes to avoid excessive existence polling, so so far I think it's expected behaviour. What's weird is that it re-runs the task although it has been marked as successful in the graph. A failing task will be retried if a certain amount of time has passed (not directly), but I didn't know that a successful task was actually re-scheduled as pending after being used as a dependency of something else and failing the existence check prior to execution of the other task. I think it would make sense to give those kinds of "runtime dependency" failures similar timeouts as failing tasks to avoid excessive re-runs. What do you think @erikbern?

[davidljung]

This is certainly strange behaviour - especially for someone learning Luigi - and particularly as it occurs when the tasks have MockFiles as outputs.

[Tarrasch]

Well. The luigi philosophy is that "workers knows better than the scheduler", once the user understands that this should feel natural.

[lexman]

Hello @davidljung, if you're looking at a framework that will check the outputs, have a look at (tuttle)[http://github.com/lexman/tuttle]. It will also check that the data you've already produced has not changed (edited by hand, for example), and would reprocess the data in that case.

[lqueryvg]

Luigi philosophy or not, this "re-try" behaviour does not feel natural.

It's inconsistent; it only happens when sub-tasks don't create output. For a simple task without a parent, the re-try doesn't occur.

If this is is natural and expected behaviour, where is this documented ?

[erikbern]

Feel free to update the documentation if you don't think this is natural and if it's not well documented

You can always write an empty file to some location to designate that the task was run

[lqueryvg]

@erikbern, I'm trying to say (badly) that this looks like a bug, not a documentation problem to me.
I.e. the behaviour is not described in any documentation because no-one expects it to behave this way.
For example, did you know that luigi.build() returns False, even if the task creates output on the re-try ?

In the case where are badly behaving task fails to create output on the first attempt, but succeeds on the re-try, the sequence of events is as follows:

• sub-task run() method is called, but creates no output
• task is noted as having failed
• when checking parent state, luigi calls complete() on sub-task methods to check for output
• the sub-task run() method gets called a second time (because it has no output), and successfully creates output
• luigi logs show the task as successful
• luigi.build() still returns False (presumably because the first attempt failed to create output)

[erikbern]

@lqueryvg can you submit a PR updating the documentation?

[lqueryvg]

I think I've already explained that this looks like a bug, not a documentation problem.

This slightly modified version of the OP's code illustrates the point. luigi.build() returns False even though the retry was successful (and the execution summary shows a happy face).

#!/usr/bin/env python3
#-*- coding: utf-8-*-0

import luigi
from luigi.mock import MockTarget


class BadlyCodedTask(luigi.Task):

    def output(self):
        return MockTarget("BadlyCodedTask")

    def run(self):
        if getattr(self, 'already_run', False):
            with self.output().open('w') as f:
                print('blah', file=f)
        else:
            self.already_run = True

class RunAll(luigi.Task):

    def requires(self):
        return BadlyCodedTask()

    def output(self):
        return MockTarget("RunAll")

    def run(self):
        with self.output().open('w') as out_file:
            out_file.write("Done")


if __name__ == '__main__':
    success = luigi.build((RunAll(),), local_scheduler=True)
    assert(success)

[erikbern]

So just to clarify, the "bug" you are referring to is that luigi.build returns False the second time? Yeah that sounds like a bug.

Just to be clear, it's NOT a bug that a task is run multiple times in case it doesn't produce output. At the risk of being over obvious, just want to make sure everyone is on the same page.

[lqueryvg]

Hi @erikbern,

Well I didn't really mean that, but I can see where this conversation is going...

IMO, the "automatic" re-try behaviour is the "bug".

I don't mean that tasks shouldn't be idempotent or re-runnable. I get all that, and fully agree.

But when a task fails to run or create output, it should not be re-tried; the user should have control over that.

Anyway, I can see that your mind is already set on this.

So, yes if the re-try behaviour is set in stone, then the luigi.build() return status should at least be made consistent. Along with some "Note" in the docs here or there to point out this behaviour.

FYI, I find myself supporting a large code base where sometimes task fail to produce output (a bug in our code somewhere which is proving difficult to track down) and the lack of control over this re-try is compounds the problem for us as follows: I have added event handlers to record task failures, but this re-try behaviour means that I may also have to track successes to detect a successful re-try after a failure.

[erikbern]

The problem is you need to store the state somewhere. And the design philosophy of Luigi as Elias mentioned is that the "worker knows best". That's why typically you implement this check by relying on the file system. In fact you can implement it in any way you want by using the completed() function. But the default implementation of completed() is to run the output() function and check if the output exists.

So you have full control over this behavior, you just need to be explicit about where the state is stored.

The benefit of this approach is that it's also explicit what to do if you want to re-run something – just delete the file (or whatever marker you use, could be a row in a database or anything) and then re-run the dependency graph

[erikbern]

maybe it's complete, i don't remember