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