extmod/uasyncio: Exception handling differences to CPython
During a message exchange with @peterhinch I (re)discovered some incompatibilities I'd like to share. At first it looked like some easy and small difference but the more I dug into it, the more suprised I got.. (keep reading :D )
Even though they might not get "fixed", they will probably need to be documented.
You'll need this test-code to reproduce everything and the addition of asyncio.new_event_loop in PR #5890:
try:
import uasyncio as asyncio
mp = True
except:
import asyncio
mp = False
_tmp_task = None
async def foo():
await asyncio.sleep(0)
print("foo")
1 / 0 # die
async def wait():
await asyncio.sleep(0.5)
print("wait done")
def _handle_exception(loop, context):
print("exception:", context["exception"] if "exception" in context else context["message"])
def _handle_exception_and_stop(loop, context):
print("exception and stop:",
context["exception"] if "exception" in context else context["message"])
loop.stop()
def test(name, func, *args, stop_after_exception=False):
print("---------------------------------")
print("--", name, "stop after exception:", stop_after_exception)
print("---------------------------------")
l = asyncio.new_event_loop()
l.set_exception_handler(
_handle_exception_and_stop if stop_after_exception else _handle_exception)
l.create_task(func(*args))
if mp:
l.create_task(wait())
l.run_forever() # in mp l.run_until_complete doesn't get stopped by loop.stop()
else:
try:
l.run_until_complete(wait())
except RuntimeError as e:
print(e)
##############################################
async def exception_is_caught(*args, **kwargs):
t = asyncio.create_task(foo())
for _ in range(3):
print('Working') # foo is dead, but we carry on
await asyncio.sleep(0.05)
try:
res = await t
except Exception as e:
res = e
print("res", res)
raise AttributeError("Stop test") # Stops the scheduler in exception handler
async def exception_uncaught(*args, **kwargs):
t = asyncio.create_task(foo())
for _ in range(3):
print('Working') # foo is dead, but we carry on
await asyncio.sleep(0.05)
raise AttributeError("Stop test") # Stops the scheduler in exception handler
async def exception_uncaught_task_not_assigned(*args, **kwargs):
asyncio.create_task(foo())
for _ in range(3):
print('Working') # foo is dead, but we carry on
await asyncio.sleep(0.05)
raise AttributeError("Stop test") # Stops the scheduler in exception handler
async def exception_uncaught_task_globally_assigned(*args, **kwargs):
global _tmp_task
_tmp_task = asyncio.create_task(foo())
for _ in range(3):
print('Working') # foo is dead, but we carry on
await asyncio.sleep(0.05)
raise AttributeError("Stop test") # Stops the scheduler in exception handler
##############################################
test("Exception_is_caught", exception_is_caught, stop_after_exception=False)
test("Exception_is_caught", exception_is_caught, stop_after_exception=True)
test("Exception_is_NOT_caught", exception_uncaught, stop_after_exception=False)
test("Exception_is_NOT_caught", exception_uncaught, stop_after_exception=True)
test("Exception_is_NOT_caught_and_task_not_assigned", exception_uncaught_task_not_assigned,
stop_after_exception=False)
test("Exception_is_NOT_caught_and_task_not_assigned", exception_uncaught_task_not_assigned,
stop_after_exception=True)
test("Exception_is_NOT_caught_and_task_globally_assigned",
exception_uncaught_task_globally_assigned,
stop_after_exception=False)
test("Exception_is_NOT_caught_and_task_globally_assigned",
exception_uncaught_task_globally_assigned,
stop_after_exception=True)
Each of the 4 testcases is also tested with making the loop stop after an exception reaches the exception handler.
Exception_is_caught
This test illustrates how CPython asyncio and upy uasyncio handle the case where the exception in the task foo() is caught. However, the test method catches the exception when it calls "await t" but foo() is not catching the exception.
The output on CPython:
---------------------------------
-- Exception_is_caught stop after exception: False
---------------------------------
Working
foo
Working
Working
res division by zero
exception: Stop test
wait done
---------------------------------
-- Exception_is_caught stop after exception: True
---------------------------------
Working
foo
Working
Working
res division by zero
exception and stop: Stop test
Event loop stopped before Future completed.
The output on Upy:
---------------------------------
-- Exception_is_caught stop after exception: False
---------------------------------
Working
foo
exception: divide by zero
Working
Working
res divide by zero
exception: Stop test
wait done
---------------------------------
-- Exception_is_caught stop after exception: True
---------------------------------
Working
foo
exception and stop: divide by zero
This already shows a fundamental difference in exception handling between CPython and upy. CPython holds the exception back until the task that created task foo() has finished. Probably because task foo() could still be awaited and the exception caught, which is the case here.
In upy however there is no obvious parent task so the exception goes to the exception_handler directly, which is incorrect.
Looking at the test variant that stops the loop after an exception reaches the exception_handler makes the difference just more obvious with upy stopping the loop early.
exception_uncaught
In this testcase the exception thrown in foo() is not caught because its task is not awaited.
The output on Cpython:
---------------------------------
-- Exception_is_NOT_caught stop after exception: False
---------------------------------
Working
foo
Working
Working
exception: Stop test
exception: division by zero
wait done
---------------------------------
-- Exception_is_NOT_caught stop after exception: True
---------------------------------
Working
foo
Working
Working
exception and stop: Stop test
exception and stop: division by zero
Event loop stopped before Future completed.
Output on upy:
---------------------------------
-- Exception_is_NOT_caught stop after exception: False
---------------------------------
Working
foo
exception: divide by zero
Working
Working
exception: Stop test
wait done
---------------------------------
-- Exception_is_NOT_caught stop after exception: True
---------------------------------
Working
foo
exception and stop: divide by zero
There's actually not much to say about it, it behaves just like the last test. Cpython holds the exception back because the task could still be awaited while upy raises it to the exception handler immediately.
Purpose of this test: To show that CPython doesn't actually care if the exception in foo() is caught or not.
exception_uncaught_task_not_assigned
This is just like the last test, with the only difference being that the task foo() is not assigned to a variable.
The output on Cpython:
---------------------------------
-- Exception_is_NOT_caught stop after exception: False
---------------------------------
Working
foo
exception: divide by zero
Working
Working
exception: Stop test
wait done
---------------------------------
-- Exception_is_NOT_caught stop after exception: True
---------------------------------
Working
foo
exception and stop: divide by zero
The output on upy:
---------------------------------
-- Exception_is_NOT_caught_and_task_not_assigned stop after exception: False
---------------------------------
Working
foo
exception: divide by zero
Working
Working
exception: Stop test
wait done
---------------------------------
-- Exception_is_NOT_caught_and_task_not_assigned stop after exception: True
---------------------------------
Working
foo
exception and stop: divide by zero
As we can see the Cpython behaviour now changed. The task foo() is not assigned to any variable and therefore can't be awaited, so there is no possibility to catch the exception raised by foo(). Therefore there is no need to hold the exception back and it is raised immediately.
In this scenario Cpython and upy behave exactly the same.
exception_uncaught_task_globally_assigned
This testcase just assigns the task foo() to a global variable to proof that Cpython only raises a tasks exception once the task is not assigned to a variable anymore (or the variable went out of scope).
The output on CPython:
---------------------------------
-- Exception_is_NOT_caught_and_task_globally_assigned stop after exception: False
---------------------------------
Working
foo
Working
Working
exception: Stop test
wait done
---------------------------------
-- Exception_is_NOT_caught_and_task_globally_assigned stop after exception: True
---------------------------------
exception and stop: Task was destroyed but it is pending!
exception: division by zero
Working
foo
Working
Working
exception and stop: Stop test
Event loop stopped before Future completed.
exception and stop: division by zero
The output on upy:
---------------------------------
-- Exception_is_NOT_caught_and_task_globally_assigned stop after exception: False
---------------------------------
Working
foo
exception: divide by zero
Working
Working
exception: Stop test
wait done
---------------------------------
-- Exception_is_NOT_caught_and_task_globally_assigned stop after exception: True
---------------------------------
Working
foo
exception and stop: divide by zero
As we can see in the CPython output, the exception is held back and since the global variable doesn't go out of scope, the exception of foo() is actually raised inside the next test, when the new loop starts.
Summary / tl;dr
In Cpython asyncio exceptions are only raised to the exception handler once the variable to which the task is assigned to goes out of scope (if the task was ever assigned to a variable) AND if that task was never awaited.
In Upy an exception will always be raised to the exception handler if the exception occurs while no other task is actively awaiting the failing task.
Why does this difference matter?
If you rely on a custom exception handler you might end up stopping your program at a different state than Cpython or process exceptions which are then caught by another task. Throw some timing variations into the mix and you can end up with a program that will behave differently on each execution (depending on the timing of awaiting the failing task). Sometimes you will get to the exception_handler, sometimes you don't. Depending on what you do with the exception you might have logged exceptions that are actually just fine or, if you decide to terminate your program when an exception occurs, you might terminate your program prematurely without a real problem.
Also it could lead to people programming "badly", like me. I was so glad about a good option to log uncaught exceptions but now I see that it is a lot more complicated. Relying on the current upy implementation is acceptable for upy if you know that it is different in CPython. But if you think the upy implementation can be used 1:1 in CPython, you end up having lots of difficulties. (e.g. I store most tasks in variables because those tasks often get canceled and recreated. This would behave very differently in CPython with exceptions only (if at all) being thrown after the task got canceled and removed from its variable assignment).
How can this be fixed?
Sadly I don't see an easy way to fix this, because it doesn't only rely on uasyncio internals. I don't know much about the micropython c(++) workings but I doubt that it'll be easy to determine when exactly a task isn't assigned to any variable anymore.
So this will probably end up being a CPython difference that needs to be documented but can't (easily) be fixed.
extmod/uasyncio: Add global exception handling
Support global exception handling to uasyncio according to CPython error handling: https://docs.python.org/3/library/asyncio-eventloop.html#error-handling-api
Adds the Loop methods (also changing all loop methods to be staticmethos or classmethods since there is only one loop) and a default exception handler.
This is especially interesting since this new version of uasyncio doesn't throw exceptions to the caller of "loop.run_forever()" and therefore exceptions in other tasks are only printed to repl, where the user might never see it since the device will be deployed without logging the repl output.
With a global exception handling a user can catch those exceptions and send them by mqtt or log them to a file on the device.
The implementation preallocates a context dictionary so in case of an exception there shouldn't be any RAM allocations.
The used approach is compatible to CPython except for 2 problems:
- There is no way to log the Exception traceback because "sys.print_exception" only prints the traceback to the repl. So there is no way to actually log the traceback, which would be very helpful. Hopefully this can be implemented. I understand that this might cause RAM allocation but a user might decide to use it anyway in a custom exception handler because it makes debugging a lot easier if you know in what file and line the error occured.
Edit: Apparently there is a way so that's fine. - In CPython the exception handler is called once the task is finished which created the task that threw an uncaught exception, whereas in UPy the exception handler is called immediately when the exception is thrown. This makes a difference in the following testcase but is generally just a minor difference that shouldn't cause any abnormal behaviour.
async def test_catch_uncaught_exception():
# can't work with a local return value because the exception handler runs after
# the current coroutine is finished in CPython. Works in UPy though.
res = False
async def fail():
raise TypeError("uncaught exception")
def handle_exception(loop, context):
# context["message"] will always be there; but context["exception"] may not
print(context)
print(context["message"])
print(context["exception"])
msg = context.get("exception", context["message"])
if mp:
print("Caught: {}{}".format(type(context["exception"]), msg))
else:
print("Caught: {}".format({msg}))
nonlocal res
print("res is", res)
res = True
print("done")
t = asyncio.create_task(fail())
loop = asyncio.get_event_loop()
loop.set_exception_handler(handle_exception)
await asyncio.sleep(0.1)
await asyncio.sleep(0.1)
print("coro done")
return res