AttributeError: 'Task' object has no attribute '_callbacks'

[jabdoa2]

We occasionally get this error when building on Mac travis build. I do not understand how this can happen since _callback is defined in __init__. Any ideas what could be wrong?

Traceback (most recent call last):
  File "/usr/local/lib/python3.5/site-packages/mpf-0.31.0.dev260-py3.5.egg/mpf/tests/MpfMachineTestCase.py", line 35, in setUp
    super().setUp()
  File "/usr/local/lib/python3.5/site-packages/mpf-0.31.0.dev260-py3.5.egg/mpf/tests/MpfTestCase.py", line 249, in setUp
    raise e
  File "/usr/local/lib/python3.5/site-packages/mpf-0.31.0.dev260-py3.5.egg/mpf/tests/MpfTestCase.py", line 237, in setUp
    self.advance_time_and_run(0.01)
  File "/usr/local/lib/python3.5/site-packages/mpf-0.31.0.dev260-py3.5.egg/mpf/tests/MpfTestCase.py", line 143, in advance_time_and_run
    self.loop.run_until_complete(asyncio.sleep(delay=delta, loop=self.loop))
  File "/usr/local/Cellar/python3/3.5.2_1/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 383, in run_until_complete
    future.remove_done_callback(_run_until_complete_cb)
  File "/usr/local/Cellar/python3/3.5.2_1/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/futures.py", line 314, in remove_done_callback
    filtered_callbacks = [f for f in self._callbacks if f != fn]
AttributeError: 'Task' object has no attribute '_callbacks'

From: https://travis-ci.org/missionpinball/mpf/jobs/155786553

[Martiusweb]

Hi,

Can you show us the code of the test that fails? Is the exception triggered only on this test, or do you see it happening in other places?

[jabdoa]

This happens randomly all over the suite. About one in one hundred runs (with 500 tests in each run).

I suspect this happens because we started to use loop.run_in_executor with concurrent.futures.ThreadPoolExecutor in a task. We used the Threading module before which caused a lot of random segfaults in our suite. The segfaults are gone now. Instead we get this strange error.

[asvetlov]

Maybe you are calling asyncio code from a thread belonging to ThreadPoolExecutor?

You know, the only thread-safe operation is loop.call_soon_threadsafe(...). It means you cannot call, e.g. fut.set_result(True) from other thread but should do it as loop.call_soon_threadsafe(fut.set_result, True)

[jabdoa2]

The threaded code is really simple. It just reads and parses files.

Asyncio should warn me about those error when I set PYTHONASYNCIODEBUG to 1, right? I did run that and it did not emit any warnings. Also the error seems to originate from the main thread.

[Martiusweb]

What kind of warnings you expect with PYTHONASYNCIODEBUG=1?

It looks like a race condition since it happens randomly, but I can't see how _callbacks can be deleted from the object's attributes here, especially since future.remove_done_callback(_run_until_complete_cb) should be called almost right after the callback ran (according to what run_until_complete() does).

[gvanrossum]

We really need to look at some code to be able to debug this further. I don't believe this is due to a bug in asyncio -- it's something the OP hasn't realized is important yet (and hence hasn't shown yet). Maybe there's a subclass of Task, maybe there's a problem with threads, who knows...

Also suspect (to me) is that it happens during setUp() of some test helper class.

[jabdoa2]

We do not subclass Task. In general, we only started to use asyncio recently so we have very few coroutines and tasks so far. There is exactly one place where we use ThreadPoolExecutor: https://github.com/missionpinball/mpf/blob/dev/mpf/core/assets.py It loads only one type of assets: https://github.com/missionpinball/mpf/blob/dev/mpf/assets/show.py#L72 (which does not use any asyncio)

Everything else is not threaded. All other tasks run in the same thread.

We create a new (time travel) event loop for every test. However, that does not overload tasks. Our main test baseclass is this: https://github.com/missionpinball/mpf/blob/dev/mpf/tests/MpfTestCase.py

Our test loop is this: https://github.com/missionpinball/mpf/blob/dev/mpf/tests/loop.py

The crashing test above is from a real world pinball machine test case: https://github.com/missionpinball/mpf/blob/dev/mpf/tests/MpfMachineTestCase.py (only changes some default settings).

[gvanrossum]

That custom event loop is definitely the most suspicious thing you've mentioned.

But here's another thought. Support the call to get_event_loop() in Future.init() raises. Then you have an uninitialized Future object, but its del method might still be called.

That thought is all I have time for right now.

[jabdoa2]

The custom event loop is just for tests and its based on the one asyncio uses in its tests but we added more mocks for socket and serial port related things. Might be the cause but it should still not lead to segfaults in Python (again only randomly but much less since we remove Threading module).

We explicitly pass the event loop everywhere in the code. But its a good hint and I will just overwrite asyncio.get_event_loop() to make sure it can be never be called in the tests. I think py.test also does that.

[jabdoa2]

I verified that get_event_loop() does not get called at all during our tests. So the chance that it fails is low. Unfortunately, its hard to reproduce the failure above reliably.

[jabdoa2]

Ok found the issue (with the help of gdb):

• Start a ThreadPoolExecutor
• Call yield from loop.run_in_executor(task)
• Stop the loop in the main thread

Obviously, the problem occurs when the task returns but the loop no longer exists. Calling ThreadPoolExecutor::shutdown() before stopping the loop fixes it for me (at least i cannot reproduce it anymore). Not sure if this is still a bug then.

[asvetlov]

asyncio calls .shutdown() for default executor:

        executor = self._default_executor
        if executor is not None:
            self._default_executor = None
            executor.shutdown(wait=False)

Do you use default one or create own executor instance?

[jabdoa]

We did not overwrite anything related to tasks or ThreadPoolExecutor. When does it call that?

I ran the tests for multiple hours in a loop and it did not happen a single time after adding shutdown. Before it happened once every 5 to 30min.

[asvetlov]

This is from loop.close(): https://github.com/python/asyncio/blob/master/asyncio/base_events.py#L397-L417

Maybe you call .shutdown() with wait=True?

Unfortunately I cannot see any run_in_executor calls in https://github.com/missionpinball/mpf/

[jabdoa]

We did not overload close() also. I call shutdown() without any arguments so wait should be True.

The call is here: https://github.com/missionpinball/mpf/blob/dev/mpf/core/assets.py#L548

[asvetlov]

But here you have your own executor called self.asset_loader_threads. In this case you should shutdown it yourself.

asyncio has nothing to do with it.