You like asynchronous programming, and appreciate the elegance of await, tasks and similar  in making asynchronous programming more intuitive and understandable and while all is good, you will likely find that async debugging  is quite tough! Exceptions in the async processes often won't show up in the console or logs until the program itself is terminated.  You end up watching your program just wait when it should have shown an exception and spurred you into debugging! The stages of asynchronous creativity are as below: The underlying reason for the delayed logging of exceptions  is that they bubble up to the calling process, which itself is an async process and will process the exceptions only when it is ready to run in the async loop. Often the calling process is waiting on an 'await' and hence ends up not processing any exceptions, resulting in situation depicted above! 'Whats happening? When the what happened?' Before delving into the issue, here is a solution (you do not have to read any further if you already know the problem and use the decorator below as befitting your code): asyncio pprint, traceback, functools datetime print( ) : func(*args) Exception E:
                print( ) wrapped deco import import import : def exceptionCatcherForAsyncDecorator () : def deco (func) @functools.wraps(func) async : def wrapped (*args) 'wrap function invoked' try return await except as f'Exception occured at: \n ' {datetime.datetime.now()} {pprint.pformat(traceback.format_exc())} raise #re-raise exception to allow process in calling function return return This is a decorator for the async functions that logs exceptions as they occur and hence the problem shows up in your logs immediately as they occur. In this decorator the print function is used to log the exceptions. Problem Description I got into this issue when coding a simple async program containing two async process, one generating data for the other and each executing indefinitely (or forever -- limited to 30 seconds in the demo below). Here is the abstracted code simulating the two async processes also showing the decorator at the top: asyncio pprint, traceback, functools datetime print( ) : func(*args) Exception E:
                print( ) wrapped deco random asyncio.sleep( )
    print( ) m/n :
        myNumerator=random.randint( , )
        myDenominator=random.randint( , )
        result= doProcessing(myNumerator,myDenominator)
        print( ) evtCreator_task = asyncio.create_task(callProcessing()) sleepTime= print( ) asyncio.sleep(sleepTime) ( )
    print( )

asyncio.run(main()) import import import : def exceptionCatcherForAsyncDecorator () : def deco (func) @functools.wraps(func) async : def wrapped (*args) 'wrap function invoked' try return await except as f'Exception occured at: \n ' {datetime.datetime.now()} {pprint.pformat(traceback.format_exc())} raise #re-raise exception to allow process in calling function return return ########## Main program starts here ############## import #@exceptionCatcherForAsyncDecorator() -- decorator commented out for demo async : def doProcessing (m,n) await 1 f' ; ; ' {m} {n} {m/n} return async : def callProcessing () while True 1 100 0 2 await f'result = ' {result} async : def main () # spawn task to create events # Sleep for and terminate. 30 f'Time now: - Sleeping for seconds..' {datetime.datetime.now()} {sleepTime} await print f'Time now: ' {datetime.datetime.now()} '..Terminated!' The two processes in the main program are: a.  doProcessing (simulates complex processing). Here it  'occasionally' generates an exception 'division by 0'. b. callProcessing (supplies input to doProcessing) The third process main() starts the program.  The main() terminates after 30 seconds and causes the doProcessing and callProcessing to be cancelled. Running this code without the decorator (as shown above, the decorator is commented out) results in the exception being visible only after 30 seconds as shown below: $ python asyncDecorator.py 
Time now: 2019-09-30 11:24:13.785183 - Sleeping for 30 seconds..
Time now: 2019-09-30 11:24:43.799021  <== 30 seconds have elapsed..
..Terminated!
Task exception was never retrieved
future: <Task finished coro=<callProcessing() done, defined at asyncDecorator.py:26> exception=ZeroDivisionError('division by zero')>
Traceback (most recent call last):
  File "asyncDecorator.py", line 30, in callProcessing
    result=await doProcessing(myNumerator,myDenominator)
  File "asyncDecorator.py", line 23, in doProcessing
    print(f'{m};{n};{m/n}')
ZeroDivisionError: division by zero Running the same code with the decorator active (i.e. decorator uncommented) results in the exception being logged immediately as it occurred: $ python asyncDecorator.py 
Time now: 2019-09-30 11:32:29.895473 - Sleeping for 30 seconds..
wrap function invoked
Exception occured at: 2019-09-30 11:32:30.896903  <== exception logged as it occurs !
 ('Traceback (most recent call last):\n'
 '  File "asyncDecorator.py", line 11, in wrapped\n'
 '    return await func(*args)\n'
 '  File "asyncDecorator.py", line 23, in doProcessing\n'
 "    print(f'{m};{n};{m/n}')\n"
 'ZeroDivisionError: division by zero\n')
Time now: 2019-09-30 11:32:59.913337 <== 30 seconds elapsed..
..Terminated!
Task exception was never retrieved <== exception logged again due to re-raise by decorator
future: <Task finished coro=<callProcessing() done, defined at asyncDecorator.py:26> exception=ZeroDivisionError('division by zero')>
Traceback (most recent call last):
  File "asyncDecorator.py", line 30, in callProcessing
    result=await doProcessing(myNumerator,myDenominator)
  File "asyncDecorator.py", line 11, in wrapped
    return await func(*args)
  File "asyncDecorator.py", line 23, in doProcessing
    print(f'{m};{n};{m/n}')
ZeroDivisionError: division by zero So if you are perplexed as to what is happening to your async program, this decorator may help.

Reducing Debugging Woes with Python Async Decorator

About Author

Comments

TOPICS

THIS ARTICLE WAS FEATURED IN

Related Stories

Untitled Story

A Javascript Queue Structure for Buffered Data

A Quick Coding Lesson On Go's ‘WaitGroup’ (vs. JavaScript's ‘PromiseAll’)

A Simple Safety Net For Async EventHandlers

Asycn Await BIBLE: Sequential, Parallel, Nest, Dynamic and Error Handle in Javascript

Async-Await ≈ Generators + Promises

A Javascript Queue Structure for Buffered Data

A Quick Coding Lesson On Go's ‘WaitGroup’ (vs. JavaScript's ‘PromiseAll’)

A Simple Safety Net For Async EventHandlers

Asycn Await BIBLE: Sequential, Parallel, Nest, Dynamic and Error Handle in Javascript

Async-Await ≈ Generators + Promises

Light-Mode

Classic

Newspaper

Dark-Mode

Neon Noir

Minty

HN StartUps