asyncio: race condition with debug and subprocess

[william-gr]

BPO	30805
Nosy	@ned-deily, @asvetlov, @1st1, @william-gr, @miss-islington
PRs	bpo-30805: Avoid race condition of self._debug in event loop #2490 bpo-30805: Avoid race condition with debug logging #7545 [3.7] bpo-30805: Avoid race condition with debug logging (GH-7545) #7547 [3.6] bpo-30805: Avoid race condition with debug logging (GH-7545) #7548

^{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 2018-06-08.22:53:34.893>
created_at = <Date 2017-06-29.17:40:25.041>
labels = ['3.7', 'expert-asyncio']
title = 'asyncio: race condition with debug and subprocess'
updated_at = <Date 2018-06-08.22:53:34.892>
user = 'https://github.com/william-gr'

bugs.python.org fields:

activity = <Date 2018-06-08.22:53:34.892>
actor = 'yselivanov'
assignee = 'none'
closed = True
closed_date = <Date 2018-06-08.22:53:34.893>
closer = 'yselivanov'
components = ['asyncio']
creation = <Date 2017-06-29.17:40:25.041>
creator = 'wg'
dependencies = []
files = []
hgrepos = []
issue_num = 30805
keywords = ['patch']
message_count = 5.0
messages = ['297289', '319105', '319113', '319114', '319115']
nosy_count = 5.0
nosy_names = ['ned.deily', 'asvetlov', 'yselivanov', 'wg', 'miss-islington']
pr_nums = ['2490', '7545', '7547', '7548']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue30805'
versions = ['Python 3.4', 'Python 3.5', 'Python 3.6', 'Python 3.7']

[william-gr]

If a process is schedule to run in the event loop with debug disabled
and debug is then enabled before the process finishes it will result in
a traceback: debug_log undefined.

[2017/06/29 14:39:13] (ERROR) asyncio.default_exception_handler():1261 - Ta
sk exception was never retrieved
future: <Task finished coro=<kmod_load() done, defined at /usr/local/lib/py
thon3.6/site-packages/middlewared/plugins/vm.py:502> exception=UnboundLocal
Error("local variable 'debug_log' referenced before assignment",)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/vm.py",
line 503, in kmod_load
    kldstat = (await (await Popen(['/sbin/kldstat'], stdout=subprocess.PIPE
)).communicate())[0].decode()
  File "/usr/local/lib/python3.6/asyncio/subprocess.py", line 225, in creat
e_subprocess_exec
    stderr=stderr, **kwds)
  File "/usr/local/lib/python3.6/asyncio/base_events.py", line 1194, in sub
process_exec
    logger.info('%s: %r', debug_log, transport)

[ned-deily]

@yselivanov, @asvetlov: ping on the languishing PR

[1st1]

New changeset 12f482e by Yury Selivanov in branch 'master':
bpo-30805: Avoid race condition with debug logging (GH-7545)
12f482e

[miss-islington]

New changeset 21f4c78 by Miss Islington (bot) in branch '3.7':
bpo-30805: Avoid race condition with debug logging (GH-7545)
21f4c78

[miss-islington]

New changeset 234b53f by Miss Islington (bot) in branch '3.6':
bpo-30805: Avoid race condition with debug logging (GH-7545)
234b53f