Mailman 3 November 2017 - Async-sig

Simplifying stack traces for tasks?
by Mark E. Haase 13 Apr '18

13 Apr '18

If an exception is thrown while the `asyncio` event loop is running, the stack trace is pretty complicated. Here's an example: Traceback (most recent call last): File "sample_client.py", line 616, in <module> loop.run_until_complete(main_task) File "/usr/lib/python3.6/asyncio/base_events.py", line 437, in run_until_complete self.run_forever() File "/usr/lib/python3.6/asyncio/base_events.py", line 405, in run_forever self._run_once() File "/usr/lib/python3.6/asyncio/base_events.py", line 1382, in _run_once handle._run() File "/usr/lib/python3.6/asyncio/events.py", line 126, in _run self._callback(*self._args) File "/usr/lib/python3.6/asyncio/tasks.py", line 315, in _wakeup self._step() File "/usr/lib/python3.6/asyncio/tasks.py", line 239, in _step result = coro.send(None) File "sample_client.py", line 319, in main await actions[args.action](args, socket) File "/usr/lib/python3.6/asyncio/coroutines.py", line 105, in __next__ return self.gen.send(None) File "sample_client.py", line 558, in sync_job await asyncio.sleep(args.delay) File "/usr/lib/python3.6/asyncio/coroutines.py", line 105, in __next__ return self.gen.send(None) File "/usr/lib/python3.6/asyncio/tasks.py", line 522, in sleep future, result) File "/usr/lib/python3.6/asyncio/base_events.py", line 525, in call_later timer = self.call_at(self.time() + delay, callback, *args) File "/usr/lib/python3.6/asyncio/base_events.py", line 541, in call_at timer = events.TimerHandle(when, callback, args, self) File "/usr/lib/python3.6/asyncio/events.py", line 148, in __init__ super().__init__(callback, args, loop) File "/usr/lib/python3.6/asyncio/events.py", line 92, in __init__ self._source_traceback = traceback.extract_stack(sys._getframe(1)) File "/usr/lib/python3.6/traceback.py", line 207, in extract_stack stack = StackSummary.extract(walk_stack(f), limit=limit) File "/usr/lib/python3.6/traceback.py", line 352, in extract filename, lineno, name, lookup_line=False, locals=f_locals)) KeyboardInterrupt Most of the stack frames are inside asyncio (_run, _wakeup, _step) and reveal the mechanics of the event loop. The stack trace would be a lot easier to read (and more similar to a stack trace of an equivalent synchronous program) if it looked like this: Traceback (most recent call last): File "sample_client.py", line 616, in <module> loop.run_until_complete(main_task) ... File "sample_client.py", line 319, in main await actions[args.action](args, socket) ... File "sample_client.py", line 558, in sync_job await asyncio.sleep(args.delay) KeyboardInterrupt I recognize that the event loop mechanics are probably useful in some circumstances, but in my experience working with asyncio for the last year, I've found the stack traces are generally too noisy. For a while, I was pasting stack traces into a text editor and cleaning them up by hand, but a few months ago I wrote a custom excepthook that generates stack traces similar to the one above. def async_excepthook(type_, exc, tb): cause_exc = None cause_str = None if exc.__cause__ is not None: cause_exc = exc.__cause__ cause_str = 'The above exception was the direct cause ' \ 'of the following exception:' elif exc.__context__ is not None and not exc.__suppress_context__: cause_exc = exc.__context__ cause_str = 'During handling of the above exception, ' \ 'another exception occurred:' if cause_exc: async_excepthook(type(cause_exc), cause_exc, cause_exc.__traceback__) if cause_str: print('\n{}\n'.format(cause_str)) print('Async Traceback (most recent call last):') for frame in traceback.extract_tb(tb): head, tail = os.path.split(frame.filename) if (head.endswith('asyncio') or tail == 'traceback.py') and \ frame.name.startswith('_'): print(' ...') continue print(' File "{}", line {}, in {}' .format(frame.filename, frame.lineno, frame.name)) print(' {}'.format(frame.line)) print('{}: {}'.format(type_.__name__, exc)) The meat of it is towards the bottom, "if head.endswith('asyncio')..."There are a lot of debatable details and this implementation is pretty hacky and clumsy, but I have found it valuable in my own usage, and I haven't yet missed the omitted stack frames. I'm posting here to get constructive criticism on the concept and would also like to hear if Curio or Trio have done anything like this. (Based on a quick skim of the docs, I don't think they are.) I might publish a PyPI package if anybody is interested. Cheers, Mark

4 7

APIs for high-bandwidth large I/O?
by Antoine Pitrou 07 Dec '17

07 Dec '17

Hi, I am currently looking into ways to optimize large data transfers for a distributed computing framework (https://github.com/dask/distributed/). We are using Tornado but the question is more general, as it turns out that certain kinds of API are an impediment to such optimizations. To put things short, there are a couple benchmarks discussed here: https://github.com/tornadoweb/tornado/issues/2147#issuecomment-337187960 - for Tornado, this benchmark: https://gist.github.com/pitrou/0f772867008d861c4aa2d2d7b846bbf0 - for asyncio, this benchmark: https://gist.github.com/pitrou/719e73c1df51e817d618186833a6e2cc Both implement a trivial form of framing using the "preferred" APIs of each framework (IOStream for Tornado, Protocol for asyncio), and then benchmark it over 100 MB frames using a simple echo client/server. The results (on Python 3.6) are interesting: - vanilla asyncio achieves 350 MB/s - vanilla Tornado achieves 400 MB/s - asyncio + uvloop achieves 600 MB/s - an optimized Tornado IOStream with a more sophisticated buffering logic (https://github.com/tornadoweb/tornado/pull/2166) achieves 700 MB/s The latter result is especially interesting. uvloop uses hand-crafted Cython code + the C libuv library, still, a pure Python version of Tornado does better thanks to an improved buffering logic in the streaming layer. Even the Tornado result is not ideal. When profiling, we see that 50% of the runtime is actual IO calls (socket.send and socket.recv), but the rest is still overhead. Especially, buffering on the read side still has costly memory copies (b''.join calls take 22% of the time!). For a framed layer, you shouldn't need so many copies. Once you've read the frame length, you can allocate the frame upfront and read into it. It is at odds, however, with the API exposed by asyncio's Protocol: data_received() gives you a new bytes object as soon as data arrives. It's already too late: a spurious memory copy will have to occur. Tornado's IOStream is less constrained, but it supports too many read schemes (including several types of callbacks). So I crafted a limited version of IOStream (*) that supports little functionality, but is able to use socket.recv_into() when asked for a given number of bytes. When benchmarked, this version achieves 950 MB/s. This is still without C code! (*) see https://github.com/tornadoweb/tornado/compare/master...pitrou:stream_readin… When profiling that limited version of IOStream, we see that 68% of the runtime is actual IO calls (socket.send and socket.recv_into). Still, 21% of the total runtime is spent allocating a 100 MB buffer for each frame! That's 70% of the non-IO overhead! Whether or not there are smart ways to reuse that writable buffer depends on how the application intends to use data: does it throw it away before the next read or not? It doesn't sound easily doable in the general case. So I'm wondering which kind of APIs async libraries could expose to make those use cases faster. I know curio and trio have socket objects which would probably fit the bill. I don't know if there are higher-level concepts that may be as adequate for achieving the highest performance. Also, since asyncio is the de facto standard now, I wonder if asyncio might grow such a new API. That may be troublesome: asyncio already has Protocols and Streams, and people often complain about its extensive API surface that's difficult for beginners :-) Addendum: asyncio streams ------------------------- I didn't think asyncio streams would be a good solution, but I still wrote a benchmark variant for them out of curiosity, and it turns out I was right. The results: - vanilla asyncio streams achieve 300 MB/s - asyncio + uvloop streams achieve 550 MB/s The benchmark script is at https://gist.github.com/pitrou/202221ca9c9c74c0b48373ac89e15fd7 Regards Antoine.

5 7

awaiting task is not chaining exception
by Chris Jerdonek 12 Nov '17

12 Nov '17

Hi, I recently encountered a situation with asyncio where the stack trace is getting truncated: an exception isn't getting chained as expected. I was able to reduce it down to the code below. The reduced case seems like a pattern that can come up a lot, and I wasn't able to find an issue on the CPython tracker, so I'm wondering if I'm doing something wrong or if the behavior is deliberate. The way I would describe it is that (at least in this case) awaiting on a task that raises an exception doesn't set __context__ when awaiting on the task inside an "except" block. Here is the code: import asyncio async def raise_error(): raise RuntimeError('exception #2') async def main(): try: raise RuntimeError('exception #1') except Exception: future = raise_error() # Uncommenting the next line makes exc.__context__ None. # future = asyncio.ensure_future(future) try: await future except Exception as exc: print(f'exc: {exc!r}, context: {exc.__context__!r}') raise asyncio.get_event_loop().run_until_complete(main()) Here is the output of the above, which works as expected: exc: RuntimeError('exception #2',), context: RuntimeError('exception #1',) Traceback (most recent call last): File "test.py", line 8, in main raise RuntimeError('exception #1') RuntimeError: exception #1 During handling of the above exception, another exception occurred: Traceback (most recent call last): File "test.py", line 20, in <module> asyncio.get_event_loop().run_until_complete(main()) File "/.../python3.6/asyncio/base_events.py", line 466, in run_until_complete return future.result() File "test.py", line 15, in main await future File "test.py", line 4, in raise_error raise RuntimeError('exception #2') RuntimeError: exception #2 And here is the unexpected output when the commented line is uncommented (exception not getting chained): exc: RuntimeError('exception #2',), context: None Traceback (most recent call last): File "test.py", line 22, in <module> asyncio.get_event_loop().run_until_complete(main()) File "/.../python3.6/asyncio/base_events.py", line 466, in run_until_complete return future.result() File "test.py", line 17, in main await future File "test.py", line 6, in raise_error raise RuntimeError('exception #2') RuntimeError: exception #2 --Chris

3 5

coroutine function vs. function returning awaitable
by Chris Jerdonek 02 Nov '17

02 Nov '17

Hi, I have a 2-part question: 1) Say you have a function that returns an awaitable (but not a coroutine object). Are there any advantages or disadvantages to replacing this with a function for which asyncio.iscoroutinefunction() returns True and asyncio.iscoroutine() returns True for the return value? An advantage might be, say, additional checks that asyncio performs. 2) If there are advantages, is there a straightforward way to construct such a replacement? In the case I have in mind (from an open source project), the "function" you'd be starting with is the class constructor for an async context manager that is also awaitable. So the class has both __aenter__ and __await__ methods. As an example naive attempt, the following _wouldn't_ work: @asyncio.coroutine def connect(): return AsyncConnectManager() The reason this doesn't work is that wrapping connect() in @asyncio.coroutine() means the return value is no longer an async context manager (it no longer has an __aenter__ method). You have to await to get the underlying async context manager. Thanks, --Chris

2 5