blob: 02a00033152aba764c3ad04daa55ed87493b7199 [file] [log] [blame]
Victor Stinnerdb39a0d2014-01-16 18:58:01 +01001.. currentmodule:: asyncio
2
Victor Stinner0f3e6bc2014-02-19 23:15:02 +01003.. _asyncio-dev:
4
Yury Selivanov805e27e2018-09-14 16:57:11 -07005=======================
6Developing with asyncio
7=======================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +01008
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -04009Asynchronous programming is different from classic "sequential"
Yury Selivanov805e27e2018-09-14 16:57:11 -070010programming.
11
12This page lists common mistakes and traps and explains how
13to avoid them.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +010014
15
Victor Stinner62511fd2014-06-23 00:36:11 +020016.. _asyncio-debug-mode:
17
Yury Selivanov805e27e2018-09-14 16:57:11 -070018Debug Mode
19==========
Victor Stinner62511fd2014-06-23 00:36:11 +020020
Yury Selivanov805e27e2018-09-14 16:57:11 -070021By default asyncio runs in production mode. In order to ease
22the development asyncio has a *debug mode*.
Victor Stinnerd71dcbb2014-08-25 17:04:12 +020023
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040024There are several ways to enable asyncio debug mode:
Victor Stinnerd71dcbb2014-08-25 17:04:12 +020025
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040026* Setting the :envvar:`PYTHONASYNCIODEBUG` environment variable to ``1``.
Victor Stinner6a1b0042015-02-04 16:14:33 +010027
Victor Stinnerb9783d22020-01-24 10:22:18 +010028* Using the :ref:`Python Development Mode <devmode>`.
Victor Stinner62511fd2014-06-23 00:36:11 +020029
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040030* Passing ``debug=True`` to :func:`asyncio.run`.
Yury Selivanov805e27e2018-09-14 16:57:11 -070031
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040032* Calling :meth:`loop.set_debug`.
33
34In addition to enabling the debug mode, consider also:
Yury Selivanov805e27e2018-09-14 16:57:11 -070035
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 Pranskevichus1fa2ec42018-09-17 19:16:44 -040044 using the :option:`-W` ``default`` command line option.
Yury Selivanov805e27e2018-09-14 16:57:11 -070045
46
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040047When the debug mode is enabled:
Yury Selivanov805e27e2018-09-14 16:57:11 -070048
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040049* 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 Selivanov805e27e2018-09-14 16:57:11 -070052
Benjamin Peterson4e3a53b2018-10-26 10:14:04 -070053* Many non-threadsafe asyncio APIs (such as :meth:`loop.call_soon` and
Yury Selivanov805e27e2018-09-14 16:57:11 -070054 :meth:`loop.call_at` methods) raise an exception if they are called
55 from a wrong thread.
56
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040057* The execution time of the I/O selector is logged if it takes too long to
58 perform an I/O operation.
Yury Selivanov805e27e2018-09-14 16:57:11 -070059
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -040060* 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 Stinner1077dee2015-01-30 00:55:58 +010063
64
Victor Stinner606ab032014-02-01 03:18:58 +010065.. _asyncio-multithreading:
66
Yury Selivanov805e27e2018-09-14 16:57:11 -070067Concurrency and Multithreading
68==============================
Victor Stinner606ab032014-02-01 03:18:58 +010069
Yury Selivanov7c7605f2018-09-11 09:54:40 -070070An event loop runs in a thread (typically the main thread) and executes
Yury Selivanov805e27e2018-09-14 16:57:11 -070071all callbacks and Tasks in its thread. While a Task is running in the
72event loop, no other Tasks can run in the same thread. When a Task
73executes an ``await`` expression, the running Task gets suspended, and
74the event loop executes the next Task.
Victor Stinner606ab032014-02-01 03:18:58 +010075
Miss Islington (bot)ddd3c462020-06-22 19:22:45 -070076To schedule a :term:`callback` from another OS thread, the
Yury Selivanov7c7605f2018-09-11 09:54:40 -070077:meth:`loop.call_soon_threadsafe` method should be used. Example::
Victor Stinner5cb84ed2014-02-04 18:18:27 +010078
Guido van Rossum601953b2015-10-05 16:20:00 -070079 loop.call_soon_threadsafe(callback, *args)
Victor Stinner606ab032014-02-01 03:18:58 +010080
Yury Selivanov805e27e2018-09-14 16:57:11 -070081Almost all asyncio objects are not thread safe, which is typically
82not a problem unless there is code that works with them from outside
83of a Task or a callback. If there's a need for such code to call a
84low-level asyncio API, the :meth:`loop.call_soon_threadsafe` method
85should be used, e.g.::
Victor Stinner790202d2014-02-07 19:03:05 +010086
87 loop.call_soon_threadsafe(fut.cancel)
88
Yury Selivanov805e27e2018-09-14 16:57:11 -070089To schedule a coroutine object from a different OS thread, the
Guido van Rossum601953b2015-10-05 16:20:00 -070090:func:`run_coroutine_threadsafe` function should be used. It returns a
91:class:`concurrent.futures.Future` to access the result::
92
Yury Selivanov805e27e2018-09-14 16:57:11 -070093 async def coro_func():
94 return await asyncio.sleep(1, 42)
95
96 # Later in another OS thread:
97
Guido van Rossum601953b2015-10-05 16:20:00 -070098 future = asyncio.run_coroutine_threadsafe(coro_func(), loop)
Yury Selivanov805e27e2018-09-14 16:57:11 -070099 # Wait for the result:
100 result = future.result()
101
102To handle signals and to execute subprocesses, the event loop must be
103run in the main thread.
Guido van Rossum601953b2015-10-05 16:20:00 -0700104
Carol Willing1abba452018-09-12 22:40:37 -0700105The :meth:`loop.run_in_executor` method can be used with a
Yury Selivanov805e27e2018-09-14 16:57:11 -0700106:class:`concurrent.futures.ThreadPoolExecutor` to execute
107blocking code in a different OS thread without blocking the OS thread
108that the event loop runs in.
Victor Stinner399c59d2015-01-09 01:32:02 +0100109
Miss Islington (bot)bf8bf1c2020-09-04 15:31:06 -0700110There is currently no way to schedule coroutines or callbacks directly
111from a different process (such as one started with
112:mod:`multiprocessing`). The :ref:`Event Loop Methods <asyncio-event-loop>`
113section lists APIs that can read from pipes and watch file descriptors
114without blocking the event loop. In addition, asyncio's
115:ref:`Subprocess <asyncio-subprocess>` APIs provide a way to start a
116process and communicate with it from the event loop. Lastly, the
117aforementioned :meth:`loop.run_in_executor` method can also be used
118with a :class:`concurrent.futures.ProcessPoolExecutor` to execute
119code in a different process.
Victor Stinner606ab032014-02-01 03:18:58 +0100120
Victor Stinner45b27ed2014-02-01 02:36:43 +0100121.. _asyncio-handle-blocking:
122
Yury Selivanov805e27e2018-09-14 16:57:11 -0700123Running Blocking Code
124=====================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100125
Yury Selivanov805e27e2018-09-14 16:57:11 -0700126Blocking (CPU-bound) code should not be called directly. For example,
127if a function performs a CPU-intensive calculation for 1 second,
128all concurrent asyncio Tasks and IO operations would be delayed
129by 1 second.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100130
Yury Selivanov805e27e2018-09-14 16:57:11 -0700131An executor can be used to run a task in a different thread or even in
Roger Iyengar675d17c2019-09-04 02:04:09 -0400132a different process to avoid blocking the OS thread with the
Yury Selivanov805e27e2018-09-14 16:57:11 -0700133event loop. See the :meth:`loop.run_in_executor` method for more
134details.
Victor Stinner45b27ed2014-02-01 02:36:43 +0100135
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100136
137.. _asyncio-logger:
138
Victor Stinner45b27ed2014-02-01 02:36:43 +0100139Logging
Yury Selivanov805e27e2018-09-14 16:57:11 -0700140=======
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100141
Yury Selivanov805e27e2018-09-14 16:57:11 -0700142asyncio uses the :mod:`logging` module and all logging is performed
143via the ``"asyncio"`` logger.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100144
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -0400145The default log level is :py:data:`logging.INFO`, which can be easily
Yury Selivanov805e27e2018-09-14 16:57:11 -0700146adjusted::
Guido van Rossumba29a4f2016-10-13 13:56:40 -0700147
Yury Selivanov805e27e2018-09-14 16:57:11 -0700148 logging.getLogger("asyncio").setLevel(logging.WARNING)
Guido van Rossumba29a4f2016-10-13 13:56:40 -0700149
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100150
151.. _asyncio-coroutine-not-scheduled:
152
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -0400153Detect never-awaited coroutines
Yury Selivanov805e27e2018-09-14 16:57:11 -0700154===============================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100155
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -0400156When a coroutine function is called, but not awaited
157(e.g. ``coro()`` instead of ``await coro()``)
158or the coroutine is not scheduled with :meth:`asyncio.create_task`, asyncio
159will emit a :exc:`RuntimeWarning`::
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100160
161 import asyncio
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100162
Andrew Svetlov88743422017-12-11 17:35:49 +0200163 async def test():
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100164 print("never scheduled")
165
Yury Selivanov805e27e2018-09-14 16:57:11 -0700166 async def main():
167 test()
168
169 asyncio.run(main())
170
171Output::
172
173 test.py:7: RuntimeWarning: coroutine 'test' was never awaited
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100174 test()
175
176Output in debug mode::
177
Yury Selivanov805e27e2018-09-14 16:57:11 -0700178 test.py:7: RuntimeWarning: coroutine 'test' was never awaited
179 Coroutine created at (most recent call last)
180 File "../t.py", line 9, in <module>
181 asyncio.run(main(), debug=True)
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100182
Yury Selivanov805e27e2018-09-14 16:57:11 -0700183 < .. >
Victor Stinner530ef2f2014-07-08 12:39:10 +0200184
Yury Selivanov805e27e2018-09-14 16:57:11 -0700185 File "../t.py", line 7, in main
186 test()
187 test()
Victor Stinner530ef2f2014-07-08 12:39:10 +0200188
Yury Selivanov805e27e2018-09-14 16:57:11 -0700189The usual fix is to either await the coroutine or call the
190:meth:`asyncio.create_task` function::
191
192 async def main():
193 await test()
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100194
195
Elvis Pranskevichus1fa2ec42018-09-17 19:16:44 -0400196Detect never-retrieved exceptions
197=================================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100198
Yury Selivanov805e27e2018-09-14 16:57:11 -0700199If a :meth:`Future.set_exception` is called but the Future object is
200never awaited on, the exception would never be propagated to the
201user code. In this case, asyncio would emit a log message when the
202Future object is garbage collected.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100203
Yury Selivanov805e27e2018-09-14 16:57:11 -0700204Example of an unhandled exception::
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100205
206 import asyncio
207
Yury Selivanov805e27e2018-09-14 16:57:11 -0700208 async def bug():
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100209 raise Exception("not consumed")
210
Yury Selivanov805e27e2018-09-14 16:57:11 -0700211 async def main():
212 asyncio.create_task(bug())
213
214 asyncio.run(main())
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100215
216Output::
217
Victor Stinner530ef2f2014-07-08 12:39:10 +0200218 Task exception was never retrieved
Yury Selivanov805e27e2018-09-14 16:57:11 -0700219 future: <Task finished coro=<bug() done, defined at test.py:3>
220 exception=Exception('not consumed')>
221
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100222 Traceback (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700223 File "test.py", line 4, in bug
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100224 raise Exception("not consumed")
225 Exception: not consumed
226
Yury Selivanov805e27e2018-09-14 16:57:11 -0700227:ref:`Enable the debug mode <asyncio-debug-mode>` to get the
228traceback where the task was created::
229
230 asyncio.run(main(), debug=True)
231
232Output in debug mode::
Victor Stinnerab1c8532014-10-12 21:37:16 +0200233
234 Task exception was never retrieved
Yury Selivanov805e27e2018-09-14 16:57:11 -0700235 future: <Task finished coro=<bug() done, defined at test.py:3>
236 exception=Exception('not consumed') created at asyncio/tasks.py:321>
237
Victor Stinnerab1c8532014-10-12 21:37:16 +0200238 source_traceback: Object created at (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700239 File "../t.py", line 9, in <module>
240 asyncio.run(main(), debug=True)
241
242 < .. >
243
Victor Stinnerab1c8532014-10-12 21:37:16 +0200244 Traceback (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700245 File "../t.py", line 4, in bug
Victor Stinnerab1c8532014-10-12 21:37:16 +0200246 raise Exception("not consumed")
247 Exception: not consumed