Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

asyncio.create_task() documentation should mention user needs to keep reference to the task #88831

Closed
vincentbernat mannequin opened this issue Jul 18, 2021 · 19 comments
Closed
Labels
3.10 only security fixes 3.11 only security fixes docs Documentation in the Doc dir type-feature A feature request or enhancement

Comments

@vincentbernat
Copy link
Mannequin

vincentbernat mannequin commented Jul 18, 2021

BPO 44665
Nosy @cmeyer, @nanjekyejoannah, @vincentbernat, @alexhartl
PRs
  • bpo-44665: asyncio.create_task() documentation should mention user needs to keep reference to the task #29163
  • 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 = None
    created_at = <Date 2021-07-18.06:01:26.261>
    labels = ['3.11', 'type-feature', '3.9', '3.10', 'docs']
    title = 'asyncio.create_task() documentation should mention user needs to keep reference to the task'
    updated_at = <Date 2022-01-06.08:53:46.602>
    user = 'https://github.com/vincentbernat'

    bugs.python.org fields:

    activity = <Date 2022-01-06.08:53:46.602>
    actor = 'alexhartl'
    assignee = 'docs@python'
    closed = False
    closed_date = None
    closer = None
    components = ['Documentation']
    creation = <Date 2021-07-18.06:01:26.261>
    creator = 'bernat'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 44665
    keywords = ['patch']
    message_count = 5.0
    messages = ['397741', '404776', '404782', '404827', '409821']
    nosy_count = 5.0
    nosy_names = ['docs@python', 'cmeyer', 'nanjekyejoannah', 'bernat', 'alexhartl']
    pr_nums = ['29163']
    priority = 'normal'
    resolution = None
    stage = None
    status = 'open'
    superseder = None
    type = 'enhancement'
    url = 'https://bugs.python.org/issue44665'
    versions = ['Python 3.9', 'Python 3.10', 'Python 3.11']

    @vincentbernat
    Copy link
    Mannequin Author

    vincentbernat mannequin commented Jul 18, 2021

    asyncio will only keep weak references to alive tasks (in _all_tasks). If a user does not keep a reference to a task and the task is not currently executing or sleeping, the user may get "Task was destroyed but it is pending!".

    I would suggest adding the following paragraph to create_task() documentation:

    Python only keeps weak references to the scheduled tasks. To avoid the task being destroyed by the garbage collector while still pending, a reference to it should be kept until the task is done.

    And maybe an example in case a user wants something "fire and forget"?

    running_tasks = set()
    # [...]
    task = asyncio.create_task(some_background_function())
    running_tasks.add(task)
    task.add_done_callback(lambda t: running_tasks.remove(t))

    The same applies to ensure_future as it now uses create_task, so maybe a "See create_task()".

    @vincentbernat vincentbernat mannequin added 3.9 only security fixes 3.10 only security fixes 3.11 only security fixes labels Jul 18, 2021
    @vincentbernat vincentbernat mannequin added docs Documentation in the Doc dir 3.9 only security fixes type-feature A feature request or enhancement 3.10 only security fixes 3.11 only security fixes labels Jul 18, 2021
    @vincentbernat vincentbernat mannequin added docs Documentation in the Doc dir type-feature A feature request or enhancement labels Jul 18, 2021
    @nanjekyejoannah
    Copy link
    Contributor

    @bernat and ncoghlan, please see if the wording I have used in the linked PR helps to clarify this.

    @cmeyer
    Copy link
    Mannequin

    cmeyer mannequin commented Oct 22, 2021

    Is there a way to reproduce this issue? I run the following code in Python 3.9 and it works as expected (prints "xyz" twice).

    import asyncio
    import gc
    
    async def xyz():
        print("xyz")
    
    event_loop = asyncio.get_event_loop()
    
    event_loop.create_task(xyz())
    
    t = event_loop.create_task(xyz())
    del t
    
    gc.collect()
    
    event_loop.stop()
    event_loop.run_forever()

    @vincentbernat
    Copy link
    Mannequin Author

    vincentbernat mannequin commented Oct 22, 2021

    Hummm, I have a hard time finding a short example when __del__ is not called until the task is finished. Sorry. I did run into this several time, for example here: ldo/dbussy#45 (and some internal projects as well). So, it happens from time to time, but it is hard to find a simple reproducer.

    @alexhartl
    Copy link
    Mannequin

    alexhartl mannequin commented Jan 6, 2022

    I just found this PR when a task of mine spontaneously crashed with a "Task was destroyed but it is pending" in the middle of program execution.

    I think the warning should be added to loop.create_task(), too. Not sure if loop.call_later() and loop.call_at() are also affected?

    I think it would be a good idea to add the fire-and-forget example that @bernat gave. At the moment, stackoverflow is full of suggestions to just use create_task() in this case, ignoring the return value. Actually, I think it is a true shortcoming that asyncio doesn't provide a fire-and forget functionality by itself.

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    @agrommek
    Copy link
    Contributor

    Hi everybody,

    I noticed the warning about "you have to keep a reference to the task" at the python docs, but this triggered only more questions. Why should I need to keep a reference when the event loop also must have a reference to run the task? I even asked about it at Stack Overflow (see here) and only found this github issue later.

    I agree with @alexhartl at #88831 (comment) that the workaround using add_done_callback() should be added to the docs. Moreover, I would suggest an addition to the warning, like so.

    "Important Save a reference to the result of this function, to avoid a task disappearing mid execution. The event loop only keeps weak references to task objects."

    Those two things together would have saved me some head-scratching.

    Maybe for a later release of python (3.11?) an addition to the API for 'fire and forget tasks' would be nice, something like asyncio.create_task(coro, *, name=None, keep_strong_reference=False).

    Thanks for your great work!

    @nanjekyejoannah
    Copy link
    Contributor

    Thanks for clarifying, feel free to open a PR if you have time with the desired wording.

    @agrommek
    Copy link
    Contributor

    I would like to contribute to the documentation of asyncio.create_task() and create a pull request. However, I have a (maybe stupid?) "never-have-contributed-to-cypthon-before" noob question: On which branch should I base the PR for the documentation on? Master branch (3.11 dev)? 3.7 where asyncio.create_task() was introduced? The development guide does not really say anything about this (or maybe I overlooked the information?).

    Thanks!

    @nanjekyejoannah
    Copy link
    Contributor

    @agrommek, Open on the main branch, the change can be backported to older branches if required.

    @ambv ambv removed the 3.9 only security fixes label Jun 7, 2022
    ambv added a commit that referenced this issue Jun 7, 2022
    …ces to tasks are needed (GH-93258)
    
    Co-authored-by: Łukasz Langa <lukasz@langa.pl>
    miss-islington pushed a commit to miss-islington/cpython that referenced this issue Jun 7, 2022
    …eferences to tasks are needed (pythonGH-93258)
    
    Co-authored-by: Łukasz Langa <lukasz@langa.pl>
    (cherry picked from commit 75ceae0)
    
    Co-authored-by: Andreas Grommek <76997441+agrommek@users.noreply.github.com>
    miss-islington pushed a commit to miss-islington/cpython that referenced this issue Jun 7, 2022
    …eferences to tasks are needed (pythonGH-93258)
    
    Co-authored-by: Łukasz Langa <lukasz@langa.pl>
    (cherry picked from commit 75ceae0)
    
    Co-authored-by: Andreas Grommek <76997441+agrommek@users.noreply.github.com>
    ambv pushed a commit that referenced this issue Jun 7, 2022
    …ces to tasks are needed (GH-93258) (GH-93566)
    
    Co-authored-by: Łukasz Langa <lukasz@langa.pl>
    (cherry picked from commit 75ceae0)
    
    Co-authored-by: Andreas Grommek <76997441+agrommek@users.noreply.github.com>
    ambv pushed a commit that referenced this issue Jun 7, 2022
    …ces to tasks are needed (GH-93258) (GH-93567)
    
    Co-authored-by: Łukasz Langa <lukasz@langa.pl>
    (cherry picked from commit 75ceae0)
    
    Co-authored-by: Andreas Grommek <76997441+agrommek@users.noreply.github.com>
    @orodbhen
    Copy link

    orodbhen commented Jul 15, 2022

    I would be great, I think, if the documentation offered more explanation for this behavior. As it is, it just raises more questions, and I turned up several search results of people trying to make sense of it. When you read, your first thought is, "That can't be right. I must be missing something."

    I agree with what's been said by others. This behavior is very non-intuitive, and adds to the difficulty of wrapping one's head around an already challenging paradigm. I do appreciate all the work that's being done to provide these tools, though. I expect these things will all get ironed out with time. Thanks to all.

    @Pirulax
    Copy link

    Pirulax commented Jul 27, 2022

    The reason was mentioned above.

    @dmoklaf
    Copy link

    dmoklaf commented Jan 20, 2023

    I have just discovered this, after days hunting a bug where my tasks where disappearing. What is unclear to me now is:

    1. Has all the asyncio library been checked for this issue while producing the documentation patch above? Or only the places identified in the issue's first post have been documented?

    2. I am thinking in particular about the callback methods that return a Handle: call_soon, call_soon_threadsafe, call_later, call_at. If we don't keep the Handle reference in our program, can these callbacks be silently deleted (and thus, unscheduled) by the GC?

    @SomberNight
    Copy link

    What about asyncio.run_coroutine_threadsafe? Does calling code need to keep a strong reference to the return value to avoid GC?

    bdraco added a commit to esphome/aioesphomeapi that referenced this issue Feb 13, 2023
    bdraco added a commit to esphome/aioesphomeapi that referenced this issue Feb 13, 2023
    bdraco added a commit to esphome/aioesphomeapi that referenced this issue Feb 13, 2023
    bdraco added a commit to esphome/aioesphomeapi that referenced this issue Feb 13, 2023
    SomberNight added a commit to SomberNight/electrum that referenced this issue Jul 17, 2023
    This clears up log spam for regtest tests.
    
    related:
    - https://bugs.python.org/issue44665
    - python/cpython#88831
    - https://textual.textualize.io/blog/2023/02/11/the-heisenbug-lurking-in-your-async-code/
    - python/cpython#91887 (comment)
    - "Task was destroyed but it is pending!"
    
    Perhaps we should inspect all our usages of
    - asyncio.create_task
    - loop.create_task
    - asyncio.ensure_future
    - asyncio.run_coroutine_threadsafe
    ?
    
    Example log for running a regtest test:
    ```
    $ python3 -m unittest electrum.tests.regtest.TestLightningAB.test_collaborative_close
    ***** test_collaborative_close ******
    initializing alice
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-2' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future finished result=0> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    
    [--- SNIP --- more of the same --- SNIP ---]
    
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-31' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()]> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    true
    true
    true
    true
    funding alice
    ```
    SomberNight added a commit to spesmilo/electrum that referenced this issue Jul 17, 2023
    This clears up log spam for regtest tests.
    
    related:
    - https://bugs.python.org/issue44665
    - python/cpython#88831
    - https://textual.textualize.io/blog/2023/02/11/the-heisenbug-lurking-in-your-async-code/
    - python/cpython#91887 (comment)
    - "Task was destroyed but it is pending!"
    
    Perhaps we should inspect all our usages of
    - asyncio.create_task
    - loop.create_task
    - asyncio.ensure_future
    - asyncio.run_coroutine_threadsafe
    ?
    
    Example log for running a regtest test:
    ```
    $ python3 -m unittest electrum.tests.regtest.TestLightningAB.test_collaborative_close
    ***** test_collaborative_close ******
    initializing alice
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-2' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future finished result=0> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    
    [--- SNIP --- more of the same --- SNIP ---]
    
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-31' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()]> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    true
    true
    true
    true
    funding alice
    ```
    @amirsoroush
    Copy link

    Is there a way to reproduce this issue? I run the following code in Python 3.9 and it works as expected (prints "xyz" twice).

    import asyncio
    import gc
    
    async def xyz():
        print("xyz")
    
    event_loop = asyncio.get_event_loop()
    
    event_loop.create_task(xyz())
    
    t = event_loop.create_task(xyz())
    del t
    
    gc.collect()
    
    event_loop.stop()
    event_loop.run_forever()

    Here is my answer for anyone wondering how to reproduce this issue (as their code works just fine without keeping a reference to the tasks). I tried to explain what I understood:

    https://stackoverflow.com/a/76823668/13944524

    SomberNight added a commit to spesmilo/electrum that referenced this issue Aug 17, 2023
    This clears up log spam for regtest tests.
    
    related:
    - https://bugs.python.org/issue44665
    - python/cpython#88831
    - https://textual.textualize.io/blog/2023/02/11/the-heisenbug-lurking-in-your-async-code/
    - python/cpython#91887 (comment)
    - "Task was destroyed but it is pending!"
    
    Perhaps we should inspect all our usages of
    - asyncio.create_task
    - loop.create_task
    - asyncio.ensure_future
    - asyncio.run_coroutine_threadsafe
    ?
    
    Example log for running a regtest test:
    ```
    $ python3 -m unittest electrum.tests.regtest.TestLightningAB.test_collaborative_close
    ***** test_collaborative_close ******
    initializing alice
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-2' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future finished result=0> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    
    [--- SNIP --- more of the same --- SNIP ---]
    
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-31' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()]> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    true
    true
    true
    true
    funding alice
    ```
    SomberNight added a commit to spesmilo/electrum that referenced this issue Sep 12, 2023
    This clears up log spam for regtest tests.
    
    related:
    - https://bugs.python.org/issue44665
    - python/cpython#88831
    - https://textual.textualize.io/blog/2023/02/11/the-heisenbug-lurking-in-your-async-code/
    - python/cpython#91887 (comment)
    - "Task was destroyed but it is pending!"
    
    Perhaps we should inspect all our usages of
    - asyncio.create_task
    - loop.create_task
    - asyncio.ensure_future
    - asyncio.run_coroutine_threadsafe
    ?
    
    Example log for running a regtest test:
    ```
    $ python3 -m unittest electrum.tests.regtest.TestLightningAB.test_collaborative_close
    ***** test_collaborative_close ******
    initializing alice
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-2' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future finished result=0> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    
    [--- SNIP --- more of the same --- SNIP ---]
    
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-31' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()]> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    true
    true
    true
    true
    funding alice
    ```
    sha-265 pushed a commit to sha-265/electrum that referenced this issue Oct 14, 2023
    This clears up log spam for regtest tests.
    
    related:
    - https://bugs.python.org/issue44665
    - python/cpython#88831
    - https://textual.textualize.io/blog/2023/02/11/the-heisenbug-lurking-in-your-async-code/
    - python/cpython#91887 (comment)
    - "Task was destroyed but it is pending!"
    
    Perhaps we should inspect all our usages of
    - asyncio.create_task
    - loop.create_task
    - asyncio.ensure_future
    - asyncio.run_coroutine_threadsafe
    ?
    
    Example log for running a regtest test:
    ```
    $ python3 -m unittest electrum.tests.regtest.TestLightningAB.test_collaborative_close
    ***** test_collaborative_close ******
    initializing alice
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-2' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future finished result=0> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    
    [--- SNIP --- more of the same --- SNIP ---]
    
    --- Logging error ---
    Traceback (most recent call last):
      File "/usr/lib/python3.10/logging/__init__.py", line 1100, in emit
        msg = self.format(record)
      File "/usr/lib/python3.10/logging/__init__.py", line 943, in format
        return fmt.format(record)
      File "/home/user/wspace/electrum/electrum/logging.py", line 44, in format
        record = copy.copy(record)  # avoid mutating arg
      File "/usr/lib/python3.10/copy.py", line 92, in copy
        rv = reductor(4)
    ImportError: sys.meta_path is None, Python is likely shutting down
    Call stack:
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1781, in call_exception_handler
        self._exception_handler(self, context)
      File "/home/user/wspace/electrum/electrum/util.py", line 1535, in on_exception
        loop.default_exception_handler(context)
      File "/usr/lib/python3.10/asyncio/base_events.py", line 1744, in default_exception_handler
        logger.error('\n'.join(log_lines), exc_info=exc_info)
    Message: "Task was destroyed but it is pending!\ntask: <Task pending name='Task-31' coro=<Abstract_Wallet.on_event_adb_set_up_to_date() running at /home/user/wspace/electrum/electrum/wallet.py:485> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()]> cb=[_chain_future.<locals>._call_set_state() at /usr/lib/python3.10/asyncio/futures.py:392]>"
    Arguments: ()
    true
    true
    true
    true
    funding alice
    ```
    @ggregoire
    Copy link

    @vincentbernat just to clarify, since I'm not that familiar with the intricacies of Python's garbage collector.

    Is this enough (in the context of this issue) to keep a reference of the task like this?

    async def coro():
        task1 = asyncio.create_task(...)
        task2 = asyncio.create_task(...)
        task3 = asyncio.create_task(...)
        task4 = asyncio.create_task(...)

    Or is it really needed to keep them in a collection?

    If so, can the collection be declared inside the coroutine? Or does it need to be outside to be a "strong" reference?

    async def coro():
        running_tasks = set()
        task1 = asyncio.create_task(...)
        running_tasks.add(task1)
        task2 = asyncio.create_task(...)
        running_tasks.add(task2)
        task3 = asyncio.create_task(...)
        running_tasks.add(task3)
        task4 = asyncio.create_task(...)
        running_tasks.add(task4)

    vs.

    running_tasks = set()
    
    async def coro():
        task1 = asyncio.create_task(...)
        running_tasks.add(task1)
        task2 = asyncio.create_task(...)
        running_tasks.add(task2)
        task3 = asyncio.create_task(...)
        running_tasks.add(task3)
        task4 = asyncio.create_task(...)
        running_tasks.add(task4)

    Just trying to keep the code as simple as possible.

    @vincentbernat
    Copy link
    Contributor

    Only the last one will work. The two other ones don't keep a reference on the tasks after the coro() function ends.

    @ggregoire
    Copy link

    ggregoire commented Feb 28, 2024

    Only the last one will work. The two other ones don't keep a reference on the tasks after the coro() function ends.

    But when the coro() function ends, all the tasks created inside coro() are done, so I don't need to keep the references anymore, right?

    Maybe I should have clarified that I call the await inside the same coro() function.

    So like:

    async def coro():
        task1 = asyncio.create_task(...)
        task2 = asyncio.create_task(...)
        task3 = asyncio.create_task(...)
        task4 = asyncio.create_task(...)
        await task1
        await task2
        await task3
        await task4
        # all the tasks are done and coro() ends

    In this case, would it work? Do I even need to keep the references task1, task2, etc or can I do directly away asyncio.create_task(...) without risking my tasks to be garbage collected before they are done?

    async def coro():
        await asyncio.create_task(...)
        await asyncio.create_task(...)
        await asyncio.create_task(...)
        await asyncio.create_task(...)
        # all the tasks are done and coro() ends

    Thanks for the help.


    Editing this post to avoid creating more noise:

    I don't think this issue should be a support forum.

    Agree but the documentation was updated following this issue and the wording is confusing. As you can see in the previous comments and in mine, it raises a lot of questions. The doc suggests to keep references of the tasks in any case, while apparently is not always necessary (like in my example).

    I appreciate the help anyway. Thanks.

    @vincentbernat
    Copy link
    Contributor

    I don't think this issue should be a support forum. But yes, both ways are fine (but they don't do the same thing).

    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.10 only security fixes 3.11 only security fixes docs Documentation in the Doc dir type-feature A feature request or enhancement
    Projects
    None yet
    Development

    No branches or pull requests

    10 participants