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

Unintuitive error handling in wsgiref when a crash happens in write() or close() #73369

Closed
jleclanche mannequin opened this issue Jan 6, 2017 · 6 comments
Closed

Unintuitive error handling in wsgiref when a crash happens in write() or close() #73369

jleclanche mannequin opened this issue Jan 6, 2017 · 6 comments
Labels
3.7 (EOL) end of life 3.8 only security fixes stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@jleclanche
Copy link
Mannequin

jleclanche mannequin commented Jan 6, 2017

BPO 29183
Nosy @cjerdonek, @berkerpeksag, @vadmium, @jleclanche
PRs
  • bpo-29183: Fix double exceptions in wsgiref.handlers.BaseHandler #12914
  • [3.7] bpo-29183: Fix double exceptions in wsgiref.handlers.BaseHandler (GH-12914) #13424
  • Files
  • test_server.py: Reproduction test case (visit localhost:8080)
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2019-05-19.16:29:18.826>
    created_at = <Date 2017-01-06.19:41:41.174>
    labels = ['3.7', '3.8', 'type-bug', 'library']
    title = 'Unintuitive error handling in wsgiref when a crash happens in write() or close()'
    updated_at = <Date 2019-05-19.16:29:18.817>
    user = 'https://github.com/jleclanche'

    bugs.python.org fields:

    activity = <Date 2019-05-19.16:29:18.817>
    actor = 'berker.peksag'
    assignee = 'none'
    closed = True
    closed_date = <Date 2019-05-19.16:29:18.826>
    closer = 'berker.peksag'
    components = ['Library (Lib)']
    creation = <Date 2017-01-06.19:41:41.174>
    creator = 'jleclanche'
    dependencies = []
    files = ['46179']
    hgrepos = []
    issue_num = 29183
    keywords = ['patch', '3.2regression']
    message_count = 6.0
    messages = ['284844', '329223', '329277', '329890', '342861', '342863']
    nosy_count = 4.0
    nosy_names = ['chris.jerdonek', 'berker.peksag', 'martin.panter', 'jleclanche']
    pr_nums = ['12914', '13424']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue29183'
    versions = ['Python 3.7', 'Python 3.8']

    @jleclanche
    Copy link
    Mannequin Author

    jleclanche mannequin commented Jan 6, 2017

    TLDR: When an error happens in the wsgiref's write() or close(), stack traces get inundated with irrelevant yet legitimate errors which make it hard to track down the real issue.

    Couple of examples of this happening in practice:
    https://stackoverflow.com/questions/28124461/how-do-i-solve-nonetype-object-is-not-callable-with-beautifulsoup-and-bottle

    https://stackoverflow.com/questions/27518844/error-when-serving-html-with-wsgi

    ----

    How to reproduce: The file I've attached reproduces the error on python 3.4, 3.5 and 3.6. The handler returns a string instead of bytes, which fails an early assert in handlers.py: write(data).

    BaseHandler.run() triggers, gets as far as finish_response(), which triggers the above AssertionError. It falls into the except: block which attempts to handle_error(). But before doing that, it triggers self.close(), which sets result/headers/status/environ to None, bytes_sent to 0 and headers_sent to False.

    Now when handle_error() triggers, self.headers_sent is False because of that, which attempts to trigger finish_response() again. This triggers a write() which attempts sending the headers, which checks client_is_modern(), subscripting self.environ which at that point has already been set to None. New error, which is caught in run()'s except block and re-raised after closing the connection (again).

    I probably skipped some steps because the traceback is truly a mess. I think this could be improved, if only so that it doesn't get so confusing anymore.

    @vadmium
    Copy link
    Member

    vadmium commented Nov 4, 2018

    Looks like the error handling is broken by bpo-16220, which calls the “BaseHandler.close” method before the exception is caught for the error handler. Perhaps it is better to just close the iterator without messing with the other attributes in the exception case.

    I tried various cases in Python 2.6 (without the bpo-16220 change) and the error handling seems better (not masked by double exceptions, no sending a 500 response after the start of the app’s response).

    The same problem exists in Python 2, except only the later exception is reported, and the original exception is forgotten.

    @vadmium vadmium added the type-bug An unexpected behavior, bug, or error label Nov 4, 2018
    @cjerdonek
    Copy link
    Member

    This may or may not be the same as what you're suggesting, Martin. But is another option to make close() a no-op if it is called a second time? Otherwise, it seems we'd need to make sure that no code path can result in close() being called twice (even during exception handling, etc).

    @vadmium
    Copy link
    Member

    vadmium commented Nov 14, 2018

    There are actually two “close” methods in the WSGI package: ServerHandler’s implementation extends the BaseHandler implementation. Making the “close” methods do nothing if called a second time would avoid the error about “self.status” being None, but won’t help very much with other problems, such as:

    • If no response has been sent when the exception happens, the first call to “ServerHandler.close” still won’t have a HTTP status code or response size to log. It is more useful in this case to log the 500 code in the second “close” call after the error page is generated, which is what happens in 2.6.

    • If the response was started when the exception happens, the first call to “BaseHandler.close” will still reset “self.headers_sent”, which fools “handle_error” into trying to generate a 500 response despite already having started the application response.

    To be clear, what I had in mind last week was to adjust “finish_response” to look something like:

    class BaseHandler:
        ...
        def finish_response(self):
            try:
                ...
            except:
                # Limited version of “close” method on exception
                if hasattr(self.result, 'close'):
                    self.result.close()
                raise
            self.close()  # Full “close” method when no exception

    For the record: This is related to bpo-27682, specifically about handling ConnectionAbortedError and other network errors.

    @berkerpeksag
    Copy link
    Member

    New changeset 7c59362 by Berker Peksag in branch 'master':
    bpo-29183: Fix double exceptions in wsgiref.handlers.BaseHandler (GH-12914)
    7c59362

    @berkerpeksag
    Copy link
    Member

    New changeset f393e8e by Berker Peksag (Miss Islington (bot)) in branch '3.7':
    bpo-29183: Fix double exceptions in wsgiref.handlers.BaseHandler (GH-12914)
    f393e8e

    @berkerpeksag berkerpeksag added 3.7 (EOL) end of life 3.8 only security fixes stdlib Python modules in the Lib dir labels May 19, 2019
    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.7 (EOL) end of life 3.8 only security fixes stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    3 participants