Mailman 3 January 2018 - 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

Blog post: Timeouts and cancellation for humans
by Nathaniel Smith 16 Jan '18

16 Jan '18

Hi all, Folks here might be interested in this new blog post: https://vorpus.org/blog/timeouts-and-cancellation-for-humans/ It's a detailed discussion of pitfalls and design-tradeoffs in APIs for timeout and cancellation, and has a proposal for handling them in a more Pythonic way. Any feedback welcome! -n -- Nathaniel J. Smith -- https://vorpus.org

5 12

Asyncio loop instrumentation
by Pau Freixes 02 Jan '18

02 Jan '18

Hi, foks First of all, I hope that you have had a good 2017 and I wish for your the best for 2018. This email is the continuation of a plan B of the first proposal [1] to articulate a way to measure the load of the Asyncio loop. The main objections with the first implementation were focused on the technical debt that the implementation imposed, taking into account that the feature was definitely out of the main scope of the Asyncio loop goal. Nathaniel proposed a plan B based on implement some kind of instrumentalization that will allow developers to implement features such as the load one. I put off the plan for a while having, wrongly, feeling that an implementation of the loop wired with the proper events will impact with the loop performance. Far away from the reality, the suggested implementation in terms of performance penalty is almost negligible, at least for what I considered the happy path which means that there are no instruments listening for these events. These new implementation of the load method - remember that it returns a load factor between 0.0 and 1.0 that inform you about how bussy is your loop - based on an instrument can be checked with the following snippet: async def coro(loop, idx): await asyncio.sleep(idx % 10) if load() > 0.9: return False start = loop.time() while loop.time() - start < 0.02: pass return True async def run(loop, n): tasks = [coro(loop, i) for i in range(n)] results = await asyncio.gather(*tasks) abandoned = len([r for r in results if not r]) print("Load reached for {} coros/seq: {}, abandoned {}/{}".format(n/10, load(), abandoned)) async def main(loop): await run(loop, 100) loop = asyncio.get_event_loop() loop.add_instrument(LoadInstrument) loop.run_until_complete(main(loop)) The `LoadInstrument` [2] meets the contract of the LoopInstrument[3] that allow it to listen the proper loop signals that will be used to calculate the load of the loop. For this proposal [4], POC, I've preferred make a reduced list of events: * `loop_start` : Executed when the loop starts for the first time. * `tick_start` : Executed when a new loop tick is started. * `io_start` : Executed when a new IO process starts. * `io_end` : Executed when the IO process ends. * `tick_end` : Executed when the loop tick ends. * `loop_stop` : Executed when the loop stops. The idea of giving just this short list of events try to avoid over complicate third loops implementations, implementing the minimum set of events that a typical reactor has to implement. I would like to gather your feedback for this new approximation, and if you believe that it might be interesting which are the next steps that must be done. Cheers, [1] https://mail.python.org/pipermail/async-sig/2017-August/000382.html [2] https://github.com/pfreixes/asyncio_load_instrument/blob/master/asyncio_loa… [3] https://github.com/pfreixes/cpython/blob/asyncio_loop_instrumentation/Lib/a… [4] https://github.com/pfreixes/cpython/commit/adc3ba46979394997c40aa89178b4724… -- --pau

4 7