Error Message shown on handled exception

[p4jo]

Describe the bug

When an exception is thrown during creation of the server app (for example the port is already in use), an exception error message is always printed.
This doesn't happen in asyncio itself, but on line 451 in web.py and in what hides behind it.

This exception is also raised, and so I could handle it silently (or not, and have its error message printed -- arguably with too much traceback) which is how it should be.

Very similar to issue #3497

To Reproduce

You can run the following MWEs.

async def async_error():
    raise EOFError()

import asyncio
try:
    asyncio.get_event_loop().run_until_complete(async_error())
except EOFError:
    print("----- CAUGHT EXCEPTION NORMALLY -----")

from aiohttp import web
try:
    web.run_app(async_error())
except EOFError:
    print("----- CAUGHT EXCEPTION, BUT SEE ABOVE -----")

from aiohttp import web
try:
    # run this example twice. It will throw an OS Error because of the blocked port 8080
    web.run_app(web.Application())
except OSError:
    print("----- CAUGHT EXCEPTION, BUT SEE ABOVE -----")

Expected behavior

I want to catch exceptions during startup silently:

python test.py

----- CAUGHT EXCEPTION NORMALLY -----
----- CAUGHT EXCEPTION, BUT SEE ABOVE -----
----- CAUGHT EXCEPTION, BUT SEE ABOVE -----

Logs/tracebacks

python test.py
----- CAUGHT EXCEPTION NORMALLY -----
unhandled exception during asyncio.run() shutdown
task: <Task finished name='Task-2' coro=<_run_app() done, defined at C:\Python38\lib\site-packages\aiohttp\web.py:287> exception=EOFError()>
Traceback (most recent call last):
  File "C:\Python38\lib\site-packages\aiohttp\web.py", line 514, in run_app
    loop.run_until_complete(main_task)
  File "C:\Python38\lib\asyncio\base_events.py", line 616, in run_until_complete
    return future.result()
  File "C:\Python38\lib\site-packages\aiohttp\web.py", line 308, in _run_app
    app = await app  # type: ignore[misc]
  File "test.py", line 5, in async_error
    raise EOFError()
EOFError
----- CAUGHT EXCEPTION, BUT SEE ABOVE -----
unhandled exception during asyncio.run() shutdown
task: <Task finished name='Task-4' coro=<_run_app() done, defined at C:\Python38\lib\site-packages\aiohttp\web.py:287> exception=OSError(10048, "error while attempting to bind on address ('::', 8080, 0, 0): normalerweise darf jede socketadresse (protokoll, netzwerkadresse oder anschluss) nur jeweils einmal verwendet werden")>
Traceback (most recent call last):
  File "C:\Python38\lib\site-packages\aiohttp\web.py", line 514, in run_app
    loop.run_until_complete(main_task)
  File "C:\Python38\lib\asyncio\base_events.py", line 616, in run_until_complete
    return future.result()
  File "C:\Python38\lib\site-packages\aiohttp\web.py", line 413, in _run_app
    await site.start()
  File "C:\Python38\lib\site-packages\aiohttp\web_runner.py", line 121, in start
    self._server = await loop.create_server(
  File "C:\Python38\lib\asyncio\base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 10048] error while attempting to bind on address ('::', 8080, 0, 0): normalerweise darf jede socketadresse (protokoll, netzwerkadresse oder anschluss) nur jeweils einmal verwendet werden
----- CAUGHT EXCEPTION, BUT SEE ABOVE -----

Python Version

Python 3.8.2

aiohttp Version

3.8.1

multidict Version

6.0.2

yarl Version

1.7.2

OS

Windows 10 21H2

Related component

Server

Additional context

No response

Code of Conduct

• I agree to follow the aio-libs Code of Conduct

[KorcakDaniel]

I have the same issue right now. Python just won't catch the exception.

[hhromic]

We are facing the same issue.
In our case, we are unable to gracefully handle exceptions in cleanup context handlers.
For example:

from aiohttp import web

async def signal(app):
    raise RuntimeError("oops")
    yield

app = web.Application()
app.cleanup_ctx.append(signal)

web.run_app(app)

I have checked the documentation and the source code, and I've been unable to find what is the correct way to handle this.

[Dreamsorcerer]

I mean, that case is trivial:

async def signal(app):
    try:
        ...
    except RuntimeError:
        ...
    yield

Or create a decorator to catch the exception. I'm not sure what the problem is with that..

For the original issue, it looks like the exception gets handled by the loop's exception handling, thus logging it. Not sure if there is much aiohttp can do (but, I'd have to check a bit closer). Though, you could probably install your own exception handler to the loop.

[hhromic]

I mean, that case is trivial:

async def signal(app):
    try:
        ...
    except RuntimeError:
        ...
    yield

Or create a decorator to catch the exception. I'm not sure what the problem is with that..

Agreed that catching it is trivial, but how do you stop the application on unrecoverable exceptions?
For example a database driver that failed to resolve the hostname of the server?

That's my actual problem, how the signal properly propagates an exception to the application to stop.

[Dreamsorcerer]

Well, then let it throw and install a custom exception handler to suppress the logging. I'll try and look at it some time later to see if something can be changed, but a custom exception handler should work currently.

[hhromic]

Ah, that was it.
You mean doing this right?

import asyncio
import logging
from aiohttp import web

def excp_handler(loop, context):
    pass  # or any other local handling logic needed

async def signal(app):
    raise RuntimeError("oops")
    yield

app = web.Application()
app.cleanup_ctx.append(signal)

loop = asyncio.new_event_loop()
loop.set_exception_handler(excp_handler)

try:
    web.run_app(app, loop=loop)
except Exception as excp:
    logging.exception(excp)  # or any top-level handling logic needed

So yes, my confusion was that the default exception handler does the logging by itself.
Python DOES catch the exception fine, it just gets logged by the default loop handler if not changed.
Thanks a lot for the hint on my case!

[Dreamsorcerer]

Yeah, I'm not exactly sure why the exception gets raised and logged, so might need to debug something there.
I wouldn't recommend just ignoring everything in the exception handler though, other things can be logged there in cases where they are uncatchable.

[hhromic]

The task exception (in my case) seems to be raised in this try/except/finally block in run_app() here:

aiohttp/aiohttp/web.py

Lines 514 to 523 in 9c13a52

	try:
	asyncio.set_event_loop(loop)
	loop.run_until_complete(main_task)
	except (GracefulExit, KeyboardInterrupt): # pragma: no cover
	pass
	finally:
	_cancel_tasks({main_task}, loop)
	_cancel_tasks(all_tasks(loop), loop)
	loop.run_until_complete(loop.shutdown_asyncgens())
	loop.close()

Which (in my case) calls _cancel_tasks() and logs the exception here before propagating it to the caller:

aiohttp/aiohttp/web.py

Lines 449 to 459 in 9c13a52

	for task in to_cancel:
	if task.cancelled():
	continue
	if task.exception() is not None:
	loop.call_exception_handler(
	{
	"message": "unhandled exception during asyncio.run() shutdown",
	"exception": task.exception(),
	"task": task,
	}
	)

The following demonstration example only logs the exception (default loop excp handler) but does NOT print "top-level catch" because the GracefulExit exception is set to just pass:

from aiohttp import web

async def signal(app):
    raise web.GracefulExit from RuntimeError("oops")
    yield

app = web.Application()
app.cleanup_ctx.append(signal)

try:
    web.run_app(app)
except:
    print("top-level catch")

Using web.GracefulExit there is a bit of an abuse, yes, but helps showing the exact flow.

With all the above, I'm not exactly sure if aiohttp is doing something wrong or not.
Perhaps the application indeed is expected to install its own exception handler if it wants better logging/handlng.

[Dreamsorcerer]

Yes, it's something to do with it trying to cancel task on the main_task, which is what is then returned from the result. I'll have to sync with upstream asyncio and see if that logic has changed in asyncio.run() since I last looked at it.