2014-01-16 13:58:01 -04:00
.. currentmodule :: asyncio
2014-02-19 18:15:02 -04:00
.. _asyncio-dev:
2014-01-16 13:58:01 -04:00
Develop with asyncio
====================
Asynchronous programming is different than classical "sequential" programming.
2014-01-20 12:13:31 -04:00
This page lists common traps and explains how to avoid them.
2014-01-16 13:58:01 -04:00
2014-06-22 19:36:11 -03:00
.. _asyncio-debug-mode:
Debug mode of asyncio
---------------------
2015-09-24 08:32:39 -03:00
The implementation of :mod: `asyncio` has been written for performance.
In order to ease the development of asynchronous code, you may wish to
enable *debug mode* .
2014-08-25 12:04:12 -03:00
2015-09-24 08:32:39 -03:00
To enable all debug checks for an application:
2014-08-25 12:04:12 -03:00
2015-02-04 11:14:33 -04:00
* Enable the asyncio debug mode globally by setting the environment variable
2017-11-20 11:14:07 -04:00
:envvar: `PYTHONASYNCIODEBUG` to `` 1 `` , using `` -X dev `` command line option
(see the :option: `-X` option), or by calling
2018-09-11 13:54:40 -03:00
:meth: `loop.set_debug` .
2015-02-04 11:14:33 -04:00
* Set the log level of the :ref: `asyncio logger <asyncio-logger>` to
:py:data: `logging.DEBUG` . For example, call
`` logging.basicConfig(level=logging.DEBUG) `` at startup.
* Configure the :mod: `warnings` module to display :exc: `ResourceWarning`
warnings. For example, use the `` -Wdefault `` command line option of Python to
display them.
Examples debug checks:
2014-06-22 19:36:11 -03:00
* Log :ref:`coroutines defined but never "yielded from"
<asyncio-coroutine-not-scheduled>`
2018-09-11 13:54:40 -03:00
* :meth: `loop.call_soon` and :meth: `loop.call_at` methods
2014-06-22 19:36:11 -03:00
raise an exception if they are called from the wrong thread.
* Log the execution time of the selector
* Log callbacks taking more than 100 ms to be executed. The
2018-09-11 13:54:40 -03:00
:attr: `loop.slow_callback_duration` attribute is the minimum
2014-06-22 19:36:11 -03:00
duration in seconds of "slow" callbacks.
2015-02-04 11:14:33 -04:00
* :exc: `ResourceWarning` warnings are emitted when transports and event loops
are :ref: `not closed explicitly <asyncio-close-transports>` .
2014-06-22 19:36:11 -03:00
2017-11-20 11:14:07 -04:00
.. versionchanged :: 3.7
The new `` -X dev `` command line option can now also be used to enable
the debug mode.
2014-06-22 19:36:11 -03:00
.. seealso ::
2018-09-11 13:54:40 -03:00
The :meth: `loop.set_debug` method and the :ref:`asyncio logger
2014-06-22 19:36:11 -03:00
<asyncio-logger>`.
2015-01-29 19:55:58 -04:00
Cancellation
------------
Cancellation of tasks is not common in classic programming. In asynchronous
2017-08-03 11:20:42 -03:00
programming, not only is it something common, but you have to prepare your
2015-01-29 19:55:58 -04:00
code to handle it.
Futures and tasks can be cancelled explicitly with their :meth: `Future.cancel`
method. The :func: `wait_for` function cancels the waited task when the timeout
occurs. There are many other cases where a task can be cancelled indirectly.
Don't call :meth: `~Future.set_result` or :meth: `~Future.set_exception` method
of :class: `Future` if the future is cancelled: it would fail with an exception.
For example, write::
if not fut.cancelled():
fut.set_result('done')
Don't schedule directly a call to the :meth: `~Future.set_result` or the
:meth: `~Future.set_exception` method of a future with
2018-09-11 13:54:40 -03:00
:meth:`loop.call_soon`: the future can be cancelled before its method
2015-01-29 19:55:58 -04:00
is called.
If you wait for a future, you should check early if the future was cancelled to
avoid useless operations. Example::
2017-12-11 11:35:49 -04:00
async def slow_operation(fut):
2015-01-29 19:55:58 -04:00
if fut.cancelled():
return
# ... slow computation ...
2017-12-11 11:35:49 -04:00
await fut
2015-01-29 19:55:58 -04:00
# ...
The :func: `shield` function can also be used to ignore cancellation.
2014-01-31 22:18:58 -04:00
.. _asyncio-multithreading:
Concurrency and multithreading
------------------------------
2018-09-11 13:54:40 -03:00
An event loop runs in a thread (typically the main thread) and executes
all callbacks and tasks in its thread. While a task is running in the
2018-09-13 02:40:37 -03:00
event loop, no other tasks may run in the same thread. When a task
executes an `` await `` expression, the running task gets suspended, and the
event loop executes the next task. Prior to suspending the task, the awaiting
chain is checked, and if the chain ends with a future, the running task is
not suspended.
2014-01-31 22:18:58 -04:00
2014-02-04 13:18:27 -04:00
To schedule a callback from a different thread, the
2018-09-11 13:54:40 -03:00
:meth: `loop.call_soon_threadsafe` method should be used. Example::
2014-02-04 13:18:27 -04:00
2015-10-05 20:20:00 -03:00
loop.call_soon_threadsafe(callback, *args)
2014-01-31 22:18:58 -04:00
2014-02-07 14:03:05 -04:00
Most asyncio objects are not thread safe. You should only worry if you access
objects outside the event loop. For example, to cancel a future, don't call
directly its :meth: `Future.cancel` method, but::
loop.call_soon_threadsafe(fut.cancel)
2014-01-31 22:18:58 -04:00
To handle signals and to execute subprocesses, the event loop must be run in
the main thread.
2015-10-05 20:20:00 -03:00
To schedule a coroutine object from a different thread, the
:func: `run_coroutine_threadsafe` function should be used. It returns a
:class: `concurrent.futures.Future` to access the result::
future = asyncio.run_coroutine_threadsafe(coro_func(), loop)
result = future.result(timeout) # Wait for the result with a timeout
2018-09-13 02:40:37 -03:00
The :meth: `loop.run_in_executor` method can be used with a
:class: `concurrent.futures.ThreadPoolExecutor` to execute a callback in
different thread so as not to block the event loop's main thread.
2014-01-31 22:18:58 -04:00
.. seealso ::
2015-01-06 02:40:43 -04:00
The :ref: `Synchronization primitives <asyncio-sync>` section describes ways
to synchronize tasks.
2014-01-31 22:18:58 -04:00
2015-01-08 20:32:02 -04:00
The :ref: `Subprocess and threads <asyncio-subprocess-threads>` section lists
asyncio limitations to run subprocesses from different threads.
2014-01-31 22:18:58 -04:00
2014-01-31 21:36:43 -04:00
.. _asyncio-handle-blocking:
2014-02-09 10:07:47 -04:00
Handle blocking functions correctly
2014-01-16 13:58:01 -04:00
-----------------------------------
Blocking functions should not be called directly. For example, if a function
blocks for 1 second, other tasks are delayed by 1 second which can have an
important impact on reactivity.
For networking and subprocesses, the :mod: `asyncio` module provides high-level
2014-02-02 10:03:02 -04:00
APIs like :ref: `protocols <asyncio-protocol>` .
2014-01-16 13:58:01 -04:00
An executor can be used to run a task in a different thread or even in a
different process, to not block the thread of the event loop. See the
2018-09-11 13:54:40 -03:00
:meth: `loop.run_in_executor` method.
2014-01-16 13:58:01 -04:00
2014-01-31 21:36:43 -04:00
.. seealso ::
2014-01-16 13:58:01 -04:00
2014-01-31 21:36:43 -04:00
The :ref: `Delayed calls <asyncio-delayed-calls>` section details how the
event loop handles time.
2014-01-16 13:58:01 -04:00
2014-01-31 21:36:43 -04:00
.. _asyncio-logger:
Logging
-------
2014-01-16 13:58:01 -04:00
2014-01-31 21:36:43 -04:00
The :mod: `asyncio` module logs information with the :mod: `logging` module in
the logger `` 'asyncio' `` .
2014-01-16 13:58:01 -04:00
2016-10-13 17:56:40 -03:00
The default log level for the :mod: `asyncio` module is :py:data: `logging.INFO` .
For those not wanting such verbosity from :mod: `asyncio` the log level can
be changed. For example, to change the level to :py:data: `logging.WARNING` :
.. code-block :: none
logging.getLogger('asyncio').setLevel(logging.WARNING)
2014-01-16 13:58:01 -04:00
.. _asyncio-coroutine-not-scheduled:
Detect coroutine objects never scheduled
----------------------------------------
2014-07-08 07:39:10 -03:00
When a coroutine function is called and its result is not passed to
2018-09-13 02:40:37 -03:00
:meth: `asyncio.create_task` the execution of the coroutine object will
never be scheduled which is probably a bug. Using `` asyncio.create_task `` is
preferred to the low level :func: `ensure_future` and :meth: `loop.create_task`
methods. :ref: `Enable the debug mode of asyncio <asyncio-debug-mode>`
2015-06-30 23:13:22 -03:00
to :ref: `log a warning <asyncio-logger>` to detect it.
2014-01-16 13:58:01 -04:00
Example with the bug::
import asyncio
2017-12-11 11:35:49 -04:00
async def test():
2014-01-16 13:58:01 -04:00
print("never scheduled")
test()
Output in debug mode::
2014-07-08 07:39:10 -03:00
Coroutine test() at test.py:3 was never yielded from
Coroutine object created at (most recent call last):
File "test.py", line 7, in <module>
test()
2014-01-16 13:58:01 -04:00
2018-09-13 02:40:37 -03:00
The fix is to call the :meth: `asyncio.create_task` function. Using
`` asyncio.create_task `` is preferred to the low level :func: `ensure_future` and
:meth: `loop.create_task` methods.
2014-01-16 13:58:01 -04:00
2014-07-08 07:39:10 -03:00
.. seealso ::
:ref: `Pending task destroyed <asyncio-pending-task-destroyed>` .
2014-01-16 13:58:01 -04:00
2014-07-08 07:39:10 -03:00
Detect exceptions never consumed
--------------------------------
2014-01-16 13:58:01 -04:00
2017-11-24 19:39:39 -04:00
Python usually calls :func: `sys.excepthook` on unhandled exceptions. If
2014-07-08 07:39:10 -03:00
:meth: `Future.set_exception` is called, but the exception is never consumed,
2017-11-24 19:39:39 -04:00
:func: `sys.excepthook` is not called. Instead, :ref:`a log is emitted
2014-07-08 07:39:10 -03:00
<asyncio-logger> ` when the future is deleted by the garbage collector, with the
traceback where the exception was raised.
2014-01-16 13:58:01 -04:00
Example of unhandled exception::
import asyncio
@asyncio.coroutine
def bug():
raise Exception("not consumed")
loop = asyncio.get_event_loop()
2015-05-11 17:33:41 -03:00
asyncio.ensure_future(bug())
2014-01-16 13:58:01 -04:00
loop.run_forever()
2015-02-23 06:41:56 -04:00
loop.close()
2014-01-16 13:58:01 -04:00
Output::
2014-07-08 07:39:10 -03:00
Task exception was never retrieved
2014-10-12 16:37:16 -03:00
future: <Task finished coro=<coro() done, defined at asyncio/coroutines.py:139> exception=Exception('not consumed',)>
Traceback (most recent call last):
File "asyncio/tasks.py", line 237, in _step
result = next(coro)
File "asyncio/coroutines.py", line 141, in coro
res = func(*args, * *kw)
File "test.py", line 5, in bug
raise Exception("not consumed")
Exception: not consumed
:ref: `Enable the debug mode of asyncio <asyncio-debug-mode>` to get the
traceback where the task was created. Output in debug mode::
Task exception was never retrieved
future: <Task finished coro=<bug() done, defined at test.py:3> exception=Exception('not consumed',) created at test.py:8>
2014-07-08 07:39:10 -03:00
source_traceback: Object created at (most recent call last):
2014-10-12 16:37:16 -03:00
File "test.py", line 8, in <module>
2015-05-11 17:33:41 -03:00
asyncio.ensure_future(bug())
2014-01-16 13:58:01 -04:00
Traceback (most recent call last):
2014-10-12 16:37:16 -03:00
File "asyncio/tasks.py", line 237, in _step
2014-01-16 13:58:01 -04:00
result = next(coro)
2014-10-12 16:37:16 -03:00
File "asyncio/coroutines.py", line 79, in __next__
2014-07-08 07:39:10 -03:00
return next(self.gen)
File "asyncio/coroutines.py", line 141, in coro
2014-01-16 13:58:01 -04:00
res = func(*args, * *kw)
2014-10-12 16:37:16 -03:00
File "test.py", line 5, in bug
2014-01-16 13:58:01 -04:00
raise Exception("not consumed")
Exception: not consumed
2015-01-06 02:40:43 -04:00
There are different options to fix this issue. The first option is to chain the
2014-01-16 13:58:01 -04:00
coroutine in another coroutine and use classic try/except::
2017-12-11 11:35:49 -04:00
async def handle_exception():
2014-01-16 13:58:01 -04:00
try:
2017-12-11 11:35:49 -04:00
await bug()
2014-01-16 13:58:01 -04:00
except Exception:
print("exception consumed")
loop = asyncio.get_event_loop()
2015-05-11 17:33:41 -03:00
asyncio.ensure_future(handle_exception())
2014-01-16 13:58:01 -04:00
loop.run_forever()
2015-02-23 06:41:56 -04:00
loop.close()
2014-01-16 13:58:01 -04:00
2018-09-13 02:40:37 -03:00
Another option is to use the :meth: `asyncio.run` function::
2014-01-16 13:58:01 -04:00
2018-09-13 02:40:37 -03:00
asyncio.run(bug())
2014-01-16 13:58:01 -04:00
2015-01-06 02:40:43 -04:00
.. seealso ::
The :meth: `Future.exception` method.
2014-01-16 13:58:01 -04:00
2015-01-06 02:40:43 -04:00
Chain coroutines correctly
2014-01-16 13:58:01 -04:00
--------------------------
When a coroutine function calls other coroutine functions and tasks, they
2017-12-11 11:35:49 -04:00
should be chained explicitly with `` await `` . Otherwise, the execution is
2014-01-20 12:13:31 -04:00
not guaranteed to be sequential.
2014-01-16 13:58:01 -04:00
2014-01-20 12:13:31 -04:00
Example with different bugs using :func: `asyncio.sleep` to simulate slow
operations::
2014-01-16 13:58:01 -04:00
import asyncio
2017-12-11 11:35:49 -04:00
async def create():
await asyncio.sleep(3.0)
2014-01-16 13:58:01 -04:00
print("(1) create file")
2017-12-11 11:35:49 -04:00
async def write():
await asyncio.sleep(1.0)
2014-01-16 13:58:01 -04:00
print("(2) write into file")
2017-12-11 11:35:49 -04:00
async def close():
2014-01-16 13:58:01 -04:00
print("(3) close file")
2017-12-11 11:35:49 -04:00
async def test():
2015-05-11 17:33:41 -03:00
asyncio.ensure_future(create())
asyncio.ensure_future(write())
asyncio.ensure_future(close())
2017-12-11 11:35:49 -04:00
await asyncio.sleep(2.0)
2014-01-16 13:58:01 -04:00
loop.stop()
loop = asyncio.get_event_loop()
2015-05-11 17:33:41 -03:00
asyncio.ensure_future(test())
2014-01-16 13:58:01 -04:00
loop.run_forever()
print("Pending tasks at exit: %s" % asyncio.Task.all_tasks(loop))
2014-01-28 18:32:40 -04:00
loop.close()
2014-01-16 13:58:01 -04:00
2016-07-26 06:18:21 -03:00
Expected output:
.. code-block :: none
2014-01-16 13:58:01 -04:00
(1) create file
(2) write into file
(3) close file
Pending tasks at exit: set()
2016-07-26 06:18:21 -03:00
Actual output:
.. code-block :: none
2014-01-16 13:58:01 -04:00
(3) close file
(2) write into file
2014-07-08 07:39:10 -03:00
Pending tasks at exit: {<Task pending create() at test.py:7 wait_for=<Future pending cb=[Task._wakeup()]>>}
Task was destroyed but it is pending!
task: <Task pending create() done at test.py:5 wait_for=<Future pending cb=[Task._wakeup()]>>
2014-01-16 13:58:01 -04:00
The loop stopped before the `` create() `` finished, `` close() `` has been called
before `` write() `` , whereas coroutine functions were called in this order:
`` create() `` , `` write() `` , `` close() `` .
2017-12-11 11:35:49 -04:00
To fix the example, tasks must be marked with `` await `` ::
2014-01-16 13:58:01 -04:00
2017-12-11 11:35:49 -04:00
async def test():
await asyncio.ensure_future(create())
await asyncio.ensure_future(write())
await asyncio.ensure_future(close())
await asyncio.sleep(2.0)
2014-01-16 13:58:01 -04:00
loop.stop()
2015-05-11 17:33:41 -03:00
Or without `` asyncio.ensure_future() `` ::
2014-01-16 13:58:01 -04:00
2017-12-11 11:35:49 -04:00
async def test():
await create()
await write()
await close()
await asyncio.sleep(2.0)
2014-01-16 13:58:01 -04:00
loop.stop()
2014-07-08 07:39:10 -03:00
.. _asyncio-pending-task-destroyed:
Pending task destroyed
----------------------
If a pending task is destroyed, the execution of its wrapped :ref:`coroutine
<coroutine> ` did not complete. It is probably a bug and so a warning is logged.
2016-07-26 06:18:21 -03:00
Example of log:
.. code-block :: none
2014-07-08 07:39:10 -03:00
2014-10-12 16:37:16 -03:00
Task was destroyed but it is pending!
task: <Task pending coro=<kill_me() done, defined at test.py:5> wait_for=<Future pending cb=[Task._wakeup()]>>
:ref: `Enable the debug mode of asyncio <asyncio-debug-mode>` to get the
2016-07-26 06:18:21 -03:00
traceback where the task was created. Example of log in debug mode:
.. code-block :: none
2014-10-12 16:37:16 -03:00
2014-07-08 07:39:10 -03:00
Task was destroyed but it is pending!
source_traceback: Object created at (most recent call last):
2014-10-12 16:37:16 -03:00
File "test.py", line 15, in <module>
2015-05-11 17:33:41 -03:00
task = asyncio.ensure_future(coro, loop=loop)
2014-10-12 16:37:16 -03:00
task: <Task pending coro=<kill_me() done, defined at test.py:5> wait_for=<Future pending cb=[Task._wakeup()] created at test.py:7> created at test.py:15>
2014-07-08 07:39:10 -03:00
.. seealso ::
:ref: `Detect coroutine objects never scheduled <asyncio-coroutine-not-scheduled>` .
2015-02-04 11:14:33 -04:00
.. _asyncio-close-transports:
2015-01-29 20:35:14 -04:00
2015-02-04 11:14:33 -04:00
Close transports and event loops
--------------------------------
2015-01-29 20:35:14 -04:00
When a transport is no more needed, call its `` close() `` method to release
2015-02-04 11:14:33 -04:00
resources. Event loops must also be closed explicitly.
2015-01-29 20:35:14 -04:00
2015-02-04 11:14:33 -04:00
If a transport or an event loop is not closed explicitly, a
:exc: `ResourceWarning` warning will be emitted in its destructor. By default,
:exc: `ResourceWarning` warnings are ignored. The :ref:`Debug mode of asyncio
<asyncio-debug-mode> ` section explains how to display them.