gunicorn icon indicating copy to clipboard operation
gunicorn copied to clipboard

Old bug reproduced:'Response' object has no attribute 'status_code' in wsgi.py with websockets

Open BoWuGit opened this issue 7 years ago • 41 comments

Just like this old issue 1210 said, gunicorn logs error when client disconnects, and my environment is:

  • Debian GNU/Linux 7.8

  • nginx

  • Python3.4

  • gunicorn(19.8.1) (with one or multiple workers)

  • Flask-SocketIO, client specifies websocket transport

Everything works well including clients, except for this error log, two cloud independent production instances both persistently logs,but I can't reproduce it in my develop machine, which is a mac.

Much thanks for your help.

Error handling request /socket.io/?EIO=3&transport=websocket Traceback (most recent call last): File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/workers/async.py", line 56, in handle self.handle_request(listener_name, req, client, addr) File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/workers/async.py", line 116, in handle_request resp.close() File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/http/wsgi.py", line 409, in close self.send_headers() File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/http/wsgi.py", line 325, in send_headers tosend = self.default_headers() File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/http/wsgi.py", line 306, in default_headers elif self.should_close(): File "/opt/apps/lms/virtualenv/lib/python3.4/site-packages/gunicorn/http/wsgi.py", line 229, in should_close if self.status_code < 200 or self.status_code in (204, 304): AttributeError: 'Response' object has no attribute 'status_code'

BoWuGit avatar Aug 09 '18 11:08 BoWuGit

do you have any simple example to reproduce it? Also please try with latest master if possible.

benoitc avatar Sep 04 '18 11:09 benoitc

Previously I have tried several times in my local development environment,which is the same application code with production environment,but I can't reproduce it.

And I have checked version 19.9.0 release log,not found something related,I'll keep watching this error log,if find something new,I would post here.

BoWuGit avatar Sep 04 '18 13:09 BoWuGit

I too have this problem, specifically when I force all my connection from client to websocket protocol. My settings is the same as BoWuGit. If allow polling protocol before upgrade, this does not show up, but another error : ` [ERROR] Error handling request /socket.io/?EIO=3&transport=polling&t=MPRHUoV&sid=cd64be7c940e474d8728b114c3fb9bbe

Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/async.py", line 56, in handle self.handle_request(listener_name, req, client, addr)

File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/async.py", line 107, in handle_request respiter = self.wsgi(environ, resp.start_response)

File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1994, in call return self.wsgi_app(environ, start_response)

File "/usr/local/lib/python3.6/site-packages/flask_socketio/init.py", line 43, in call start_response)

File "/usr/local/lib/python3.6/site-packages/engineio/middleware. py", line 47, in call return self.engineio_app.handle_request(environ, start_response)

File "/usr/local/lib/python3.6/site-packages/socketio/server.py", line 360, in handle_request return self.eio.handle_request(environ, start_response)

File "/usr/local/lib/python3.6/site-packages/engineio/server.py", line 279, in handle_request socket = self._get_socket(sid)

File "/usr/local/lib/python3.6/site-packages/engineio/server.py", line 439, in _get_socket raise KeyError('Session is disconnected') ` But I suspect it might have something to do with each other, since I force the connection to be websocket, this error has not been seen again.

mat10tng avatar Oct 10 '18 08:10 mat10tng

Having this issue as well with gunicorn 19.9.0 and Flask-socketIO 3.0.2, when using eventlet 0.24.1

AttributeError: 'Response' object has no attribute 'status_code'

Mitalee avatar Oct 27 '18 09:10 Mitalee

Also experiencing this issue with the following requirements:

Flask==1.0.2
gunicorn==19.5.0
python-socketio==2.0.0
eventlet==0.24.1

Error message when closing web browser that has open socket connection:

 Error handling request /socket.io/?EIO=3&transport=websocket&sid=d43ec0ae0bb946debc51f1ca2e5b8a94
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/gunicorn/workers/async.py", line 52, in handle
    self.handle_request(listener_name, req, client, addr)
  File "/usr/lib/python2.7/dist-packages/gunicorn/workers/async.py", line 114, in handle_request
    resp.close()
  File "/usr/lib/python2.7/dist-packages/gunicorn/http/wsgi.py", line 403, in close
    self.send_headers()
  File "/usr/lib/python2.7/dist-packages/gunicorn/http/wsgi.py", line 319, in send_headers
    tosend = self.default_headers()
  File "/usr/lib/python2.7/dist-packages/gunicorn/http/wsgi.py", line 300, in default_headers
    elif self.should_close():
  File "/usr/lib/python2.7/dist-packages/gunicorn/http/wsgi.py", line 233, in should_close
    if self.status_code < 200 or self.status_code in (204, 304):
AttributeError: 'Response' object has no attribute 'status_code'

insanj avatar Nov 03 '18 20:11 insanj

It looks like this issue has been fixed in the latest version of python-engineio..

Mitalee avatar Nov 09 '18 15:11 Mitalee

Have tested with python-engineio latest version(2.3.2), still not work.

BoWuGit avatar Nov 12 '18 09:11 BoWuGit

Any news on this issue? I get the same error when using sentry-python

NotSoShaby avatar Jun 20 '19 10:06 NotSoShaby

I have the same issue

eventlet: 0.25.1 flask-socketio: 4.2.1 gunicorn: 19.9.0

image

image

eazow avatar Oct 14 '19 08:10 eazow

how to reproduce it? cna you provide a simple example?

benoitc avatar Nov 22 '19 20:11 benoitc

i'm also not sure how to reproduce it, but it happens OFTEN when i refresh a page on my gunicorn app

sagydr avatar Feb 11 '20 10:02 sagydr

Encounter the same issue, and my environment is the same as @eazow while gunicorn == 20.0.4. It seems that the issue happened after I installed sentry for bug tracking. The issues can be reproduced by

  1. refreshing the page(not opening a new page)
  2. closing the page

Interestingly, opening a new page won't produce the issue. Not sure why. Thanks!

cowbonlin avatar Mar 10 '20 04:03 cowbonlin

I have the same issue as @cowbonlin . Same gunicorn version, too.

After installing sentry, we're getting crazy amounts of this error. Though I find it hard to tell if this always happened or not - since we didn't track errors before sentry.

While it doesn't seem to influence actual functionality of our server, this is just a ton of spam.

TheSHEEEP avatar Mar 10 '20 07:03 TheSHEEEP

We're experiencing the same. Sentry installed but disabled. Any ideas?

blackmicha avatar Mar 19 '20 08:03 blackmicha

Same issue with sentry installed.

Divide-By-0 avatar Apr 16 '20 23:04 Divide-By-0

Do you hve any example that reproduce it without sentry (disabled or not) ?

benoitc avatar Apr 17 '20 14:04 benoitc

In addition, instead of a namespace I manually hit /api.

Divide-By-0 avatar Apr 17 '20 16:04 Divide-By-0

In addition, instead of a namespace I manually hit /api.

what does it mean ? Is this sentry related?

benoitc avatar Apr 17 '20 16:04 benoitc

In addition, instead of a namespace I manually hit /api.

what does it mean ? Is this sentry related?

No, this is related to socket.io namespaces. I tried removing them, and even after removing them, I get the error. I get this other error on local machine without gunicorn or nginx however, which may be related.

These are my requirements:

sentry_sdk == 0.14.3
Flask_SocketIO == 4.2.1
eventlet == 0.25.1

This is my flask-socketio code on the server side:

socketio = SocketIO(engineio_logger=True, logger=True, debug=True, cors_allowed_origins="*", path='/socket.io')
...
socketio.init_app(app, async_mode="eventlet")

And this is my React socket io code on the client side:

          this.socket = io.connect(`http://localhost:5000?info=${someInfo}`, {
            transports: ['websocket', 'polling'] // an attempt to keep polling as a fallback but start on websockets
          });

Let me know if this helps. On Ubuntu the error looks like the above one, and locally on Windows it looks like this:

  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 599, in handle_one_response
    write(b'')
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 491, in write
    raise AssertionError("write() before start_response()")
AssertionError: write() before start_response()

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 357, in __init__
    self.handle()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 390, in handle
    self.handle_one_request()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 466, in handle_one_request
    self.handle_one_response()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 609, in handle_one_response
    write(err_body)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 538, in write
    wfile.flush()
  File "C:\ProgramData\Anaconda3\lib\socket.py", line 607, in write
    return self._sock.send(b)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\greenio\base.py", line 397, in send
    return self._send_loop(self.fd.send, data, flags)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\greenio\base.py", line 384, in _send_loop
    return send_method(data, *args)
ConnectionAbortedError: [WinError 10053] An established connection was aborted by the software in your host machine

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\hubs\hub.py", line 461, in fire_timers
    timer()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\hubs\timer.py", line 59, in __call__
    cb(*args, **kw)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\semaphore.py", line 147, in _do_acquire
    waiter.switch()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\greenthread.py", line 221, in main
    result = function(*args, **kwargs)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 818, in process_request
    proto.__init__(conn_state, self)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 359, in __init__
    self.finish()
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\wsgi.py", line 732, in finish
    BaseHTTPServer.BaseHTTPRequestHandler.finish(self)
  File "C:\ProgramData\Anaconda3\lib\socketserver.py", line 784, in finish
    self.wfile.close()
  File "C:\ProgramData\Anaconda3\lib\socket.py", line 607, in write
    return self._sock.send(b)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\greenio\base.py", line 397, in send
    return self._send_loop(self.fd.send, data, flags)
  File "C:\ProgramData\Anaconda3\lib\site-packages\eventlet\greenio\base.py", line 384, in _send_loop
    return send_method(data, *args)
ConnectionAbortedError: [WinError 10053] An established connection was aborted by the software in your host machine```

Divide-By-0 avatar Apr 18 '20 00:04 Divide-By-0

Can confirm this error disappears when sentry is fully disabled. Would be great if gunicorn was robust enough to deal with this.

Divide-By-0 avatar Apr 19 '20 11:04 Divide-By-0

Bump @benoitc

Divide-By-0 avatar May 22 '20 05:05 Divide-By-0

Can confirm this error disappears when sentry is fully disabled. Would be great if gunicorn was robust enough to deal with this.

I found that disabling the Sentry's FlaskIntegration also makes the error disappear.

eelkevdbos avatar Jun 18 '20 20:06 eelkevdbos

Seeing similar behavior. Using New Relic in production causes this error with flask-socketio. In development, the werkzeug debugger middleware needs to be loaded before flask-socketio is initialized (so it's not applied to engineio's wsgi app). Problem is production is where I really don't want the errors tripping.

Can't replace the response in gunicorn config's post_request, but I tried forcing a status code onto resp.status_code. It didn't take though.

ziddey avatar Aug 17 '20 05:08 ziddey

This error is reproducible by using Sentry's FlaskIntegration together with Gunicorn and Flask-SocketIO. Is it possible to solve it soon?

Canicio avatar Sep 17 '20 06:09 Canicio

@Canicio we thought to try that to get rid of the error and even after disabling the integration, the error persists.

blackmicha avatar Sep 22 '20 15:09 blackmicha

Does anyone have sharable code/a minimal example for @benoitc to go off of?

Divide-By-0 avatar Sep 22 '20 21:09 Divide-By-0

Sure:

import sentry_sdk
from flask import Flask
from flask_socketio import SocketIO
from sentry_sdk.integrations.flask import FlaskIntegration

sentry_sdk.init(
    dsn="https://[email protected]/0",
    integrations=[FlaskIntegration()]
)

app = Flask(__name__)
socketio = SocketIO(app)

@app.route('/')
def index():
    return '''
<script src="https://cdnjs.cloudflare.com/ajax/libs/socket.io/2.2.0/socket.io.js"></script>
<script>
    var socket = io()
</script>

requirements:

gunicorn
flask
sentry-sdk[flask]
flask-socketio
eventlet

example gunicorn config:

bind = '[::]:4444'
worker_class = 'eventlet'
accesslog = '-'

On loading / it'll connect to the websocket. On websocket disconnect (e.g. navigate away, refresh), will produce exception like so:

[2020-09-23 07:24:49 +0000] [16303] [ERROR] Error handling request /socket.io/?EIO=3&transport=websocket&sid=29f4c1adfac343d6bc6db56acf8fd0ee
Traceback (most recent call last):
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/workers/base_async.py", line 55, in handle
    self.handle_request(listener_name, req, client, addr)
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/workers/base_async.py", line 115, in handle_request
    resp.close()
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 402, in close
    self.send_headers()
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 318, in send_headers
    tosend = self.default_headers()
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 299, in default_headers
    elif self.should_close():
  File "/home/ziddey/projects/sentry/venv_sentry/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 219, in should_close
    if self.status_code < 200 or self.status_code in (204, 304):
AttributeError: 'Response' object has no attribute 'status_code'
2001:470:1f07:7eb:9dd4:254c:35d7:236c - - [23/Sep/2020:07:24:49 +0000] "GET /socket.io/?EIO=3&transport=websocket&sid=29f4c1adfac343d6bc6db56acf8fd0ee HTTP/1.1" 500 0 "-" "-"

Note: I've never actually used sentry myself. This is just from the sentry getting started page. The example dsn works fine for our test.

Commenting integrations=[FlaskIntegration()] will then eliminate the error (of course effectively disabling sentry).

For what it's worth, gevent-websocket can be used instead of eventlet without errors. However, it then seems to handle all requests..

ziddey avatar Sep 23 '20 07:09 ziddey

Ok, did some playing around. Looks like sentry/newrelic wraps the response. Without sentry, we get <eventlet.wsgi._AlreadyHandled object at 0x7fd0f5b1c0d0> as expected and gunicorn's EventletWorker.is_already_handled() will stop iteration.

However, when using sentry, this becomes something like <sentry_sdk.integrations.wsgi._ScopedResponse object at 0x7f30155a5100> instead, failing the check

Instead, we could peek at respiter to see if it's empty. Will look further tomorrow.

ziddey avatar Sep 23 '20 09:09 ziddey

Alright, here's the workaround I've come up with:

eventlet_fix.py: see edit below

And in my gunicorn config.py: worker_class = 'eventlet_fix.EventletWorker.

The issue is that sentry/newrelic wraps the responses, so we can't simply check it against eventlet's ALREADY_HANDLED. Since the nature of an already handled request is that gunicorn's start_response doesn't get called, we can instead check for the presence of a response status.

So I've hijacked the wsgi call to then check for a response status, and hack response values as necessary. This allows the request to still be logged by gunicorn. If instead, it's desired to keep the original behavior, StopIteration can be raised instead.

Hacking the status to 101 is appropriate for our use case here (flask-socketio websocket), but otherwise, leaving it as None works as well since headers_sent and should_close are forced to True.

Again, this makes the assumption that if status isn't set, start_response wasn't called, and therefore the request must have been "already handled" externally.

edit: No good. Will need to reevaluate. If the request takes time to perform, start_response won't be called before resp.status is checked.

edit2: Here's a fixed version with a hacked response iterator:

from functools import wraps

from gunicorn.workers.geventlet import EventletWorker as _EventletWorker


class HackedResponse:
    def __init__(self, respiter, resp):
        self.respiter = iter(respiter)
        self.resp = resp
        if hasattr(respiter, "close"):
            self.close = respiter.close

    def __iter__(self):
        return self

    def __next__(self):
        try:
            return next(self.respiter)
        except StopIteration:
            if not self.resp.status:
                self.resp.status = "101"  # logger derives status code from status instead of using status_code
                self.resp.status_code = 101  # not actually needed since headers_sent/force_close result in status_code not being checked anymore
                self.resp.headers_sent = True
                self.resp.force_close()
            raise


def wsgi_decorator(wsgi):
    @wraps(wsgi)
    def wrapper(environ, start_response):
        respiter = wsgi(environ, start_response)
        resp = start_response.__self__
        return HackedResponse(respiter, resp)

    return wrapper


class EventletWorker(_EventletWorker):
    def load_wsgi(self):
        super().load_wsgi()
        self.wsgi = wsgi_decorator(self.wsgi)

Obviously this is just a monkey patch. The actual fix could potentially go in handle_request in base_async.py. The key may be to (indirectly) check if start_response was called after iterating through respiter, either by checking resp.status (just start_response called) or resp.headers_sent (confirmation that we've actually responded to the request).

ziddey avatar Sep 24 '20 01:09 ziddey

@benoitc @ziddey has found a way to solve the problem.

Canicio avatar Jan 12 '21 09:01 Canicio