asyncio segfault when using threadpool and "_asyncio" native module

[thehesiod]

BPO	31061
Nosy	@methane, @1st1, @thehesiod
PRs	bpo-31061: fix crash in asyncio speedup module #2966 [3.6] bpo-31061: fix crash in asyncio speedup module #2984
Files	native___python_crash_stacks.txt: Python and native stack trace during segfault python crash.txt python_crash.py python crash2.txt

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2017-08-02.16:21:59.872>
created_at = <Date 2017-07-27.20:16:30.230>
labels = ['type-crash', 'expert-asyncio']
title = 'asyncio segfault when using threadpool and "_asyncio" native module'
updated_at = <Date 2017-08-07.19:32:20.767>
user = 'https://github.com/thehesiod'

bugs.python.org fields:

activity = <Date 2017-08-07.19:32:20.767>
actor = 'thehesiod'
assignee = 'none'
closed = True
closed_date = <Date 2017-08-02.16:21:59.872>
closer = 'yselivanov'
components = ['asyncio']
creation = <Date 2017-07-27.20:16:30.230>
creator = 'thehesiod'
dependencies = []
files = ['47043', '47049', '47050', '47051']
hgrepos = []
issue_num = 31061
keywords = []
message_count = 23.0
messages = ['299346', '299347', '299349', '299421', '299422', '299426', '299427', '299512', '299515', '299516', '299517', '299522', '299574', '299581', '299583', '299590', '299591', '299644', '299647', '299662', '299663', '299792', '299863']
nosy_count = 3.0
nosy_names = ['methane', 'yselivanov', 'thehesiod']
pr_nums = ['2966', '2984']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'crash'
url = 'https://bugs.python.org/issue31061'
versions = ['Python 3.5', 'Python 3.6']

[thehesiod]

I have a project in a prod environment which heavily uses asyncio and a threadpool. It uses the threadpool to run CPU heavy tasks (in this case populating a defaultdict) to avoid blocking the main thread (no async code in thread). For some time now my service has been randomly crashing at the same place in the thread which does the dict updating. I've finally got both the python and native stack traces, and based on the information presented it looked very similar to the issue found by the devs at home-assistant (home-assistant/core#7752 (comment), which points to home-assistant/core#7848). So I tried their fix of disabling the "_asyncio" module, and lo and behold python no longer segfaults.

Per the stacktrace it's crashing in PyObject_GC_Del, and the only place this is used in the asyncio module seems to be here: https://github.com/python/cpython/blob/master/Modules/_asynciomodule.c#L996

does anyone have any idea why it's crashing on this line? Are there thread protections missing in this file?

I'm trying to reproduce this in a testcase but it's proving very difficult as I'm guessing it's timing related.

[thehesiod]

btw I've seen this issue in 3.5.2 + 3.6.2 on debian jessie + stretch

[1st1]

Interesting. A code to reproduce this crash would help tremendously. So far this is the first time I hear about this crash.

[thehesiod]

so looks like disabling the _asyncio module just caused the crash to happen less often, closing and will continue investigating after a get a core file

[1st1]

so looks like disabling the _asyncio module just caused the crash to happen less often, closing and will continue investigating after a get a core file

Interesting. So it crashes even with pure Python Future/Task implementations?

Another idea to debug this is to try to see what happens when you run your code with CFuture and PyTask, and with PyFuture/CTask.

[thehesiod]

the problem with this crash is that it only happens periodically in our prod environment :( If I try running the exact same docker container with the same inputs locally it doesn't reproduce, so frustrating. I've created a whole workflow now for deploying with a debug python to get a core file with symbols. Hopefully have some more info w/in a day. Thanks for the tips!

[1st1]

Thank you for trying to get to the bottom of this!

[thehesiod]

ok got a full debug core file, let me know what other information I can provide.

[1st1]

ok got a full debug core file, let me know what other information I can provide.

Thank you. Does the crash happen with python versions of Tasks and Future?

[thehesiod]

this is the comment on the assert:

/* Python's cyclic gc should never see an incoming refcount

• of 0: if something decref'ed to 0, it should have been
• deallocated immediately at that time.
• Possible cause (if the assert triggers): a tp_dealloc
• routine left a gc-aware object tracked during its teardown
• phase, and did something-- or allowed something to happen --
• that called back into Python. gc can trigger then, and may
• see the still-tracked dying object. Before this assert
• was added, such mistakes went on to allow gc to try to
• delete the object again. In a debug build, that caused
• a mysterious segfault, when _Py_ForgetReference tried
• to remove the object from the doubly-linked list of all
• objects a second time. In a release build, an actual
• double deallocation occurred, which leads to corruption
• of the allocator's internal bookkeeping pointers. That's
• so serious that maybe this should be a release-build
• check instead of an assert?
  */

I've also attached a file that's similar to the code we run in production, however couldn't get it to reproduce the crash. In the datafile it uses it has some tuples like the following:
StationTuple = namedtuple('StationTuple', ['stationname', 'stationsubtype', 's2id'])

[thehesiod]

hmm, how would I do that? btw I'm not 100% sure this is due to asyncio.