Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 1 | .. currentmodule:: asyncio |
| 2 | |
| 3 | Develop with asyncio |
| 4 | ==================== |
| 5 | |
| 6 | Asynchronous programming is different than classical "sequential" programming. |
| 7 | This page lists common traps and explain how to avoid them. |
| 8 | |
| 9 | |
| 10 | Handle correctly blocking functions |
| 11 | ----------------------------------- |
| 12 | |
| 13 | Blocking functions should not be called directly. For example, if a function |
| 14 | blocks for 1 second, other tasks are delayed by 1 second which can have an |
| 15 | important impact on reactivity. |
| 16 | |
| 17 | For networking and subprocesses, the :mod:`asyncio` module provides high-level |
| 18 | APIs like :ref:`protocols <protocol>`. |
| 19 | |
| 20 | An executor can be used to run a task in a different thread or even in a |
| 21 | different process, to not block the thread of the event loop. See the |
| 22 | :func:`BaseEventLoop.run_in_executor` function. |
| 23 | |
| 24 | |
| 25 | .. _asyncio-logger: |
| 26 | |
| 27 | Logger |
| 28 | ------ |
| 29 | |
| 30 | .. data:: asyncio.logger.log |
| 31 | |
| 32 | :class:`logging.Logger` instance used by :mod:`asyncio` to log messages. |
| 33 | |
| 34 | The logger name is ``'asyncio'``. |
| 35 | |
| 36 | .. _asyncio-coroutine-not-scheduled: |
| 37 | |
| 38 | Detect coroutine objects never scheduled |
| 39 | ---------------------------------------- |
| 40 | |
| 41 | When a coroutine function is called but not passed to :func:`async` or to the |
| 42 | :class:`Task` constructor, it is not scheduled and it is probably a bug. |
| 43 | |
| 44 | To detect such bug, set :data:`asyncio.tasks._DEBUG` to ``True``. When the |
| 45 | coroutine object is destroyed by the garbage collector, a log will be emitted |
| 46 | with the traceback where the coroutine function was called. See the |
| 47 | :ref:`asyncio logger <asyncio-logger>`. |
| 48 | |
| 49 | The debug flag changes the behaviour of the :func:`coroutine` decorator. The |
Victor Stinner | 9731183 | 2014-01-17 10:31:02 +0100 | [diff] [blame] | 50 | debug flag value is only used when then coroutine function is defined, not when |
| 51 | it is called. Coroutine functions defined before the debug flag is set to |
Victor Stinner | db39a0d | 2014-01-16 18:58:01 +0100 | [diff] [blame] | 52 | ``True`` will not be tracked. For example, it is not possible to debug |
| 53 | coroutines defined in the :mod:`asyncio` module, because the module must be |
| 54 | imported before the flag value can be changed. |
| 55 | |
| 56 | Example with the bug:: |
| 57 | |
| 58 | import asyncio |
| 59 | asyncio.tasks._DEBUG = True |
| 60 | |
| 61 | @asyncio.coroutine |
| 62 | def test(): |
| 63 | print("never scheduled") |
| 64 | |
| 65 | test() |
| 66 | |
| 67 | Output in debug mode:: |
| 68 | |
| 69 | Coroutine 'test' defined at test.py:4 was never yielded from |
| 70 | |
| 71 | The fix is to call the :func:`async` function or create a :class:`Task` object |
| 72 | with this coroutine object. |
| 73 | |
| 74 | |
| 75 | Detect exceptions not consumed |
| 76 | ------------------------------ |
| 77 | |
| 78 | Python usually calls :func:`sys.displayhook` on unhandled exceptions. If |
| 79 | :meth:`Future.set_exception` is called, but the exception is not consumed, |
| 80 | :func:`sys.displayhook` is not called. Instead, a log is emitted when the |
| 81 | future is deleted by the garbage collector, with the traceback where the |
| 82 | exception was raised. See the :ref:`asyncio logger <asyncio-logger>`. |
| 83 | |
| 84 | Example of unhandled exception:: |
| 85 | |
| 86 | import asyncio |
| 87 | |
| 88 | @asyncio.coroutine |
| 89 | def bug(): |
| 90 | raise Exception("not consumed") |
| 91 | |
| 92 | loop = asyncio.get_event_loop() |
| 93 | asyncio.async(bug()) |
| 94 | loop.run_forever() |
| 95 | |
| 96 | Output:: |
| 97 | |
| 98 | Future/Task exception was never retrieved: |
| 99 | Traceback (most recent call last): |
| 100 | File "/usr/lib/python3.4/asyncio/tasks.py", line 279, in _step |
| 101 | result = next(coro) |
| 102 | File "/usr/lib/python3.4/asyncio/tasks.py", line 80, in coro |
| 103 | res = func(*args, **kw) |
| 104 | File "test.py", line 5, in bug |
| 105 | raise Exception("not consumed") |
| 106 | Exception: not consumed |
| 107 | |
| 108 | There are different options to fix this issue. The first option is to chain to |
| 109 | coroutine in another coroutine and use classic try/except:: |
| 110 | |
| 111 | @asyncio.coroutine |
| 112 | def handle_exception(): |
| 113 | try: |
| 114 | yield from bug() |
| 115 | except Exception: |
| 116 | print("exception consumed") |
| 117 | |
| 118 | loop = asyncio.get_event_loop() |
| 119 | asyncio.async(handle_exception()) |
| 120 | loop.run_forever() |
| 121 | |
| 122 | Another option is to use the :meth:`BaseEventLoop.run_until_complete` |
| 123 | function:: |
| 124 | |
| 125 | task = asyncio.async(bug()) |
| 126 | try: |
| 127 | loop.run_until_complete(task) |
| 128 | except Exception: |
| 129 | print("exception consumed") |
| 130 | |
| 131 | See also the :meth:`Future.exception` method. |
| 132 | |
| 133 | |
| 134 | Chain correctly coroutines |
| 135 | -------------------------- |
| 136 | |
| 137 | When a coroutine function calls other coroutine functions and tasks, they |
| 138 | should chained explicitly with ``yield from``. Otherwise, the execution is no |
| 139 | more guaranteed to be sequential. |
| 140 | |
| 141 | Example with different bugs using sleep to simulate slow operations:: |
| 142 | |
| 143 | import asyncio |
| 144 | |
| 145 | @asyncio.coroutine |
| 146 | def create(): |
| 147 | yield from asyncio.sleep(3.0) |
| 148 | print("(1) create file") |
| 149 | |
| 150 | @asyncio.coroutine |
| 151 | def write(): |
| 152 | yield from asyncio.sleep(1.0) |
| 153 | print("(2) write into file") |
| 154 | |
| 155 | @asyncio.coroutine |
| 156 | def close(): |
| 157 | print("(3) close file") |
| 158 | |
| 159 | @asyncio.coroutine |
| 160 | def test(): |
| 161 | asyncio.async(create()) |
| 162 | asyncio.async(write()) |
| 163 | asyncio.async(close()) |
| 164 | yield from asyncio.sleep(2.0) |
| 165 | loop.stop() |
| 166 | |
| 167 | loop = asyncio.get_event_loop() |
| 168 | asyncio.async(test()) |
| 169 | loop.run_forever() |
| 170 | print("Pending tasks at exit: %s" % asyncio.Task.all_tasks(loop)) |
| 171 | |
| 172 | Expected output:: |
| 173 | |
| 174 | (1) create file |
| 175 | (2) write into file |
| 176 | (3) close file |
| 177 | Pending tasks at exit: set() |
| 178 | |
| 179 | Actual output:: |
| 180 | |
| 181 | (3) close file |
| 182 | (2) write into file |
| 183 | Pending tasks at exit: {Task(<create>)<PENDING>} |
| 184 | |
| 185 | The loop stopped before the ``create()`` finished, ``close()`` has been called |
| 186 | before ``write()``, whereas coroutine functions were called in this order: |
| 187 | ``create()``, ``write()``, ``close()``. |
| 188 | |
| 189 | To fix the example, tasks must be marked with ``yield from``:: |
| 190 | |
| 191 | @asyncio.coroutine |
| 192 | def test(): |
| 193 | yield from asyncio.async(create()) |
| 194 | yield from asyncio.async(write()) |
| 195 | yield from asyncio.async(close()) |
| 196 | yield from asyncio.sleep(2.0) |
| 197 | loop.stop() |
| 198 | |
| 199 | Or without ``asyncio.async()``:: |
| 200 | |
| 201 | @asyncio.coroutine |
| 202 | def test(): |
| 203 | yield from create() |
| 204 | yield from write() |
| 205 | yield from close() |
| 206 | yield from asyncio.sleep(2.0) |
| 207 | loop.stop() |
| 208 | |
| 209 | .. XXX: Document "poll xxx" log message? |
| 210 | |