Skip to content

Commit ebc4a00

Browse files
committed
util.CallbackManager: keep strong references for running futures
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 ```
1 parent 803a7ec commit ebc4a00

File tree

1 file changed

+5
-1
lines changed

1 file changed

+5
-1
lines changed

electrum/util.py

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1878,6 +1878,7 @@ class CallbackManager:
18781878
def __init__(self):
18791879
self.callback_lock = threading.Lock()
18801880
self.callbacks = defaultdict(list) # note: needs self.callback_lock
1881+
self._running_cb_futs = set()
18811882

18821883
def register_callback(self, func, events):
18831884
with self.callback_lock:
@@ -1902,7 +1903,10 @@ def trigger_callback(self, event, *args):
19021903
for callback in callbacks:
19031904
# FIXME: if callback throws, we will lose the traceback
19041905
if asyncio.iscoroutinefunction(callback):
1905-
asyncio.run_coroutine_threadsafe(callback(*args), loop)
1906+
fut = asyncio.run_coroutine_threadsafe(callback(*args), loop)
1907+
# keep strong references around to avoid GC issues:
1908+
self._running_cb_futs.add(fut)
1909+
fut.add_done_callback(lambda fut_: self._running_cb_futs.remove(fut_))
19061910
elif get_running_loop() == loop:
19071911
# run callback immediately, so that it is guaranteed
19081912
# to have been executed when this method returns

0 commit comments

Comments
 (0)