classification
Title: 'async with' somehow suppresses unawaited coroutine warnings
Type: Stage: resolved
Components: Interpreter Core Versions: Python 3.8, Python 3.7, Python 3.6, Python 3.5
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: asvetlov, giampaolo.rodola, ncoghlan, njs, xgdomingo, yselivanov
Priority: normal Keywords: patch

Created on 2018-01-29 04:06 by njs, last changed 2018-01-31 17:10 by xgdomingo. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 5410 merged yselivanov, 2018-01-29 06:15
Messages (13)
msg311052 - (view) Author: Nathaniel Smith (njs) * (Python committer) Date: 2018-01-29 04:06
Example (minimal version of https://github.com/python-trio/trio/issues/425):

-----

async def open_file():
    pass

async def main():
    async with open_file():  # Should be 'async with await open_file()'
        pass

coro = main()
coro.send(None)

-----

Here we accidentally left out an 'await' on the call to 'open_file', so the 'async with' tries to look up 'CoroutineType.__aexit__', which obviously doesn't exist, and the program crashes with an AttributeError("__aexit__"). Yet weirdly, this doesn't trigger a warning about 'open_file' being unawaited. It should!

Yury's theory: maybe BEFORE_ASYNC_WITH's error-handling path is forgetting to DECREF the object.
msg311053 - (view) Author: Nathaniel Smith (njs) * (Python committer) Date: 2018-01-29 04:10
> Yury's theory: maybe BEFORE_ASYNC_WITH's error-handling path is forgetting to DECREF the object.

Nope, that doesn't seem to be it. This version prints "refcount: 2" twice, *and* prints a proper "was never awaited" warning:

-----

import sys

async def open_file():
    pass

async def main():
    open_file_coro = open_file()
    print("refcount:", sys.getrefcount(open_file_coro))

    try:
        async with open_file_coro:
            pass
    except:
        pass

    print("refcount:", sys.getrefcount(open_file_coro))

coro = main()
try:
    coro.send(None)
except:
    pass
msg311058 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2018-01-29 05:36
Looking at the ceval code, I think Yury's theory is plausible, and we may also be leaving the interpreter's internal stack in a dubious state. Things then get cleaned up if you wrap the async with in a try/except or try/finally:

==============
>>> async def try_main():
...     try:
...         async with open_file():
...             pass
...     finally:
...         pass
... 
>>> try_main().send(None)
sys:1: RuntimeWarning: coroutine 'open_file' was never awaited
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 3, in try_main
AttributeError: __aexit__
==============

Unfortunately for that theory, adding braces and "Py_DECREF(POP());" to the relevant error handling branch *doesn't* fix the problem.

I also found another way to provoke similar misbehaviour without async with:

==========
>>> async def open_file():
...     pass
... 
>>> open_file()
<coroutine object open_file at 0x7f92fe19c548>
>>> _
<coroutine object open_file at 0x7f92fe19c548>
>>> 1
__main__:1: RuntimeWarning: coroutine 'open_file' was never awaited
1
>>> open_file()
<coroutine object open_file at 0x7f92fe19c548>
>>> del _
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
NameError: name '_' is not defined
>>> _
<coroutine object open_file at 0x7f92fe19c548>
>>> 1
1
>>> _
1
>>> 
==========
msg311060 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 05:51
Changing

  async def main():
    async with open_file():
      pass

to

  async def main():
    c = open_file()
    async with c:
      pass

also makes it print the warning :)

Also I've made a test out of this snippet and running tests in refleak mode shows that there's indeed no refleak here.
msg311061 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 05:53
The difference between these two functions is two extra opcodes: STORE_FAST/LOAD_FAST before BEFORE_ASYNC_WITH.  With them we have a warning.
msg311062 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 05:55
So refactoring it into "c = open_file(); async with c" just prolongs the life of the coroutine so that it's GCed outside of WITH_CLEANUP_START/WITH_CLEANUP_FINISH block.  Something weird is going on in that block.
msg311064 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 05:57
Ah, we should never really get to WITH_CLEANUP_START; the exception should be raised in BEFORE_ASYNC_WITH
msg311065 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 06:20
So the problem was that _PyGen_Finalize wasn't issuing any warnings if there's any error set in the current tstate.  And in Nathaniel's case, the current error was an AttributeError('__aexit__').

This check is weird, because right before raising the warning, we call PyErr_Fetch to temporarily reset the current exception if any, specifically to raise the warning :)

The PR just removes the check.  Unless I'm missing something this should fix the issue.
msg311066 - (view) Author: Nathaniel Smith (njs) * (Python committer) Date: 2018-01-29 06:21
Well, I feel silly then: bpo-32605
msg311071 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2018-01-29 06:38
Ah, and in my REPL example, the NameError was pending when the internal result storage was getting set back to None.

I'm not sure I even knew the "Don't complain when an exception is pending" check existed, so it would have taken me a long time to find that.
msg311072 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 06:47
I knew about that "if", but it never fully registered to me why it's there and what it is protecting us from ;) So I had to debug half of ceval loop before I stumbled upon it again ;)
msg311157 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 19:31
New changeset 2a2270db9be9bdac5ffd2d50929bf905e7391a06 by Yury Selivanov in branch 'master':
bpo-32703: Fix coroutine resource warning in case where there's an error (GH-5410)
https://github.com/python/cpython/commit/2a2270db9be9bdac5ffd2d50929bf905e7391a06
msg311158 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-01-29 19:32
Merged; closing this issue.
History
Date User Action Args
2018-01-31 17:10:01xgdomingosetnosy: + xgdomingo
2018-01-29 19:32:15yselivanovsetstatus: open -> closed
resolution: fixed
messages: + msg311158

stage: patch review -> resolved
2018-01-29 19:31:55yselivanovsetmessages: + msg311157
2018-01-29 06:47:49yselivanovsetmessages: + msg311072
2018-01-29 06:38:53ncoghlansetmessages: + msg311071
2018-01-29 06:21:25njssetmessages: + msg311066
2018-01-29 06:20:02yselivanovsetmessages: + msg311065
2018-01-29 06:15:49yselivanovsetkeywords: + patch
stage: patch review
pull_requests: + pull_request5243
2018-01-29 05:57:56yselivanovsetmessages: + msg311064
2018-01-29 05:55:54yselivanovsetmessages: + msg311062
2018-01-29 05:53:27yselivanovsetmessages: + msg311061
2018-01-29 05:51:34yselivanovsetmessages: + msg311060
2018-01-29 05:36:50ncoghlansetmessages: + msg311058
2018-01-29 04:23:41yselivanovsetnosy: + ncoghlan
components: + Interpreter Core, - asyncio
2018-01-29 04:10:22njssetmessages: + msg311053
2018-01-29 04:06:16njscreate