Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 1 | .. currentmodule:: asyncio |
| 2 | |
Victor Stinner | 0f3e6bc | 2014-02-19 23:15:02 +0100 | [diff] [blame] | 3 | .. _asyncio-dev: |
| 4 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 5 | ======================= |
| 6 | Developing with asyncio |
| 7 | ======================= |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 8 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 9 | Asynchronous programming is different from classical "sequential" |
| 10 | programming. |
| 11 | |
| 12 | This page lists common mistakes and traps and explains how |
| 13 | to avoid them. |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 14 | |
| 15 | |
Victor Stinner | 62511fd | 2014-06-23 00:36:11 +0200 | [diff] [blame] | 16 | .. _asyncio-debug-mode: |
| 17 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 18 | Debug Mode |
| 19 | ========== |
Victor Stinner | 62511fd | 2014-06-23 00:36:11 +0200 | [diff] [blame] | 20 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 21 | By default asyncio runs in production mode. In order to ease |
| 22 | the development asyncio has a *debug mode*. |
Victor Stinner | d71dcbb | 2014-08-25 17:04:12 +0200 | [diff] [blame] | 23 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 24 | To enable debugging for an application: |
Victor Stinner | d71dcbb | 2014-08-25 17:04:12 +0200 | [diff] [blame] | 25 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 26 | * Enable the debug mode globally by setting the environment variable |
| 27 | :envvar:`PYTHONASYNCIODEBUG` to ``1``. |
Victor Stinner | 6a1b004 | 2015-02-04 16:14:33 +0100 | [diff] [blame] | 28 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 29 | * Alternatively, the debug mode can be enabled by using the ``-X dev`` |
| 30 | command line option for Python (see the :option:`-X` option). |
Victor Stinner | 62511fd | 2014-06-23 00:36:11 +0200 | [diff] [blame] | 31 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 32 | * Yet another way to enable the debug mode is by calling |
| 33 | :meth:`loop.set_debug` or by passing ``debug=True`` to |
| 34 | :func:`asyncio.run`. |
| 35 | |
| 36 | In addition to enabling debug mode, consider also: |
| 37 | |
| 38 | * setting the log level of the :ref:`asyncio logger <asyncio-logger>` to |
| 39 | :py:data:`logging.DEBUG`, for example the following snippet of code |
| 40 | can be run at startup of the application:: |
| 41 | |
| 42 | logging.basicConfig(level=logging.DEBUG) |
| 43 | |
| 44 | * configuring the :mod:`warnings` module to display |
| 45 | :exc:`ResourceWarning` warnings. One way of doing that is by |
| 46 | using the ``-Wdefault`` command line option. |
| 47 | |
| 48 | |
| 49 | In asyncio debug mode the following checks are performed: |
| 50 | |
| 51 | * Log :ref:`coroutines that were not awaited |
| 52 | <asyncio-coroutine-not-scheduled>`; this mitigates the "forgotten |
| 53 | await" pitfall. |
| 54 | |
| 55 | * Many non-treadsafe asyncio APIs (such as :meth:`loop.call_soon` and |
| 56 | :meth:`loop.call_at` methods) raise an exception if they are called |
| 57 | from a wrong thread. |
| 58 | |
| 59 | * Log the execution time of the IO selector if it takes too long to |
| 60 | perform an IO operation. |
| 61 | |
| 62 | * Log callbacks taking longer than 100 ms to be executed. The |
Yury Selivanov | 7c7605f | 2018-09-11 09:54:40 -0700 | [diff] [blame] | 63 | :attr:`loop.slow_callback_duration` attribute is the minimum |
Victor Stinner | 62511fd | 2014-06-23 00:36:11 +0200 | [diff] [blame] | 64 | duration in seconds of "slow" callbacks. |
Victor Stinner | 1077dee | 2015-01-30 00:55:58 +0100 | [diff] [blame] | 65 | |
| 66 | |
Victor Stinner | 606ab03 | 2014-02-01 03:18:58 +0100 | [diff] [blame] | 67 | .. _asyncio-multithreading: |
| 68 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 69 | Concurrency and Multithreading |
| 70 | ============================== |
Victor Stinner | 606ab03 | 2014-02-01 03:18:58 +0100 | [diff] [blame] | 71 | |
Yury Selivanov | 7c7605f | 2018-09-11 09:54:40 -0700 | [diff] [blame] | 72 | An event loop runs in a thread (typically the main thread) and executes |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 73 | all callbacks and Tasks in its thread. While a Task is running in the |
| 74 | event loop, no other Tasks can run in the same thread. When a Task |
| 75 | executes an ``await`` expression, the running Task gets suspended, and |
| 76 | the event loop executes the next Task. |
Victor Stinner | 606ab03 | 2014-02-01 03:18:58 +0100 | [diff] [blame] | 77 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 78 | To schedule a callback from a different OS thread, the |
Yury Selivanov | 7c7605f | 2018-09-11 09:54:40 -0700 | [diff] [blame] | 79 | :meth:`loop.call_soon_threadsafe` method should be used. Example:: |
Victor Stinner | 5cb84ed | 2014-02-04 18:18:27 +0100 | [diff] [blame] | 80 | |
Guido van Rossum | 601953b | 2015-10-05 16:20:00 -0700 | [diff] [blame] | 81 | loop.call_soon_threadsafe(callback, *args) |
Victor Stinner | 606ab03 | 2014-02-01 03:18:58 +0100 | [diff] [blame] | 82 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 83 | Almost all asyncio objects are not thread safe, which is typically |
| 84 | not a problem unless there is code that works with them from outside |
| 85 | of a Task or a callback. If there's a need for such code to call a |
| 86 | low-level asyncio API, the :meth:`loop.call_soon_threadsafe` method |
| 87 | should be used, e.g.:: |
Victor Stinner | 790202d | 2014-02-07 19:03:05 +0100 | [diff] [blame] | 88 | |
| 89 | loop.call_soon_threadsafe(fut.cancel) |
| 90 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 91 | To schedule a coroutine object from a different OS thread, the |
Guido van Rossum | 601953b | 2015-10-05 16:20:00 -0700 | [diff] [blame] | 92 | :func:`run_coroutine_threadsafe` function should be used. It returns a |
| 93 | :class:`concurrent.futures.Future` to access the result:: |
| 94 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 95 | async def coro_func(): |
| 96 | return await asyncio.sleep(1, 42) |
| 97 | |
| 98 | # Later in another OS thread: |
| 99 | |
Guido van Rossum | 601953b | 2015-10-05 16:20:00 -0700 | [diff] [blame] | 100 | future = asyncio.run_coroutine_threadsafe(coro_func(), loop) |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 101 | # Wait for the result: |
| 102 | result = future.result() |
| 103 | |
| 104 | To handle signals and to execute subprocesses, the event loop must be |
| 105 | run in the main thread. |
Guido van Rossum | 601953b | 2015-10-05 16:20:00 -0700 | [diff] [blame] | 106 | |
Carol Willing | 1abba45 | 2018-09-12 22:40:37 -0700 | [diff] [blame] | 107 | The :meth:`loop.run_in_executor` method can be used with a |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 108 | :class:`concurrent.futures.ThreadPoolExecutor` to execute |
| 109 | blocking code in a different OS thread without blocking the OS thread |
| 110 | that the event loop runs in. |
Victor Stinner | 399c59d | 2015-01-09 01:32:02 +0100 | [diff] [blame] | 111 | |
Victor Stinner | 606ab03 | 2014-02-01 03:18:58 +0100 | [diff] [blame] | 112 | |
Victor Stinner | 45b27ed | 2014-02-01 02:36:43 +0100 | [diff] [blame] | 113 | .. _asyncio-handle-blocking: |
| 114 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 115 | Running Blocking Code |
| 116 | ===================== |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 117 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 118 | Blocking (CPU-bound) code should not be called directly. For example, |
| 119 | if a function performs a CPU-intensive calculation for 1 second, |
| 120 | all concurrent asyncio Tasks and IO operations would be delayed |
| 121 | by 1 second. |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 122 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 123 | An executor can be used to run a task in a different thread or even in |
| 124 | a different process to avoid blocking block the OS thread with the |
| 125 | event loop. See the :meth:`loop.run_in_executor` method for more |
| 126 | details. |
Victor Stinner | 45b27ed | 2014-02-01 02:36:43 +0100 | [diff] [blame] | 127 | |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 128 | |
| 129 | .. _asyncio-logger: |
| 130 | |
Victor Stinner | 45b27ed | 2014-02-01 02:36:43 +0100 | [diff] [blame] | 131 | Logging |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 132 | ======= |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 133 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 134 | asyncio uses the :mod:`logging` module and all logging is performed |
| 135 | via the ``"asyncio"`` logger. |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 136 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 137 | The default log level is :py:data:`logging.INFO`, which can easily be |
| 138 | adjusted:: |
Guido van Rossum | ba29a4f | 2016-10-13 13:56:40 -0700 | [diff] [blame] | 139 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 140 | logging.getLogger("asyncio").setLevel(logging.WARNING) |
Guido van Rossum | ba29a4f | 2016-10-13 13:56:40 -0700 | [diff] [blame] | 141 | |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 142 | |
| 143 | .. _asyncio-coroutine-not-scheduled: |
| 144 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 145 | Detect never awaited coroutines |
| 146 | =============================== |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 147 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 148 | When a coroutine is called (e.g. ``coro()`` instead of ``await coro()``) |
| 149 | the call is not wrapped with :meth:`asyncio.create_task`, the execution |
| 150 | of the coroutine object will never be scheduled. For example:: |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 151 | |
| 152 | import asyncio |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 153 | |
Andrew Svetlov | 8874342 | 2017-12-11 17:35:49 +0200 | [diff] [blame] | 154 | async def test(): |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 155 | print("never scheduled") |
| 156 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 157 | async def main(): |
| 158 | test() |
| 159 | |
| 160 | asyncio.run(main()) |
| 161 | |
| 162 | Output:: |
| 163 | |
| 164 | test.py:7: RuntimeWarning: coroutine 'test' was never awaited |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 165 | test() |
| 166 | |
| 167 | Output in debug mode:: |
| 168 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 169 | test.py:7: RuntimeWarning: coroutine 'test' was never awaited |
| 170 | Coroutine created at (most recent call last) |
| 171 | File "../t.py", line 9, in <module> |
| 172 | asyncio.run(main(), debug=True) |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 173 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 174 | < .. > |
Victor Stinner | 530ef2f | 2014-07-08 12:39:10 +0200 | [diff] [blame] | 175 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 176 | File "../t.py", line 7, in main |
| 177 | test() |
| 178 | test() |
Victor Stinner | 530ef2f | 2014-07-08 12:39:10 +0200 | [diff] [blame] | 179 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 180 | The usual fix is to either await the coroutine or call the |
| 181 | :meth:`asyncio.create_task` function:: |
| 182 | |
| 183 | async def main(): |
| 184 | await test() |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 185 | |
| 186 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 187 | Detect never consumed exceptions |
| 188 | ================================ |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 189 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 190 | If a :meth:`Future.set_exception` is called but the Future object is |
| 191 | never awaited on, the exception would never be propagated to the |
| 192 | user code. In this case, asyncio would emit a log message when the |
| 193 | Future object is garbage collected. |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 194 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 195 | Example of an unhandled exception:: |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 196 | |
| 197 | import asyncio |
| 198 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 199 | async def bug(): |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 200 | raise Exception("not consumed") |
| 201 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 202 | async def main(): |
| 203 | asyncio.create_task(bug()) |
| 204 | |
| 205 | asyncio.run(main()) |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 206 | |
| 207 | Output:: |
| 208 | |
Victor Stinner | 530ef2f | 2014-07-08 12:39:10 +0200 | [diff] [blame] | 209 | Task exception was never retrieved |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 210 | future: <Task finished coro=<bug() done, defined at test.py:3> |
| 211 | exception=Exception('not consumed')> |
| 212 | |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 213 | Traceback (most recent call last): |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 214 | File "test.py", line 4, in bug |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 215 | raise Exception("not consumed") |
| 216 | Exception: not consumed |
| 217 | |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 218 | :ref:`Enable the debug mode <asyncio-debug-mode>` to get the |
| 219 | traceback where the task was created:: |
| 220 | |
| 221 | asyncio.run(main(), debug=True) |
| 222 | |
| 223 | Output in debug mode:: |
Victor Stinner | ab1c853 | 2014-10-12 21:37:16 +0200 | [diff] [blame] | 224 | |
| 225 | Task exception was never retrieved |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 226 | future: <Task finished coro=<bug() done, defined at test.py:3> |
| 227 | exception=Exception('not consumed') created at asyncio/tasks.py:321> |
| 228 | |
Victor Stinner | ab1c853 | 2014-10-12 21:37:16 +0200 | [diff] [blame] | 229 | source_traceback: Object created at (most recent call last): |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 230 | File "../t.py", line 9, in <module> |
| 231 | asyncio.run(main(), debug=True) |
| 232 | |
| 233 | < .. > |
| 234 | |
Victor Stinner | ab1c853 | 2014-10-12 21:37:16 +0200 | [diff] [blame] | 235 | Traceback (most recent call last): |
Yury Selivanov | 805e27e | 2018-09-14 16:57:11 -0700 | [diff] [blame] | 236 | File "../t.py", line 4, in bug |
Victor Stinner | ab1c853 | 2014-10-12 21:37:16 +0200 | [diff] [blame] | 237 | raise Exception("not consumed") |
| 238 | Exception: not consumed |