I get 500 bad response error when i use it along with gunicorn

[aswinckr]

website_1   | 172.18.0.1 - - [06/Apr/2017:02:36:20 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1491446149614-17&sid=1bd2a25fa898425ea117df5ea5492f8b HTTP/1.1" 400 11 "http://local.docker:9000/chat/chatroom" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36"
website_1   | 172.18.0.1 - - [06/Apr/2017:02:36:20 +0000] "POST /socket.io/?EIO=3&transport=polling&t=1491446174928-18&sid=1bd2a25fa898425ea117df5ea5492f8b HTTP/1.1" 400 11 "http://local.docker:9000/chat/chatroom" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36"
website_1   | 172.18.0.1 - - [06/Apr/2017:02:36:21 +0000] "POST /socket.io/?EIO=3&transport=polling&t=1491446181593-19&sid=1bd2a25fa898425ea117df5ea5492f8b HTTP/1.1" 400 11 "http://local.docker:9000/chat/chatroom" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36"
website_1   | 172.18.0.1 - - [06/Apr/2017:02:36:23 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1491446183092-20 HTTP/1.1" 200 119 "http://local.docker:9000/chat/chatroom" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36"
website_1   | 172.18.0.1 - - [06/Apr/2017:02:36:23 +0000] "POST /socket.io/?EIO=3&transport=polling&t=1491446183102-21&sid=6020b18d861b419d82f1e5d0881a7496 HTTP/1.1" 200 2 "http://local.docker:9000/chat/chatroom" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36"

My gunicorn command ( i run this in my dockerfile )- CMD gunicorn -b 0.0.0.0:9000 --worker-class eventlet --access-logfile - "my.app:create_app()"

My requirements.txt eventlet==0.17.4 flask-socketio greenlet==0.4.2

I'm not able to figure out why its not working when i integrate this into my app. When i run this separately it works. Please help!

[miguelgrinberg]

I recommend that you work on this without Docker. Add Docker after you can get the server to behave when running as a normal process.

So with Docker out of the picture, try running the server standalone, without gunicorn. Does it work that way? If not, then run in debug mode to see stack traces for all errors.

[aswinckr]

Hi Miguel,

Without docker and gunicorn the application runs fine. I was using gunicorn 19.0 , now changed to 18.0 still nothing :/ can you please take a look at my source code? I'm new to programming and I tried every possible way i know to tackle this and I really need socket connections to work for my use case.

[miguelgrinberg]

@aswinckr I don't think you told me where your code is. Or did you?

In any case, the next step is to add gunicorn, but also add logging to the app (add engineio_logger=True to your SocketIO class). Watch the console when those 400 errors occur. You should have stack traces or error messages there.

[aswinckr]

@miguelgrinberg pasting the engineio_logger output

website_1   | c5b6d27c769d475987d8f489f14bc8ec: Sending packet OPEN data {'pingInterval': 25000, 'pingTimeout': 60000, 'upgrades': [], 'sid': 'c5b6d27c769d475987d8f489f14bc8ec'}
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Sending packet MESSAGE data 0
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Received request to upgrade to websocket
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Upgrade to websocket successful
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Received packet MESSAGE data 0/chat/chatroom
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Sending packet MESSAGE data 0/chat/chatroom
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Received packet PING data None
website_1   | c5b6d27c769d475987d8f489f14bc8ec: Sending packet PONG data None
website_1   | 2017-04-06 15:45:49 [1] [CRITICAL] WORKER TIMEOUT (pid:10)
website_1   | 2017-04-06 15:45:49 [1] [CRITICAL] WORKER TIMEOUT (pid:10)
website_1   | 2017-04-06 15:45:49 [12] [INFO] Booting worker with pid: 12
website_1   | Server initialized for eventlet.
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Sending packet OPEN data {'pingInterval': 25000, 'pingTimeout': 60000, 'upgrades': [], 'sid': '86772dd6360143ec897b6a8c8cd8c2b2'}
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Sending packet MESSAGE data 0
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Received request to upgrade to websocket
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Upgrade to websocket successful
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Received packet MESSAGE data 0/chat/chatroom
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Sending packet MESSAGE data 0/chat/chatroom
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Received packet PING data None
website_1   | 86772dd6360143ec897b6a8c8cd8c2b2: Sending packet PONG data None
website_1   | 2017-04-06 15:46:21 [1] [CRITICAL] WORKER TIMEOUT (pid:12)
website_1   | 2017-04-06 15:46:21 [1] [CRITICAL] WORKER TIMEOUT (pid:12)
website_1   | 2017-04-06 15:46:21 [14] [INFO] Booting worker with pid: 14
website_1   | Server initialized for eventlet.
website_1   | e1f9fab7dbcf473998a8facac84e6238: Sending packet OPEN data {'pingInterval': 25000, 'pingTimeout': 60000, 'upgrades': [], 'sid': 'e1f9fab7dbcf473998a8facac84e6238'}
website_1   | e1f9fab7dbcf473998a8facac84e6238: Sending packet MESSAGE data 0
website_1   | e1f9fab7dbcf473998a8facac84e6238: Received request to upgrade to websocket
website_1   | e1f9fab7dbcf473998a8facac84e6238: Upgrade to websocket successful
website_1   | e1f9fab7dbcf473998a8facac84e6238: Received packet MESSAGE data 0/chat/chatroom
website_1   | e1f9fab7dbcf473998a8facac84e6238: Sending packet MESSAGE data 0/chat/chatroom

also the link to my source code here.

[miguelgrinberg]

Do you have long running SocketIO event handlers? Looks like gunicorn is killing workers because it thinks they are taking too long. Maybe you need to set a longer timeout, see http://docs.gunicorn.org/en/latest/settings.html#timeout.

[aswinckr]

No @miguelgrinberg , I'm running the same sample application that's used here https://github.com/miguelgrinberg/Flask-SocketIO-Chat . there's basically no response after that

From the logs above, can we be sure that the eventlet worker is running?

also, the data field shouldn't be 'none', right? according to the code its this - emit('status', {'msg': session.get('name') + ' has entered the room.'}, room=room)

[aswinckr]

So when i added {transports: ['websocket']} in socket = io.connect(document.domain + ':' + location.port + '/chat/chatroom', {transports: ['websocket']});, the upgrade to websocket is now atleast successful.

But the received packet has no data in it .. log - Received packet MESSAGE data 0/chat/chatroom

What would this mean @miguelgrinberg ?

Latest Logs -

website_1   | a26070b1f5c34e849ee5173758604d6e: Sending packet OPEN data {'pingInterval': 25000, 'pingTimeout': 60000, 'upgrades': [], 'sid': 'a26070b1f5c34e849ee5173758604d6e'}
website_1   | a26070b1f5c34e849ee5173758604d6e: Sending packet MESSAGE data 0
website_1   | a26070b1f5c34e849ee5173758604d6e: Received request to upgrade to websocket
website_1   | a26070b1f5c34e849ee5173758604d6e: Upgrade to websocket successful
website_1   | a26070b1f5c34e849ee5173758604d6e: Received packet MESSAGE data 0/chat/chatroom
website_1   | a26070b1f5c34e849ee5173758604d6e: Sending packet MESSAGE data 0/chat/chatroom

[miguelgrinberg]

The packets that carry events start with 2. The 0 packages are connection packages, so those are expected to not have any data.

So the question is why there are no event packets in your logs. Have you looked at the browser console? Any errors there?

[aswinckr]

Oh, so the connection itself fails in that case.

My browser console is clean. Shows no errors. This is my events.py file - just edited the namespace

from flask import session
from flask_socketio import emit, join_room, leave_room

from my_app.extensions import socketio

@socketio.on('joined', namespace='/chat/chatroom')
def joined(message):
    """Sent by clients when they enter a room.
    A status message is broadcast to all people in the room."""
    room = session.get('room')
    join_room(room)
    emit('status', {'msg': session.get('name') + ' has entered the room.'}, room=room)

@socketio.on('text', namespace='/chat/chatroom')
def text(message):
    """Sent by a client when the user entered a new message.
    The message is sent to all people in the room."""
    room = session.get('room')
    emit('message', {'msg': session.get('name') + ':' + message['msg']}, room=room)

@socketio.on('left', namespace='/chat/chatroom')
def left(message):
    """Sent by clients when they leave a room.
    A status message is broadcast to all people in the room."""
    room = session.get('room')
    leave_room(room)
    emit('status', {'msg': session.get('name') + ' has left the room.'}, room=room)

[aswinckr]

The GET request from ws://local.docker:9000/socket.io/?EIO=3&transport=websocket shows a status code of 101 and never succeedes. I give it a timeout of 30 as well - CMD gunicorn -b 0.0.0.0:9000 --worker-class eventlet -w 1 -t 30 --access-logfile - "my_app.app:create_app()"

[miguelgrinberg]

The 101 code is the correct code for when a websocket connection is established. That's normal.

[aswinckr]

weird then. basically no emits are being executed.

this is my views.py

from flask import (
    session,
    redirect,
    url_for,
    request,
    render_template)

from . import chat

from my_app.blueprints.chat.forms import LoginForm

@chat.route('/chat', methods=['GET', 'POST'])
def index():
    """"Login form to enter a room."""
    form = LoginForm()
    if form.validate_on_submit():
        session['name'] = form.name.data
        session['room'] = form.room.data
        return redirect(url_for('chat.chatroom'))
    elif request.method == 'GET':
        form.name.data = session.get('name', '')
        form.room.data = session.get('room', '')
    return render_template('index.html', form=form)

@chat.route('/chat/chatroom')
def chatroom():
    """Chat room. The user's name and room must be stored in
    the session."""
    name = session.get('name', '')
    room = session.get('room', '')
    if name == '' or room == '':
        return redirect(url_for('chat.index'))
    return render_template('chat.html', name=name, room=room)

do you see any errors in either of these files? should i be looking elsewhere?

Also if its worth mentioning, I'm using celery. I followed one of the issues and made this change socketio = SocketIO(async_mode='eventlet', engineio_logger=True, message_queue='redis://')

[aswinckr]

Also, is adding a worker with this command : gunicorn -b 0.0.0.0:9000 --worker-class eventlet -w 1 --timeout 30 --access-logfile - "my_app.app:create_app()" enough to replace socketio.run(app) ?

[miguelgrinberg]

Yes, that should work, though I never needed to set the timeout. That's the part that we still don't understand, something on your system is blocking the worker, which ends up timing out. You may want to try creating a brand new virtualenv and see if that helps. FYI, the command that I use on my https://flack.miguelgrinberg.com site is gunicorn -k eventlet -b 127.0.0.1:8200 -w 1 --log-file - flack.wsgi:app

[aswinckr]

What about celery? socketio = SocketIO(async_mode='eventlet', engineio_logger=True, message_queue='redis://') - is this code right? celery can't be the blocking one right?

[miguelgrinberg]

Have you configured Celery to use eventlet as well? If you didn't, then you need to start SocketIO in threading mode, like I do in Flack. See https://github.com/miguelgrinberg/flack/blob/master/flack/__init__.py#L46-L51.

[aswinckr]

Okay , wow. Progress! it emits just the 'person has entered the room' emit but the console still goes with errors. Also, this message keeps repeating ( i get [CRITICAL] WORKER TIMEOUT (pid:19) )

[miguelgrinberg]

The gunicorn command in your docker-compose file is different than the one in your Dockerfile. Which are you using? The Dockerfile one is correct, the other is not.

[aswinckr]

Wow! @miguelgrinberg you are a real genius. It worked! :1st_place_medal: that was two days of messing around the code and i wasn't smart enough to notice that. docker noobs 😅

[miguelgrinberg]

This issue will be automatically closed due to being inactive for more than six months. Seeing that I haven't responded to your last comment, it is quite possible that I have dropped the ball on this issue and I apologize about that. If that is the case, do not take the closing of the issue personally as it is an automated process doing it, just reopen it and I'll get back to you.