python / cpython

The Python programming language
https://www.python.org
Other
62.76k stars 30.08k forks source link

Incorrect `Context` in corotine's `except` and `finally` blocks #93740

Closed ProgramRipper closed 2 years ago

ProgramRipper commented 2 years ago

Bug report

Now we have the following code to show what happen:

import asyncio
from contextvars import ContextVar

ctx = ContextVar("test")
loop = asyncio.new_event_loop()

test.set("global")
print('expected to be "global":', ctx.get())

async def main():
    test.set("inner")
    print('expected to be "inner":', ctx.get())
    try:
        await asyncio.sleep(5) # may exit here
        raise Exception("this is the expected case")
    except BaseException as e:
        print('in except, expected to be "inner":', ctx.get())
        raise e
    finally:
        print('in finally, expected to be "inner":', ctx.get())

loop.run_until_complete(main())

If I left it run to the end, the result will as expected:

expected to be "global": global
expected to be "inner": inner
in except, expected to be "inner": inner
in finally, expected to be "inner": inner
Traceback (most recent call last):
  File "/home/programripper/PycharmProjects/test/test.py", line 25, in <module>
    loop.run_until_complete(main())
  File "/home/programripper/.pyenv/versions/3.10.1/lib/python3.10/asyncio/base_events.py", line 641, in run_until_complete
    return future.result()
  File "/home/programripper/PycharmProjects/test/test.py", line 20, in main
    raise e
  File "/home/programripper/PycharmProjects/test/test.py", line 17, in main
    raise Exception("this is the expected case")
Exception: this is the expected case

But if I interrupt it while running, it turns to:

expected to be "global": global
expected to be "inner": inner
^CTraceback (most recent call last):
  File "/home/programripper/PycharmProjects/test/test.py", line 22, in <module>
    loop.run_until_complete(main())
  File "/home/programripper/.pyenv/versions/3.10.1/lib/python3.10/asyncio/base_events.py", line 628, in run_until_complete
    self.run_forever()
  File "/home/programripper/.pyenv/versions/3.10.1/lib/python3.10/asyncio/base_events.py", line 595, in run_forever
    self._run_once()
  File "/home/programripper/.pyenv/versions/3.10.1/lib/python3.10/asyncio/base_events.py", line 1845, in _run_once
    event_list = self._selector.select(timeout)
  File "/home/programripper/.pyenv/versions/3.10.1/lib/python3.10/selectors.py", line 469, in select
    fd_event_list = self._selector.poll(timeout, max_ev)
KeyboardInterrupt
in except, expected to be "inner": global
in finally, expected to be "inner": global

Obviously, the ctx.get() in except and finally blocks didn't work as expected.

What's more, this not only happen by KeyboardInterrupt, but also other operations that will triger except or finally block, such as garbage collect.

As it is hard to trigger gc, so I can't give a minimal case, but a real case https://github.com/GraiaProject/BroadcastControl/blob/6a4a13e3531109bcb82dd4b306e7498d2bff9b0b/src/graia/broadcast/__init__.py#L207:

2022-06-12 14:55:14.445 | ERROR    | graia.ariadne.util:loguru_exc_callback_async:103 - Exception: {'message': 'Task was destroyed but it is pending!', 'task': <Task pending name='Task-112' coro=<Broadcast.layered_scheduler() done, defined at /home/programripper/PycharmProjects/test/__pypackages__/3.10/lib/graia/broadcast/__init__.py:97> wait_for=<Future pending cb=[Task.task_wakeup()]>>}
Exception ignored in: <coroutine object Broadcast.Executor at 0x7fdf404553f0>
Traceback (most recent call last):
  File "/home/programripper/PycharmProjects/test/__pypackages__/3.10/lib/graia/broadcast/__init__.py", line 207, in Executor
    dii.ctx.reset(dii_token)
  File "/home/programripper/PycharmProjects/test/__pypackages__/3.10/lib/graia/broadcast/utilles.py", line 60, in reset
    return self.current_ctx.reset(token)
ValueError: <Token var=<ContextVar name='bcc_dii' at 0x7fdf43259a30> at 0x7fdf4047a940> was created in a different Context

The "free-flying" task is collected by gc, and trigger finally. But ctx.reset() raised a ValueError, because the token "was created in a different Context".

Though I didn't test, I suppose any exception or other else that trigger except or finally outside a corotine will suffer from this problem.

Your environment

ProgramRipper commented 2 years ago

Another news, maybe context manager will suffer from this problem, too.

from contextvars import ContextVar
import asyncio
from signal import raise_signal
from contextlib import ExitStack

test = ContextVar("test")
loop = asyncio.new_event_loop()

test.set("global")
print('expected to be "global":', test.get())

async def main():
    test.set("inner")
    with ExitStack() as stack:
        stack.push(lambda *args: print('expected to be "inner":', test.get()))
        print('expected to be "inner":', test.get())
        await asyncio.sleep(5)

loop.run_until_complete(main())

Run this code as the front I said:

But if I interrupt it while running, it turns to:

expected to be "global": global
expected to be "inner": inner
^CTraceback (most recent call last):
File "/home/programripper/PycharmProjects/test/test.py", line 21, in <module>
loop.run_until_complete(main())
File "/home/programripper/.pyenv/versions/3.9.11/lib/python3.9/asyncio/base_events.py", line 634, in run_until_complete
self.run_forever()
File "/home/programripper/.pyenv/versions/3.9.11/lib/python3.9/asyncio/base_events.py", line 601, in run_forever
self._run_once()
File "/home/programripper/.pyenv/versions/3.9.11/lib/python3.9/asyncio/base_events.py", line 1869, in _run_once
event_list = self._selector.select(timeout)
File "/home/programripper/.pyenv/versions/3.9.11/lib/python3.9/selectors.py", line 469, in select
fd_event_list = self._selector.poll(timeout, max_ev)
KeyboardInterrupt
expected to be "inner": global

Get a same result.

kumaraditya303 commented 2 years ago

If you use asyncio.run then it works as expected.

import asyncio
from contextvars import ContextVar
import contextvars

ctx = ContextVar("test")

ctx.set("global")
print('expected to be "global":', ctx.get())

async def main():
    ctx.set("inner")
    print('expected to be "inner":', ctx.get())
    try:
        await asyncio.sleep(5) # may exit here
        raise Exception("this is the expected case")
    except BaseException as e:
        print('in except, expected to be "inner":', ctx.get())
        raise e
    finally:
        print('in finally, expected to be "inner":', ctx.get())

asyncio.run(main())
expected to be "global": global
expected to be "inner": inner
^Cin except, expected to be "inner": inner
in finally, expected to be "inner": inner
Traceback (most recent call last):
  File "/workspaces/cpython/Lib/asyncio/runners.py", line 114, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/workspaces/cpython/Lib/asyncio/base_events.py", line 650, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/workspaces/cpython/main.py", line 19, in main
    raise e
    ^^^^^^^
  File "/workspaces/cpython/main.py", line 15, in main
    await asyncio.sleep(5) # may exit here
    ^^^^^^^^^^^^^^^^^^^^^^
  File "/workspaces/cpython/Lib/asyncio/tasks.py", line 648, in sleep
    return await future
           ^^^^^^^^^^^^
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/workspaces/cpython/main.py", line 23, in <module>
    asyncio.run(main())
    ^^^^^^^^^^^^^^^^^^^
  File "/workspaces/cpython/Lib/asyncio/runners.py", line 180, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/workspaces/cpython/Lib/asyncio/runners.py", line 117, in run
    raise KeyboardInterrupt()
    ^^^^^^^^^^^^^^^^^^^^^^^^^
KeyboardInterrupt
ProgramRipper commented 2 years ago

If you use asyncio.run then it works as expected.

Yes, you're right, and I have found this before I put forward the issue, but I suppose this doesn't help solving the problem. asyncio.run() handle exception in another way that raise exception inside every future and await them again. In this way, it do enter the correct context. However, even run by asyncio.run(), it doesn't change that other procedure like gc won't enter the correct context, as the second example I give.

The "free-flying" task is collected by gc, and trigger finally. But ctx.reset() raised a ValueError, because the token "was created in a different Context".

I know it is hard to explain what is happening through a complicate real case, so I will try to give a minimal case later.

kumaraditya303 commented 2 years ago

The "free-flying" task is collected by gc, and trigger finally. But ctx.reset() raised a ValueError, because the token "was created in a different Context".

You should keep a reference to the created task to avoid it being collected by gc. It is even documented here https://docs.python.org/3/library/asyncio-task.html#asyncio.create_task

ProgramRipper commented 2 years ago

You should keep a reference to the created task to avoid it being collected by gc. It is even documented here https://docs.python.org/3/library/asyncio-task.html#asyncio.create_task

Yep, I know this and I just fix it days before. But what I wanna emphasize is that there are cases that need to use ContextVar in except or finally block to cleanup something when a corotine is being garbage collected. So, now what I wanna know is whether this " confusing" behavior make sense and I shouldn't expect ContextVar will work properly during garbage collect, or this is a bug that will be fixed?

kumaraditya303 commented 2 years ago

So, now what I wanna know is whether this " confusing" behavior make sense and I shouldn't expect ContextVar will work properly during garbage collect, or this is a bug that will be fixed?

The event loop needs to finalize the coroutine in the associated context in which it was created. If gc will close the coroutine then it can be done in any task with different context so you should keep a reference to the task to avoid this behavior, also relying on gc closing the coroutine is undefined behavior as it can delay closing of coroutine and in some cases it may not even happen. Closing as this is not a bug.

ProgramRipper commented 2 years ago

I got it, thanks a lot.