blob: 7083e60061ce8984596c79aba2fdf8e08c1a9f97 [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
Victor Stinnerdb39a0d2014-01-16 18:58:01 +01005Develop with asyncio
6====================
7
8Asynchronous programming is different than classical "sequential" programming.
Eli Bendersky679688e2014-01-20 08:13:31 -08009This page lists common traps and explains how to avoid them.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +010010
11
Victor Stinner62511fd2014-06-23 00:36:11 +020012.. _asyncio-debug-mode:
13
14Debug mode of asyncio
15---------------------
16
17To enable the debug mode globally, set the environment variable
Victor Stinnerd71dcbb2014-08-25 17:04:12 +020018:envvar:`PYTHONASYNCIODEBUG` to ``1``. To see debug traces, set the log level
19of the :ref:`asyncio logger <asyncio-logger>` to :py:data:`logging.DEBUG`. The
20simplest configuration is::
21
22 import logging
23 # ...
24 logging.basicConfig(level=logging.DEBUG)
25
26Examples of effects of the debug mode:
Victor Stinner62511fd2014-06-23 00:36:11 +020027
28* Log :ref:`coroutines defined but never "yielded from"
29 <asyncio-coroutine-not-scheduled>`
30* :meth:`~BaseEventLoop.call_soon` and :meth:`~BaseEventLoop.call_at` methods
31 raise an exception if they are called from the wrong thread.
32* Log the execution time of the selector
33* Log callbacks taking more than 100 ms to be executed. The
34 :attr:`BaseEventLoop.slow_callback_duration` attribute is the minimum
35 duration in seconds of "slow" callbacks.
36
37.. seealso::
38
39 The :meth:`BaseEventLoop.set_debug` method and the :ref:`asyncio logger
40 <asyncio-logger>`.
41
42
Victor Stinner606ab032014-02-01 03:18:58 +010043.. _asyncio-multithreading:
44
45Concurrency and multithreading
46------------------------------
47
48An event loop runs in a thread and executes all callbacks and tasks in the same
Victor Stinner86516d92014-02-18 09:22:00 +010049thread. While a task is running in the event loop, no other task is running in
Victor Stinner5cb84ed2014-02-04 18:18:27 +010050the same thread. But when the task uses ``yield from``, the task is suspended
51and the event loop executes the next task.
Victor Stinner606ab032014-02-01 03:18:58 +010052
Victor Stinner5cb84ed2014-02-04 18:18:27 +010053To schedule a callback from a different thread, the
54:meth:`BaseEventLoop.call_soon_threadsafe` method should be used. Example to
Guido van Rossum3c9bb692014-02-04 13:49:34 -080055schedule a coroutine from a different thread::
Victor Stinner5cb84ed2014-02-04 18:18:27 +010056
57 loop.call_soon_threadsafe(asyncio.async, coro_func())
Victor Stinner606ab032014-02-01 03:18:58 +010058
Victor Stinner790202d2014-02-07 19:03:05 +010059Most asyncio objects are not thread safe. You should only worry if you access
60objects outside the event loop. For example, to cancel a future, don't call
61directly its :meth:`Future.cancel` method, but::
62
63 loop.call_soon_threadsafe(fut.cancel)
64
Victor Stinner606ab032014-02-01 03:18:58 +010065To handle signals and to execute subprocesses, the event loop must be run in
66the main thread.
67
68The :meth:`BaseEventLoop.run_in_executor` method can be used with a thread pool
69executor to execute a callback in different thread to not block the thread of
70the event loop.
71
72.. seealso::
73
Zachary Ware5819cfa2015-01-06 00:40:43 -060074 The :ref:`Synchronization primitives <asyncio-sync>` section describes ways
75 to synchronize tasks.
Victor Stinner606ab032014-02-01 03:18:58 +010076
Victor Stinner399c59d2015-01-09 01:32:02 +010077 The :ref:`Subprocess and threads <asyncio-subprocess-threads>` section lists
78 asyncio limitations to run subprocesses from different threads.
79
80
81
Victor Stinner606ab032014-02-01 03:18:58 +010082
Victor Stinner45b27ed2014-02-01 02:36:43 +010083.. _asyncio-handle-blocking:
84
Eli Benderskyb73c8332014-02-09 06:07:47 -080085Handle blocking functions correctly
Victor Stinnerdb39a0d2014-01-16 18:58:01 +010086-----------------------------------
87
88Blocking functions should not be called directly. For example, if a function
89blocks for 1 second, other tasks are delayed by 1 second which can have an
90important impact on reactivity.
91
92For networking and subprocesses, the :mod:`asyncio` module provides high-level
Victor Stinner9592edb2014-02-02 15:03:02 +010093APIs like :ref:`protocols <asyncio-protocol>`.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +010094
95An executor can be used to run a task in a different thread or even in a
96different process, to not block the thread of the event loop. See the
Victor Stinner606ab032014-02-01 03:18:58 +010097:meth:`BaseEventLoop.run_in_executor` method.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +010098
Victor Stinner45b27ed2014-02-01 02:36:43 +010099.. seealso::
100
101 The :ref:`Delayed calls <asyncio-delayed-calls>` section details how the
102 event loop handles time.
103
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100104
105.. _asyncio-logger:
106
Victor Stinner45b27ed2014-02-01 02:36:43 +0100107Logging
108-------
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100109
Victor Stinner45b27ed2014-02-01 02:36:43 +0100110The :mod:`asyncio` module logs information with the :mod:`logging` module in
111the logger ``'asyncio'``.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100112
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100113
114.. _asyncio-coroutine-not-scheduled:
115
116Detect coroutine objects never scheduled
117----------------------------------------
118
Victor Stinner530ef2f2014-07-08 12:39:10 +0200119When a coroutine function is called and its result is not passed to
Zachary Ware5819cfa2015-01-06 00:40:43 -0600120:func:`async` or to the :meth:`BaseEventLoop.create_task` method, the execution
121of the coroutine object will never be scheduled which is probably a bug.
Victor Stinner530ef2f2014-07-08 12:39:10 +0200122:ref:`Enable the debug mode of asyncio <asyncio-debug-mode>` to :ref:`log a
123warning <asyncio-logger>` to detect it.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100124
125Example with the bug::
126
127 import asyncio
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100128
129 @asyncio.coroutine
130 def test():
131 print("never scheduled")
132
133 test()
134
135Output in debug mode::
136
Victor Stinner530ef2f2014-07-08 12:39:10 +0200137 Coroutine test() at test.py:3 was never yielded from
138 Coroutine object created at (most recent call last):
139 File "test.py", line 7, in <module>
140 test()
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100141
Victor Stinner530ef2f2014-07-08 12:39:10 +0200142The fix is to call the :func:`async` function or the
143:meth:`BaseEventLoop.create_task` method with the coroutine object.
144
145.. seealso::
146
147 :ref:`Pending task destroyed <asyncio-pending-task-destroyed>`.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100148
149
Victor Stinner530ef2f2014-07-08 12:39:10 +0200150Detect exceptions never consumed
151--------------------------------
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100152
153Python usually calls :func:`sys.displayhook` on unhandled exceptions. If
Victor Stinner530ef2f2014-07-08 12:39:10 +0200154:meth:`Future.set_exception` is called, but the exception is never consumed,
Zachary Ware5819cfa2015-01-06 00:40:43 -0600155:func:`sys.displayhook` is not called. Instead, :ref:`a log is emitted
Victor Stinner530ef2f2014-07-08 12:39:10 +0200156<asyncio-logger>` when the future is deleted by the garbage collector, with the
157traceback where the exception was raised.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100158
159Example of unhandled exception::
160
161 import asyncio
162
163 @asyncio.coroutine
164 def bug():
165 raise Exception("not consumed")
166
167 loop = asyncio.get_event_loop()
168 asyncio.async(bug())
169 loop.run_forever()
170
171Output::
172
Victor Stinner530ef2f2014-07-08 12:39:10 +0200173 Task exception was never retrieved
Victor Stinnerab1c8532014-10-12 21:37:16 +0200174 future: <Task finished coro=<coro() done, defined at asyncio/coroutines.py:139> exception=Exception('not consumed',)>
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100175 Traceback (most recent call last):
Victor Stinnerab1c8532014-10-12 21:37:16 +0200176 File "asyncio/tasks.py", line 237, in _step
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100177 result = next(coro)
Victor Stinner530ef2f2014-07-08 12:39:10 +0200178 File "asyncio/coroutines.py", line 141, in coro
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100179 res = func(*args, **kw)
Victor Stinnerab1c8532014-10-12 21:37:16 +0200180 File "test.py", line 5, in bug
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100181 raise Exception("not consumed")
182 Exception: not consumed
183
Victor Stinner530ef2f2014-07-08 12:39:10 +0200184:ref:`Enable the debug mode of asyncio <asyncio-debug-mode>` to get the
Victor Stinnerab1c8532014-10-12 21:37:16 +0200185traceback where the task was created. Output in debug mode::
186
187 Task exception was never retrieved
188 future: <Task finished coro=<bug() done, defined at test.py:3> exception=Exception('not consumed',) created at test.py:8>
189 source_traceback: Object created at (most recent call last):
190 File "test.py", line 8, in <module>
191 asyncio.async(bug())
192 Traceback (most recent call last):
193 File "asyncio/tasks.py", line 237, in _step
194 result = next(coro)
195 File "asyncio/coroutines.py", line 79, in __next__
196 return next(self.gen)
197 File "asyncio/coroutines.py", line 141, in coro
198 res = func(*args, **kw)
199 File "test.py", line 5, in bug
200 raise Exception("not consumed")
201 Exception: not consumed
Victor Stinner530ef2f2014-07-08 12:39:10 +0200202
Zachary Ware5819cfa2015-01-06 00:40:43 -0600203There are different options to fix this issue. The first option is to chain the
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100204coroutine in another coroutine and use classic try/except::
205
206 @asyncio.coroutine
207 def handle_exception():
208 try:
209 yield from bug()
210 except Exception:
211 print("exception consumed")
212
213 loop = asyncio.get_event_loop()
214 asyncio.async(handle_exception())
215 loop.run_forever()
216
217Another option is to use the :meth:`BaseEventLoop.run_until_complete`
218function::
219
220 task = asyncio.async(bug())
221 try:
222 loop.run_until_complete(task)
223 except Exception:
224 print("exception consumed")
225
Zachary Ware5819cfa2015-01-06 00:40:43 -0600226.. seealso::
227
228 The :meth:`Future.exception` method.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100229
230
Zachary Ware5819cfa2015-01-06 00:40:43 -0600231Chain coroutines correctly
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100232--------------------------
233
234When a coroutine function calls other coroutine functions and tasks, they
Eli Bendersky679688e2014-01-20 08:13:31 -0800235should be chained explicitly with ``yield from``. Otherwise, the execution is
236not guaranteed to be sequential.
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100237
Eli Bendersky679688e2014-01-20 08:13:31 -0800238Example with different bugs using :func:`asyncio.sleep` to simulate slow
239operations::
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100240
241 import asyncio
242
243 @asyncio.coroutine
244 def create():
245 yield from asyncio.sleep(3.0)
246 print("(1) create file")
247
248 @asyncio.coroutine
249 def write():
250 yield from asyncio.sleep(1.0)
251 print("(2) write into file")
252
253 @asyncio.coroutine
254 def close():
255 print("(3) close file")
256
257 @asyncio.coroutine
258 def test():
259 asyncio.async(create())
260 asyncio.async(write())
261 asyncio.async(close())
262 yield from asyncio.sleep(2.0)
263 loop.stop()
264
265 loop = asyncio.get_event_loop()
266 asyncio.async(test())
267 loop.run_forever()
268 print("Pending tasks at exit: %s" % asyncio.Task.all_tasks(loop))
Victor Stinnerf40c6632014-01-28 23:32:40 +0100269 loop.close()
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100270
271Expected output::
272
273 (1) create file
274 (2) write into file
275 (3) close file
276 Pending tasks at exit: set()
277
278Actual output::
279
280 (3) close file
281 (2) write into file
Victor Stinner530ef2f2014-07-08 12:39:10 +0200282 Pending tasks at exit: {<Task pending create() at test.py:7 wait_for=<Future pending cb=[Task._wakeup()]>>}
283 Task was destroyed but it is pending!
284 task: <Task pending create() done at test.py:5 wait_for=<Future pending cb=[Task._wakeup()]>>
Victor Stinnerdb39a0d2014-01-16 18:58:01 +0100285
286The loop stopped before the ``create()`` finished, ``close()`` has been called
287before ``write()``, whereas coroutine functions were called in this order:
288``create()``, ``write()``, ``close()``.
289
290To fix the example, tasks must be marked with ``yield from``::
291
292 @asyncio.coroutine
293 def test():
294 yield from asyncio.async(create())
295 yield from asyncio.async(write())
296 yield from asyncio.async(close())
297 yield from asyncio.sleep(2.0)
298 loop.stop()
299
300Or without ``asyncio.async()``::
301
302 @asyncio.coroutine
303 def test():
304 yield from create()
305 yield from write()
306 yield from close()
307 yield from asyncio.sleep(2.0)
308 loop.stop()
309
Victor Stinner530ef2f2014-07-08 12:39:10 +0200310
311.. _asyncio-pending-task-destroyed:
312
313Pending task destroyed
314----------------------
315
316If a pending task is destroyed, the execution of its wrapped :ref:`coroutine
317<coroutine>` did not complete. It is probably a bug and so a warning is logged.
318
319Example of log::
320
321 Task was destroyed but it is pending!
Victor Stinnerab1c8532014-10-12 21:37:16 +0200322 task: <Task pending coro=<kill_me() done, defined at test.py:5> wait_for=<Future pending cb=[Task._wakeup()]>>
Victor Stinner530ef2f2014-07-08 12:39:10 +0200323
324:ref:`Enable the debug mode of asyncio <asyncio-debug-mode>` to get the
Victor Stinnerab1c8532014-10-12 21:37:16 +0200325traceback where the task was created. Example of log in debug mode::
326
327 Task was destroyed but it is pending!
328 source_traceback: Object created at (most recent call last):
329 File "test.py", line 15, in <module>
330 task = asyncio.async(coro, loop=loop)
331 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>
332
Victor Stinner530ef2f2014-07-08 12:39:10 +0200333
334.. seealso::
335
336 :ref:`Detect coroutine objects never scheduled <asyncio-coroutine-not-scheduled>`.
337