tornadoweb / tornado

Tornado is a Python web framework and asynchronous networking library, originally developed at FriendFeed.
http://www.tornadoweb.org/
Apache License 2.0
21.75k stars 5.5k forks source link

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

Open ghevge opened 3 years ago

ghevge commented 3 years ago

Hi,

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

https://github.com/tornadoweb/tornado/blob/1db5b45918da8303d2c6958ee03dbbd5dc2709e9/tornado/web.py#L1709

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

_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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

log_request method should also offer async support.

spaceone commented 3 years ago

I also need support for an async write_error().

bhperry commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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!