blob: e8153186760bb79c6183d73b1002327df605b437 [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
Yury Selivanov805e27e2018-09-14 16:57:11 -07009Asynchronous programming is different from classical "sequential"
10programming.
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
Yury Selivanov805e27e2018-09-14 16:57:11 -070024To enable debugging for an application:
Victor Stinnerd71dcbb2014-08-25 17:04:12 +020025
Yury Selivanov805e27e2018-09-14 16:57:11 -070026* Enable the debug mode globally by setting the environment variable
27 :envvar:`PYTHONASYNCIODEBUG` to ``1``.
Victor Stinner6a1b0042015-02-04 16:14:33 +010028
Yury Selivanov805e27e2018-09-14 16:57:11 -070029* Alternatively, the debug mode can be enabled by using the ``-X dev``
30 command line option for Python (see the :option:`-X` option).
Victor Stinner62511fd2014-06-23 00:36:11 +020031
Yury Selivanov805e27e2018-09-14 16:57:11 -070032* 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
36In 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
49In 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 Selivanov7c7605f2018-09-11 09:54:40 -070063 :attr:`loop.slow_callback_duration` attribute is the minimum
Victor Stinner62511fd2014-06-23 00:36:11 +020064 duration in seconds of "slow" callbacks.
Victor Stinner1077dee2015-01-30 00:55:58 +010065
66
Victor Stinner606ab032014-02-01 03:18:58 +010067.. _asyncio-multithreading:
68
Yury Selivanov805e27e2018-09-14 16:57:11 -070069Concurrency and Multithreading
70==============================
Victor Stinner606ab032014-02-01 03:18:58 +010071
Yury Selivanov7c7605f2018-09-11 09:54:40 -070072An event loop runs in a thread (typically the main thread) and executes
Yury Selivanov805e27e2018-09-14 16:57:11 -070073all callbacks and Tasks in its thread. While a Task is running in the
74event loop, no other Tasks can run in the same thread. When a Task
75executes an ``await`` expression, the running Task gets suspended, and
76the event loop executes the next Task.
Victor Stinner606ab032014-02-01 03:18:58 +010077
Yury Selivanov805e27e2018-09-14 16:57:11 -070078To schedule a callback from a different OS thread, the
Yury Selivanov7c7605f2018-09-11 09:54:40 -070079:meth:`loop.call_soon_threadsafe` method should be used. Example::
Victor Stinner5cb84ed2014-02-04 18:18:27 +010080
Guido van Rossum601953b2015-10-05 16:20:00 -070081 loop.call_soon_threadsafe(callback, *args)
Victor Stinner606ab032014-02-01 03:18:58 +010082
Yury Selivanov805e27e2018-09-14 16:57:11 -070083Almost all asyncio objects are not thread safe, which is typically
84not a problem unless there is code that works with them from outside
85of a Task or a callback. If there's a need for such code to call a
86low-level asyncio API, the :meth:`loop.call_soon_threadsafe` method
87should be used, e.g.::
Victor Stinner790202d2014-02-07 19:03:05 +010088
89 loop.call_soon_threadsafe(fut.cancel)
90
Yury Selivanov805e27e2018-09-14 16:57:11 -070091To schedule a coroutine object from a different OS thread, the
Guido van Rossum601953b2015-10-05 16:20:00 -070092:func:`run_coroutine_threadsafe` function should be used. It returns a
93:class:`concurrent.futures.Future` to access the result::
94
Yury Selivanov805e27e2018-09-14 16:57:11 -070095 async def coro_func():
96 return await asyncio.sleep(1, 42)
97
98 # Later in another OS thread:
99
Guido van Rossum601953b2015-10-05 16:20:00 -0700100 future = asyncio.run_coroutine_threadsafe(coro_func(), loop)
Yury Selivanov805e27e2018-09-14 16:57:11 -0700101 # Wait for the result:
102 result = future.result()
103
104To handle signals and to execute subprocesses, the event loop must be
105run in the main thread.
Guido van Rossum601953b2015-10-05 16:20:00 -0700106
Carol Willing1abba452018-09-12 22:40:37 -0700107The :meth:`loop.run_in_executor` method can be used with a
Yury Selivanov805e27e2018-09-14 16:57:11 -0700108:class:`concurrent.futures.ThreadPoolExecutor` to execute
109blocking code in a different OS thread without blocking the OS thread
110that the event loop runs in.
Victor Stinner399c59d2015-01-09 01:32:02 +0100111
Victor Stinner606ab032014-02-01 03:18:58 +0100112
Victor Stinner45b27ed2014-02-01 02:36:43 +0100113.. _asyncio-handle-blocking:
114
Yury Selivanov805e27e2018-09-14 16:57:11 -0700115Running Blocking Code
116=====================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100117
Yury Selivanov805e27e2018-09-14 16:57:11 -0700118Blocking (CPU-bound) code should not be called directly. For example,
119if a function performs a CPU-intensive calculation for 1 second,
120all concurrent asyncio Tasks and IO operations would be delayed
121by 1 second.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100122
Yury Selivanov805e27e2018-09-14 16:57:11 -0700123An executor can be used to run a task in a different thread or even in
124a different process to avoid blocking block the OS thread with the
125event loop. See the :meth:`loop.run_in_executor` method for more
126details.
Victor Stinner45b27ed2014-02-01 02:36:43 +0100127
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100128
129.. _asyncio-logger:
130
Victor Stinner45b27ed2014-02-01 02:36:43 +0100131Logging
Yury Selivanov805e27e2018-09-14 16:57:11 -0700132=======
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100133
Yury Selivanov805e27e2018-09-14 16:57:11 -0700134asyncio uses the :mod:`logging` module and all logging is performed
135via the ``"asyncio"`` logger.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100136
Yury Selivanov805e27e2018-09-14 16:57:11 -0700137The default log level is :py:data:`logging.INFO`, which can easily be
138adjusted::
Guido van Rossumba29a4f2016-10-13 13:56:40 -0700139
Yury Selivanov805e27e2018-09-14 16:57:11 -0700140 logging.getLogger("asyncio").setLevel(logging.WARNING)
Guido van Rossumba29a4f2016-10-13 13:56:40 -0700141
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100142
143.. _asyncio-coroutine-not-scheduled:
144
Yury Selivanov805e27e2018-09-14 16:57:11 -0700145Detect never awaited coroutines
146===============================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100147
Yury Selivanov805e27e2018-09-14 16:57:11 -0700148When a coroutine is called (e.g. ``coro()`` instead of ``await coro()``)
149the call is not wrapped with :meth:`asyncio.create_task`, the execution
150of the coroutine object will never be scheduled. For example::
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100151
152 import asyncio
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100153
Andrew Svetlov88743422017-12-11 17:35:49 +0200154 async def test():
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100155 print("never scheduled")
156
Yury Selivanov805e27e2018-09-14 16:57:11 -0700157 async def main():
158 test()
159
160 asyncio.run(main())
161
162Output::
163
164 test.py:7: RuntimeWarning: coroutine 'test' was never awaited
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100165 test()
166
167Output in debug mode::
168
Yury Selivanov805e27e2018-09-14 16:57:11 -0700169 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 Stinnerdb39a0d2014-01-16 18:58:01 +0100173
Yury Selivanov805e27e2018-09-14 16:57:11 -0700174 < .. >
Victor Stinner530ef2f2014-07-08 12:39:10 +0200175
Yury Selivanov805e27e2018-09-14 16:57:11 -0700176 File "../t.py", line 7, in main
177 test()
178 test()
Victor Stinner530ef2f2014-07-08 12:39:10 +0200179
Yury Selivanov805e27e2018-09-14 16:57:11 -0700180The 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 Stinnerdb39a0d2014-01-16 18:58:01 +0100185
186
Yury Selivanov805e27e2018-09-14 16:57:11 -0700187Detect never consumed exceptions
188================================
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100189
Yury Selivanov805e27e2018-09-14 16:57:11 -0700190If a :meth:`Future.set_exception` is called but the Future object is
191never awaited on, the exception would never be propagated to the
192user code. In this case, asyncio would emit a log message when the
193Future object is garbage collected.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100194
Yury Selivanov805e27e2018-09-14 16:57:11 -0700195Example of an unhandled exception::
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100196
197 import asyncio
198
Yury Selivanov805e27e2018-09-14 16:57:11 -0700199 async def bug():
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100200 raise Exception("not consumed")
201
Yury Selivanov805e27e2018-09-14 16:57:11 -0700202 async def main():
203 asyncio.create_task(bug())
204
205 asyncio.run(main())
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100206
207Output::
208
Victor Stinner530ef2f2014-07-08 12:39:10 +0200209 Task exception was never retrieved
Yury Selivanov805e27e2018-09-14 16:57:11 -0700210 future: <Task finished coro=<bug() done, defined at test.py:3>
211 exception=Exception('not consumed')>
212
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100213 Traceback (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700214 File "test.py", line 4, in bug
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100215 raise Exception("not consumed")
216 Exception: not consumed
217
Yury Selivanov805e27e2018-09-14 16:57:11 -0700218:ref:`Enable the debug mode <asyncio-debug-mode>` to get the
219traceback where the task was created::
220
221 asyncio.run(main(), debug=True)
222
223Output in debug mode::
Victor Stinnerab1c8532014-10-12 21:37:16 +0200224
225 Task exception was never retrieved
Yury Selivanov805e27e2018-09-14 16:57:11 -0700226 future: <Task finished coro=<bug() done, defined at test.py:3>
227 exception=Exception('not consumed') created at asyncio/tasks.py:321>
228
Victor Stinnerab1c8532014-10-12 21:37:16 +0200229 source_traceback: Object created at (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700230 File "../t.py", line 9, in <module>
231 asyncio.run(main(), debug=True)
232
233 < .. >
234
Victor Stinnerab1c8532014-10-12 21:37:16 +0200235 Traceback (most recent call last):
Yury Selivanov805e27e2018-09-14 16:57:11 -0700236 File "../t.py", line 4, in bug
Victor Stinnerab1c8532014-10-12 21:37:16 +0200237 raise Exception("not consumed")
238 Exception: not consumed