Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Nicer error handling after eof, warning for second response being created #2323

Conversation

ChihweiLHBird
Copy link
Member

@ChihweiLHBird ChihweiLHBird commented Nov 26, 2021

Trying to solve issue: #2219

Some doubts I still have:

  1. Whether it's okay to put a response reference in request instance. I recently learned from the memory leak issue; we should not create more reference if not necessary. I am considering replace it with a bool flag.
  2. Should we only allow one response instance for each request? If so, we can consider keep and cache the response reference and return it if request.respond method is called more than 1 time.
  3. I believe that self.response_func is None and self.stage == Stage.IDLE implies the request has been responded and the response stream is ended. Am I correct on this?

Please let me know your suggestions, thanks! @sanic-org/core-devs

@Tronic
Copy link
Member

Tronic commented Nov 26, 2021

1-2. Trying to make another response should probably just fail, especially if the headers of the previous one have already been sent. Perhaps this can be handled if the original one was never actually sent anywhere.

3 - I believe you are right. IDLE means that no request is being served but that the pipeline is still alive. I am not exactly sure why that also needs to test for response_func separately but certainly there was a reason for that when I wrote it but the stage meanings have also changed since. I think that during Stage.RESPONSE you can check response_func to find which state the response is in (not started, something sent, already EOF).

@ChihweiLHBird
Copy link
Member Author

ChihweiLHBird commented Nov 27, 2021

3 - I believe you are right. IDLE means that no request is being served but that the pipeline is still alive. I am not exactly sure why that also needs to test for response_func separately but certainly there was a reason for that when I wrote it but the stage meanings have also changed since. I think that during Stage.RESPONSE you can check response_func to find which state the response is in (not started, something sent, already EOF).

Thank you! Currently, the exception raised for sending some data after end_stream being set to True is send method is NonType, and the send method is a property that returns response_func. I am not near my laptop right now and above is from my memory. That's why I thought testing whether response_func is None or not.

@ChihweiLHBird
Copy link
Member Author

ChihweiLHBird commented Nov 27, 2021

1-2. Trying to make another response should probably just fail, especially if the headers of the previous one have already been sent. Perhaps this can be handled if the original one was never actually sent anywhere.

Like raising an exception when the user is trying to create second response and the first response has sent some data?

@ChihweiLHBird
Copy link
Member Author

Found a tricky problem that in some circumstances, if an exception raised during the making response, the exception handler would try to generate another response which can lead to the exception again. Have no idea how to make progress so far. Probably need to look into the exception handling mechanism, which is complicated.

@ChihweiLHBird ChihweiLHBird marked this pull request as ready for review November 28, 2021 06:22
@ChihweiLHBird ChihweiLHBird requested a review from a team as a code owner November 28, 2021 06:22
@ChihweiLHBird
Copy link
Member Author

ChihweiLHBird commented Nov 28, 2021

I would like to propose the change included in this PR for issues: #2219 and #2197

Basically, it prevents second response object being created from request.respond. ResponseException is not always handled by usual exception handler that returns a default 500 page because a part of the response stream might have been sent. To be honest, these changes is not perfect in my mind because it seems added code snippets that makes the modified modules unclear as before, but it is the best I can do so far. Can you guys let me know if these changes are ok? Maybe I got some of them or all of them in the wrong track? Thank you so much for guiding me, I really appreciate it.

@ahopkins
Copy link
Member

I would like to propose the change included in this PR for issues: #2219 and #2197

Agreed. Those can be tackled in this PR.

1-2. Trying to make another response should probably just fail, especially if the headers of the previous one have already been sent. Perhaps this can be handled if the original one was never actually sent anywhere.

I am not sure what you mean by fail. I agree that we should not allow multiple response instances to be generated. As the original use case from the issue shows, weird behaviors arise. However, I am not sure that raising an exception is appropriate either. It sounds like it might an area ripe for race conditions as the sending of the response might be in different states. The exception might be thrown inconsistently during the response.

Therefore, I am more in favor of the idea that it either fails silently to the logs (probably also difficult to debug), or just return the same response (as mentioned, what would the memory impact look like?) Clearly any attempt to change the headers after the first byte was sent should fail. Again, should it sack the whole response or just do it to the logs? I am more inclined to allow the response to complete.

Another though popped into my head. I am not sure this is a road we want to go down, but at startup we already examine route handlers to see what kind of responses they might send. Perhaps we piggyback off that to inspect if there might be the case for multiple responses. If we throw an exception, I would rather do it at startup.

@Tronic
Copy link
Member

Tronic commented Nov 30, 2021

Where could we end up in this situation? If a handler attempts to start another response or returns something after using request.respond, there is a clear logic error in the program. Other common case supposedly is when an exception is risen and Sanic then tries to send its error response. The latter is a case where Sanic exception handling should probably detect this and not even try to send an error response, but only log it.

Now, in either of these situations, what to do with the response in progress?

I believe that in any case, if the handler has not signaled EOF yet, it is wrong for Sanic to complete the response (even if it can, depending on content-length header). It is better to disconnect the TCP connection, which will cause an error in browser that is not pretty but it is better than giving "successful" 200 responses with incomplete data.

On the other hand, if the handler has signaled EOF, from client perspective there is nothing wrong, and Sanic can just silently log the error and even keep the keep-alive alive. A bit of risky business there in case we have any logic errors in Sanic, so it might still be safer to disable keep-alive at this point. No error on client but it will have to make another connection.

@ahopkins
Copy link
Member

ahopkins commented Nov 30, 2021

Something like this is what I had in mind:

diff --git a/sanic/mixins/routes.py b/sanic/mixins/routes.py
index a543a05..667ad64 100644
--- a/sanic/mixins/routes.py
+++ b/sanic/mixins/routes.py
@@ -20,6 +20,7 @@ from sanic.exceptions import (
     FileNotFound,
     HeaderNotFound,
     InvalidUsage,
+    SanicException,
 )
 from sanic.handlers import ContentRangeHandler
 from sanic.log import error_logger
@@ -934,6 +935,7 @@ class RouteMixin:

     def _get_response_types(self, node):
         types = set()
+        responds = 0

         class HttpResponseVisitor(NodeVisitor):
             def visit_Return(self, node: Return) -> Any:
@@ -954,6 +956,14 @@ class RouteMixin:
                 except AttributeError:
                     ...

-        HttpResponseVisitor().visit(node)
+            def visit_Call(self, node) -> Any:
+                nonlocal responds
+
+                responds += node.func.attr == "respond"

+        HttpResponseVisitor().visit(node)
+        if responds > 1:
+            raise SanicException(
+                "Multiple streaming responses identified in handler"
+            )
         return types

Obviously we would need to work on this to look at scoping, but this is the idea.

@Tronic
Copy link
Member

Tronic commented Nov 30, 2021

@ahopkins Is that Visitor pattern? I am too tired to understand that code now.

@ChihweiLHBird ChihweiLHBird marked this pull request as draft November 30, 2021 23:55
@ahopkins
Copy link
Member

ahopkins commented Dec 1, 2021

@ahopkins Is that Visitor pattern? I am too tired to understand that code now.

Yeah. It's a super simple method to look for callables named "respond". Just meant as an illustration, not a complete solution.

@ChihweiLHBird
Copy link
Member Author

ChihweiLHBird commented Dec 1, 2021

@ahopkins Do you think we should still handler the second response situation beside the code inspection for the user specified request handler? One reason I can think of is that second responding not only happens in the request handler, but also in Sanic's internal code, for example exception handler. Consider the code below:

@app.get("/")
async def handler(request: Request):
    resp1: HTTPResponse = await request.respond()
    await resp1.send(b"Now I'm free, free-falling")
    raise SanicException("Some text here.")

resp1 was created as a response, but since a Sanic exception is raised, handle_exception will be invoked to handle it and try to create another response for the Sanic's 500 error page. Some weird behaviours would happen as @Tronic mentioned above.

Where could we end up in this situation? If a handler attempts to start another response or returns something after using request.respond, there is a clear logic error in the program. Other common case supposedly is when an exception is risen and Sanic then tries to send its error response. The latter is a case where Sanic exception handling should probably detect this and not even try to send an error response, but only log it.

Now, in either of these situations, what to do with the response in progress?

I believe that in any case, if the handler has not signaled EOF yet, it is wrong for Sanic to complete the response (even if it can, depending on content-length header). It is better to disconnect the TCP connection, which will cause an error in browser that is not pretty but it is better than giving "successful" 200 responses with incomplete data.

On the other hand, if the handler has signaled EOF, from client perspective there is nothing wrong, and Sanic can just silently log the error and even keep the keep-alive alive. A bit of risky business there in case we have any logic errors in Sanic, so it might still be safer to disable keep-alive at this point. No error on client but it will have to make another connection.

@ChihweiLHBird
Copy link
Member Author

ChihweiLHBird commented Dec 1, 2021

Currently, I plan to make the following changes as we discussed:

  1. Try to implement code inspection for request handler.
  2. When request.respond is being called second time, return the same response instance.
    a. If different headers, status, and content_type are provided, then response instance's corresponding attributes would be overridden if it was never sent (partially or fully).
    b. If response has already been sent while different parameters mentioned above are provided, log an error and return the same response instance
  3. Make Sanic.handle_exception method detect whether the response has been sent (partially or fully), and only log the error without making second 500 response if previous response was sent. This is somehow already implemented in this PR, but need some improvements, I think.

Does it sound good for you guys? @Tronic @ahopkins Thanks for feedbacks!

@Tronic
Copy link
Member

Tronic commented Dec 1, 2021

  1. When request.respond is being called second time, return the same response instance.
    a. If different headers, status, and content_type are provided, then response instance's corresponding attributes would be overridden if it was never sent (partially or fully).
    b. If response has already been sent while different parameters mentioned above are provided, log an error and return the same response instance

I believe there should be no effort to do any of this. 2a may lead to problematic responses that accidentally combine unrelated headers, status or content types when the latter response assumes to have the default values. 2b should raise RuntimeError(...) to terminate the code that attempts another response (which will certainly lead to invalid results).

In 2b, as a practical example:

  1. The handler makes a 200-response and starts sending data (using chunked encoding)
  2. The client receives and saves a file as it is being sent
  3. The handler has some logic error such that it for whatever reason starts sending another unrelated response
  4. The client appends the other message to the file it saved thinking that everything was OK, while it actually got corrupt data!
  5. The handler sees no error and writes to database that the request was successfully completed

A very similar but maybe more common flow follows if step 3 is an exception (e.g. cannot read more data from database) and the exception is handled by Sanic, and then in step 4 the client silently appends the error message to the file it downloads, but there is no step 5 because the exception caused the handler to terminate.

The only case of another response that could be accepted is when no response packets have been sent to the client yet, and in that case this might be best implemented in http.py:

    def respond(self, response: BaseHTTPResponse) -> BaseHTTPResponse:
        """
        Initiate new streaming response.

        Nothing is sent until the first send() call on the returned object, and
        calling this function multiple times will just alter the response to be
        given.
        """
        if self.stage is not Stage.HANDLER:
            self.stage = Stage.FAILED
            raise RuntimeError("Response already started")

        # Disconnect any earlier but unused response object  (this part is new code)
        if self.response is not None:
            self.response.stream = None

        # Connect and return the response
        self.response, response.stream = response, self
        return response

The ASGI mode does not use http.py and that backend might be sending the headers earlier anyway (I don't recall, @ahopkins might), but in any case would then need separate handling of this to safely support replacing unused response objects with new ones.

        # This logic of determining which response to use is subject to change
        if response is None:
            response = (self.stream and self.stream.response) or HTTPResponse(

The above part in request.py is written by me and seems to be a part of the problem. I now believe it is wrong to use an existing response object (this would silently ignore any status, headers and content type parameters).

  1. Make Sanic.handle_exception method detect whether the response has been sent (partially or fully), and only log the error without making second 500 response if previous response was sent. This is somehow already implemented in this PR, but need some improvements, I think.

This is a good thing, and is what I proposed in the previous message.

@Tronic
Copy link
Member

Tronic commented Dec 1, 2021

I would very much like to see this PR included in 21.12 LTS. Looks like it fixes some rather nasty and dangerous bugs.

@ahopkins
Copy link
Member

ahopkins commented Dec 1, 2021

I am for getting this one in. We have time, but it is December now, so that means we need to finish this in the next week or so.

I agree that the checks on the subsequent respond calls are unnecessary and too complicated. I am okay with raising an error there, but does bring into question the existing response.

resp1 = await request.respond(...)
await resp.send(...)

resp2 = await request.respond(...)

Raising an exception here would be weird. Headers have been sent. The client is already expecting a complete response. This is why I was suggesting to return the same instance and have some sort of logging only failure.

I suppose it is really the same as this:

resp = await request.respond()
await resp.send(...)

raise Exception(...)

So, ultimately I agree that is probably the correct approach. Plus it should be simpler to implement.

@ChihweiLHBird As for Item 1 (code inspection), if we can sneak that in great. But do not focus on that. It is much more important to get the rest of this right and in 21.12. If the inspection needs to happen in 22.3, then that is fine with me.

@ahopkins
Copy link
Member

ahopkins commented Dec 1, 2021

Correction, now that I am looking at this and playing again I remember that this fails anyway:

resp1 = await request.respond(...)
await resp.send(...)

resp2 = await request.respond(...)

The use case that is the problem is instantiating the response twice before anything is sent which seems to work okay client side but fails server side.

In that case, it really should be fine to throw the exception the second time respond is called.

@ChihweiLHBird ChihweiLHBird marked this pull request as ready for review December 2, 2021 06:17
@ChihweiLHBird ChihweiLHBird marked this pull request as draft December 2, 2021 08:07
@ChihweiLHBird ChihweiLHBird marked this pull request as ready for review December 2, 2021 08:07
@ChihweiLHBird
Copy link
Member Author

Furthermore, if there is a partially sent response, then it does not make sense that the handler would be able to take over. It couldn't send a valid HTTP response at that point.

Suppose a custom handler was used to do something server side (like log errors somewhere), it might be expected that they still get executed, and Sanic could then just never send the response that they return. But then, if implementing that is not absolutely trivial, I wouldn't bother (given how unlikely such situation is - need an exception being raised during a streaming response, and then a custom handler that attempts to do something about it server side).

Exactly, that's what I concerned about; some exception handlers not necessarily have to return a response but might have some business logic for the exception, like sending a report to an email address or log it somewhere else. And I am wondering whether it is worth to still execute the handler without sending its response.

@ChihweiLHBird ChihweiLHBird marked this pull request as draft December 2, 2021 08:14
@ChihweiLHBird ChihweiLHBird marked this pull request as ready for review December 2, 2021 08:14
@ahopkins
Copy link
Member

ahopkins commented Dec 2, 2021

Exactly, that's what I concerned about; some exception handlers not necessarily have to return a response but might have some business logic for the exception, like sending a report to an email address or log it somewhere else. And I am wondering whether it is worth to still execute the handler without sending its response.

I am not sure that this have ever been an express supported use case for exception handlers. This is precisely the sort of thing that @app.signal("http.lifecycle.exception") is meant to cover.

@ahopkins
Copy link
Member

ahopkins commented Dec 2, 2021

I spent a little time hacking on the code inspection. Again, this is not necessarily meant to be included here, but it seems as good a place as any to keep it for now.

Source code for respond inspector
class Visitor(ast.NodeVisitor):
    def __init__(self, tree, assignments) -> None:
        super().__init__()
        self.respond_refs = 0
        self.tree = tree
        self.assignments = assignments

    @classmethod
    def load(cls, handler):
        src = dedent(getsource(handler))
        tree = ast.parse(src)
        node = tree.body[0]
        idx = 1 if node.args.args[0].arg == "self" else 0
        assignments = [(node.args.args[idx].arg, "respond")]
        return cls(tree, assignments)

    def count_refs(self):
        self.visit(self.tree)
        return self.respond_refs

    def visit_Assign(self, node: ast.Assign) -> Any:
        for name, attr in self.assignments:
            if (
                isinstance(node.value, ast.Attribute)
                and node.value.value.id == name
                and node.value.attr == attr
            ) or (
                isinstance(node.value, ast.Name)
                and not attr
                and node.value.id == name
            ):
                for target in node.targets:
                    self.assignments.append((target.id, None))

    def visit_Call(self, node: ast.Call) -> Any:
        for name, attr in self.assignments:
            if (
                attr
                and isinstance(node.func, ast.Attribute)
                and node.func.value.id == name
                and node.func.attr == attr
            ):
                self.respond_refs += 1
            elif (
                not attr
                and isinstance(node.func, ast.Name)
                and node.func.id == name
            ):
                self.respond_refs += 1

Current limitations:

  • Only works on CBV if it is a staticmethod or the instance ref is self
  • Does not take scoping into account, therefore two respond calls that are in different paths could still trigger a count

What it does handle:

@app.get("/")
async def handler(request):
    await request.respond()
    foo = request.respond
    bar = foo
    await bar()
    await foo()

class HandlerView(HTTPMethodView):
    async def get(self, request: Request):
        await request.respond()
        await request.respond()

    @staticmethod
    async def post(req: Request):
        await req.respond()
        await req.respond()

One potential option might just be to use some iteration of this and instead of throwing an exception, just raising a warning:

Route handler "handler" may contain more than one response object.

error_logger.exception(
"Exception occurred in one of response middleware handlers"
)
if not re_use_res:
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like this better. Let's just use a better variable name: should_reuse_response

@Tronic
Copy link
Member

Tronic commented Dec 2, 2021

@ChihweiLHBird Please check for Stage.HANDLER in all code that needs to check whether a response can be sent, to stay consistent with http.py. This is the only stage where you can, no need to check for IDLE or RESPONSE anywhere.

Still, I suppose that ASGI might need separate handling (does it use Stages at all?).

@Tronic
Copy link
Member

Tronic commented Dec 2, 2021

One thing I mentioned earlier, that is not implemented, is that responses should never be reused or combined. Could you fix that as well?

And possibly we could delay the running of response middlewares to the first send? This would entirely avoid the problem with them being executed twice, or being executed for responses that never get sent.

@Tronic
Copy link
Member

Tronic commented Dec 2, 2021

asgi.py lines 166-190 show no Stages and no handling of multiple responses. Namely, calling respond() again does not check for a response already started and does not disconnect any previous response, just connects with the new one blindly. The send() function then uses the most recent response and clears it. So, then one can initiate another response and corrupt the stream (which hopefully then raises an exception in the ASGI server).

This needs to be fixed. I suppose that adding a stage variable on ASGI would be a rather simple way to do it.

@ahopkins
Copy link
Member

ahopkins commented Dec 2, 2021

And possibly we could delay the running of response middlewares to the first send?

I am assuming you mean right before it? As in the first .send() will run the middleware before hitting the transport? That would be a breaking change. Not sure if it matters.

@Tronic
Copy link
Member

Tronic commented Dec 2, 2021

I am assuming you mean right before it? As in the first .send() will run the middleware before hitting the transport? That would be a breaking change. Not sure if it matters.

Yes, but I am not very convinced that this is a good idea. I gather that it is very rare for multiple responses to be created, and that an extra execution of the middleware then (for the response never sent) is not a big deal. Also, the way that it is done now potentially allows middlewares to pass information back to handler (not that I could immediately think of any use for that either). But maybe most importantly, it might be a bit confusing to developers if these middlewares are triggered on send(), rather than on respond()

@ahopkins
Copy link
Member

ahopkins commented Dec 2, 2021

Agreed.

@ChihweiLHBird
Copy link
Member Author

This needs to be fixed. I suppose that adding a stage variable on ASGI would be a rather simple way to do it.

Do you expect that to be done in this PR? I think this PR became complicated and we might want a separate PR for it, lol.

@ChihweiLHBird
Copy link
Member Author

I spent a little time hacking on the code inspection. Again, this is not necessarily meant to be included here, but it seems as good a place as any to keep it for now.

Source code for respond inspector
Current limitations:

  • Only works on CBV if it is a staticmethod or the instance ref is self
  • Does not take scoping into account, therefore two respond calls that are in different paths could still trigger a count

What it does handle:

@app.get("/")
async def handler(request):
    await request.respond()
    foo = request.respond
    bar = foo
    await bar()
    await foo()

class HandlerView(HTTPMethodView):
    async def get(self, request: Request):
        await request.respond()
        await request.respond()

    @staticmethod
    async def post(req: Request):
        await req.respond()
        await req.respond()

One potential option might just be to use some iteration of this and instead of throwing an exception, just raising a warning:

Route handler "handler" may contain more than one response object.

Yeah, let's open another PR later for it later.

@ChihweiLHBird
Copy link
Member Author

Too many stuffs going on, let's continue here to summarize them: #2327

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants