Any particular reason why calls to _handle_request_exception(e) or on_finish() are not being awaited ?

[ghevge]

Hi,

Any particular reason why methods calls to _handle_request_exception(e) or on_finish() are not being awaited ?

tornado/tornado/web.py

Line 1709 in 1db5b45

self._handle_request_exception(e)

In my implementation I'm overwriting these methods, but I need async support on them. I was trying to use asyncio functionality to handle my async calls , but it doesn't work properly in my project.

It's much easier to make a sync call from an async method then to make an async call from a sync method.

Thanks

[mivade]

In the implementation there's no reason for that method to be async. By convention methods that are prepended with an underscore are private and generally shouldn't be overridden by subclasses. You're probably better off doing something like

class MyRequestHandler(RequestHandler):
    async def get(self):
        try:
            ...
        except Exception as e:
            await my_async_exception_handler(e)

[ghevge]

OK, _handle_request_exception(e) is private I get that, but on_finish() is public.

Regarding _handle_request_exception, I have to deal with some old code which I've inherited from folks who are no longer with the company. And they decided to overwrite and use this method to handle errors that are not being caught at the controllers level, as a last line of defense. So I'm kind of stuck with this approach as it is a big project and I'm not planning to change everything to fix this. Anyhow I will see what I can do.

[mivade]

You're right about on_finish. The documentation describes it as a counterpart to prepare which may be awaitable. Maybe it would make sense to allow it to be asynchronous, too.

[ploxiln]

You can use IOLoop.current().spawn_callback() from on_finish() to trigger an async function. on_finish() can't affect the request/response (it's too late), so it's not really necessary for on_finish() to be able to suspend/resume.

[bdarnell]

_handle_request_exception is private, but in the early days of Tornado it was the only error-handling hook available so it was common to override it. Today (since version 3.1 it's generally possible to override log_exception() and write_error() instead. Neither of those are currently allowed to be async either.

For all three methods (write_error, log_exception, and on_finish), I'd make them async if I was starting from scratch. The main reason they're synchronous is that they were introduced when async code required explicit callback arguments and it was generally used sparingly. Now it's much easier to use async functions but there are backwards-compatibility headaches with retrofitting async into existing interfaces, especially with the variety of ways that people modify RequestHandler in subclasses. If there's enough demand we could consider it, but this is the first time I recall seeing interest in async versions of _handle_request_exception or the methods that replaced it (I think on_finish has come up once before).

[ghevge]

My problem is that I'm trying to migrate sqlalchemy to use the new async support (this is a new feature. Couple of month old). And I have some calls to sqlalchemy in my overwritten _handle_request_exception and on_finish calls too. The problem with the sqlalchemy is that once I switch to async calls, I cannot run sync anymore. On top of this I am also cleaning up some context_vars on these 2 methods. So I can manage to trigger the async execution of the sqlalchemy calls, from the sync methods, using a task, but I'm having problems cleaning up the context vars.

Maybe you can give me some ideas on how I can achieve this?

m-middleware-server | Traceback (most recent call last): m-middleware-server | File "/bolt-webserver/bolt/api/handlers.py", line 457, in on_finish m-middleware-server | super().on_finish() m-middleware-server | File "/usr/local/lib/python3.9/site-packages/tornado_opentracing/handlers.py", line 48, in on_finish m-middleware-server | tracing._finish_tracing(handler) m-middleware-server | File "/usr/local/lib/python3.9/site-packages/tornado_opentracing/_tracing.py", line 177, in _finish_tracing m-middleware-server | scope.close() m-middleware-server | File "/usr/local/lib/python3.9/site-packages/opentracing/scope_managers/contextvars.py", line 101, in close m-middleware-server | _SCOPE.reset(self._token) m-middleware-server | ValueError: <Token var=<ContextVar name='scope' at 0x7fab7ccef7c0> at 0x7fab7b484740> was created in a different Context

My code looks something like this. I was also trying to wait for the task completion but I believe because time.sleep is blocking, the task never gets completed.

`def _handle_request_exception(self, e):
loop = asyncio.get_running_loop()
coro = self._handle_async_request_exception(e)
task = asyncio.create_task(coro)
#while not task.done():
# print('========================sle====================')
# time.sleep(0.5)
#self.test()

def test(future):
    print('========================te====================')
    self.finish()

async def _handle_async_request_exception(self, e):
    print('========================he====================')
    if isinstance(e, SecurityError):
        security_log.warning(e)
        if e.__cause__:
            self._log_error_cause(e.__cause__, logger=security_log, level=logging.WARNING)

        # No information should be disclosed in the HTTP response about
        # what caused the security error...
        self.set_status(500)
        self.finish()
    elif isinstance(e, BoltHTTPError):
        if e.error_to_log:
            log.error(e.error_to_log)
        self.set_status(e.status_code)
        self.write(e.payload)
        self.finish()
    elif isinstance(e, HTTPError):
        self.set_status(e.code)
        if e.response.body:
            for v in e.response.headers.get_list('content-type'):
                self.add_header('Content-Type', v)
            self.write(e.response.body)
        self.finish()
    elif isinstance(e, SQLAlchemyError):
        await self.db.rollback()
        super()._handle_request_exception(e)
    else:
        super()._handle_request_exception(e)`

Thanks

[ghevge]

Can you please let me know which are the chances to get async support for on_finish and an async hook to handle request exceptions ? I won't be able to complete my conversion without these changes, so at least I can decide if I should continue or not.
Thanks

[bdarnell]

It's doable, but I have very little time for Tornado these days and adapting to the changes in Python 3.10 takes priority, so it might be a while before I get to it.

There's a design question around making these methods async: What, if anything, happens when the async parts complete? Do we block starting the next request on the connection while the async on_finish completes? That doesn't seem ideal, but that's what's implied by making the method async. If you want it to be fire-and-forget without blocking anything, you can just handle this today by spawning an async callback from your synchronous on_finish.

To make on_finish async and block the rest of the connection we'd need to move its call site from finish() to _execute(). I think that's probably OK but it may need to be a new method instead. Making _handle_request_exception async actually looks easier, although I'm reluctant to touch that one (I'd argue that you should be doing your transaction rollback from on_finish instead of _handle_request_exception. My philosophy is that commits should always be explicit and if you reach the end of the request without committing you must roll back).

[ghevge]

log_request method should also offer async support.

[spaceone]

I also need support for an async write_error().

[bhperry]

Async for on_finish would be really useful. I am also migrating to async sqlalchemy and need to be able close the session with async. I've seen loop.add_callback(....) mentioned a few places which seems to work well enough generally, but in unit tests I get some non-deterministic failures from tearing down the database before the session has closed.

[bhperry]

Actually async on_finish would not help my particular issue (although it would still be nice to have). I simulated it by overriding the _execute method and still had the same issue where DB sessions don't always clean up on time. I think it's because the test env and server share the same event loop, so as soon as the await session.close() yields control there is nothing stopping the tests from finishing and attempting to tear down the database.

Found sqlalchemy.ext.asyncio.close_all_sessions, which helps ensure the sessions have all closed before doing DB teardown.

[bdarnell]

Yes, the design challenge here is that finish() itself is the main point of coordination with other systems. on_finish() is really a post-finish hook, so if you make it asynchronous, the completion of the async on_finish is not going to be connected to anything. If we had a pre-finish hook that would do what you want in testing scenarios but it's undesirable in other ways since you don't want your HTTP responses to wait while you clean up your database connections. A general-purpose solution can get complicated, and in practice I tend to handle things like this with interfaces like sqlalchemy.ext.asyncio.close_all_sessions in teardown instead of something integrated into the HTTP stack.

[bhperry]

Agreed, finishing async after the request has finished is all around better for prod.

I did find it quite frustrating to get DB teardown to work reliably in tests though because of that. Even with close_all_sessions there were still random failures due to connections left open in the connection pool, despite closing all sessions and disposing the engine. Ended up force-dropping the db in my test suite in order to get it working 100% of the time.

Anyway, not a tornado problem at this point. Thanks for the insight!