Flask-Socketio takes extremely long to connect on Heroku

0
votes

All code works perfectly fine on my local machine, just not on Heroku. Have read through many issues on github / other errors on Flask-socketio and nothing seems to work.

I left my browser running for about 20mins when using the eventlet setup and I saw the .on('connect') run correctly but none of the other parts of the code.

Here's my current procfile:

web: gunicorn -k geventwebsocket.gunicorn.workers.GeventWebSocketWorker -w 1 --chdir nickdima wsgi:app
heroku features:enable http-session-affinity

I've also tried this one with gevent:

web: gunicorn -k geventwebsocket.gunicorn.workers.GeventWebSocketWorker -w 1 --chdir nickdima wsgi:app

I've also tried this profile with eventlet:

web: gunicorn -k eventlet wsgi:app

and this profile with eventlet:

web: gunicorn --worker-class eventlet -w 1 --chdir nickdima wsgi:app

Here's my current requirements.txt file:

click==6.7
dnspython==1.15.0
eventlet==0.24.1
Flask==1.0.2
Flask-SocketIO==3.0.1
greenlet==0.4.14
gunicorn==19.9.0
itsdangerous==0.24
Jinja2==2.10
MarkupSafe==1.0
monotonic==1.5
python-engineio==2.2.0
python-socketio==2.0.0
six==1.11.0
Werkzeug==0.14.1

I've also tried with gevent:

click==6.7
dnspython==1.15.0
gevent==1.2.2
gevent-socketio==0.3.6
gevent-websocket==0.10.1
Flask==1.0.2
Flask-SocketIO==3.0.1
greenlet==0.4.14
gunicorn==19.9.0
itsdangerous==0.24
Jinja2==2.10
MarkupSafe==1.0
monotonic==1.5
python-engineio==2.2.0
python-socketio==2.0.0
six==1.11.0
Werkzeug==0.14.1

I've also tried eventlet / gevent with gunicorn 18.0.0 instead of 19.x.

Here is the javascript portion of code:

player_id = Math.round(Math.random() * 5000);
your_sock = io.connect('http://' + document.domain + ':' + location.port);
your_sock.on('connect', function(){
    your_sock.emit('player_connect', {'id': player_id});
    console.log('I have connected with ID ' + player_id);
});

your_sock.on('what_player', function(data){
    console.log('recieved player number ' + data['player_number']);
    if(data['id'] == player_id){
        players[player_id] = {};
        if(data['player_number'] == 1){
            players[player_id]['num'] = data['player_number'];
            players[player_id]['x'] = 10;
            players[player_id]['y'] = 50;
        } else {
            players[player_id]['num'] = data['player_number'];
            players[player_id]['x'] = 375;
            players[player_id]['y'] = 50;
        }
    }
});

Here is the python Flask portion of code

@socketio.on('connect')
def handle_connect():
    print('Player connected')

@socketio.on('player_connect')
def handle_player_connect(data):
    print('received player_connect event')
    data_base = get_db()
    if data_base['count'] == 0:
        data_base[data['id']] = {'player_number': 1}
        data_base[data['id']]['x'] = 10
        data_base[data['id']]['y'] = 50
        data_base['count'] += 1
        socketio.emit('what_player', {'id': data['id'], 'player_number': data_base['count']})
    elif data_base['count'] == 1:
        data_base[data['id']] = {'player_number': 2}
        data_base[data['id']]['x'] = 375
        data_base[data['id']]['y'] = 50
        data_base['count'] += 1
        socketio.emit('what_player', {'id': data['id'], 'player_number': data_base['count']})

        #all players connected
        print('SENDING ALL PLAYERS CONNECTED SIGNAL')
        socketio.emit('all_players', data_base)

Here are my Heroku logs:

2018-09-03T05:46:30.740683+00:00 heroku[router]: at=info method=GET path="/test_pong/test_pong_game" host=www.nickdima.com request_id=d00254d0-f823-4a85-8e19-95f0087724f3 fwd="73.99.8.227" dyno=web.1 connect=0ms service=14ms status=200 bytes=999 protocol=http
2018-09-03T05:46:30.785061+00:00 heroku[router]: at=info method=GET path="/test_pong/static/js/paddle.js" host=www.nickdima.com request_id=01ff06e3-aaee-480f-941d-75626143bf4c fwd="73.99.8.227" dyno=web.1 connect=0ms service=5ms status=200 bytes=897 protocol=http
2018-09-03T05:46:30.795732+00:00 heroku[router]: at=info method=GET path="/test_pong/static/js/sketch.js" host=www.nickdima.com request_id=63c23be1-8ba7-4a6a-8100-bcc19146f42a fwd="73.99.8.227" dyno=web.1 connect=1ms service=8ms status=200 bytes=3601 protocol=http
2018-09-03T05:46:30.808960+00:00 heroku[router]: at=info method=GET path="/test_pong/static/libraries/p5.min.js" host=www.nickdima.com request_id=ce4d9796-efdc-402c-aae0-bc2b7c265816 fwd="73.99.8.227" dyno=web.1 connect=0ms service=34ms status=200 bytes=1135120 protocol=http
2018-09-03T05:46:30.788657+00:00 heroku[router]: at=info method=GET path="/test_pong/static/js/ball.js" host=www.nickdima.com request_id=7fa4fa84-8580-4a68-9560-834c627baa84 fwd="73.99.8.227" dyno=web.1 connect=1ms service=7ms status=200 bytes=410 protocol=http
2018-09-03T05:46:30.962821+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t=1535953590967-0" host=www.nickdima.com request_id=42bff075-2609-40da-8c9b-718fabd18003 fwd="73.99.8.227" dyno=web.1 connect=1ms service=2ms status=200 bytes=357 protocol=http
2018-09-03T05:46:31.098055+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1535953591019-1&sid=3fba645de8d7485eba3a26a83f84fc71" host=www.nickdima.com request_id=fce93aa4-04e4-4f67-8e88-064841c5edac fwd="73.99.8.227" dyno=web.1 connect=1ms service=84ms status=200 bytes=191 protocol=http
2018-09-03T05:46:56.090655+00:00 heroku[router]: at=info method=GET path="/test_pong/test_pong_game" host=www.nickdima.com request_id=db9cd6aa-a1d7-4efb-8385-5b6224517c40 fwd="73.99.8.227" dyno=web.1 connect=0ms service=3ms status=200 bytes=999 protocol=http
2018-09-03T05:46:56.177394+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t=1535953616185-0" host=www.nickdima.com request_id=546fc2cc-a82f-4155-922f-a1d39a9b5ba6 fwd="73.99.8.227" dyno=web.1 connect=0ms service=2ms status=200 bytes=357 protocol=http
2018-09-03T05:46:56.113312+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= websocket&sid=3fba645de8d7485eba3a26a83f84fc71" host=www.nickdima.com request_id=2717000f-8493-4c2d-9361-b2985064ef3d fwd="73.99.8.227" dyno=web.1 connect=0ms service=25044ms status=101 bytes=129 protocol=http
2018-09-03T05:46:56.383739+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1535953616311-1&sid=51e5baac529f43a98b522dd8272a9e5d" host=www.nickdima.com request_id=5d3e3c1d-208c-4ac6-983c-aa353157f483 fwd="73.99.8.227" dyno=web.1 connect=0ms service=88ms status=200 bytes=191 protocol=http

Current Attempt ------------ 2018-09-04

requirements.txt:

click==6.7
dnspython==1.15.0
eventlet==0.24.1
Flask==1.0.2
Flask-SocketIO==3.0.1
greenlet==0.4.14
gunicorn==19.9.0
itsdangerous==0.24
Jinja2==2.10
MarkupSafe==1.0
monotonic==1.5
python-engineio==2.2.0
python-socketio==2.0.0
six==1.11.0
Werkzeug==0.14.1

procfile:

web: gunicorn --worker-class eventlet -w 1 --chdir nickdima wsgi:app

heroku logs:

2018-09-05T01:49:33.156384+00:00 heroku[router]: sock=backend at=error code=H18 desc="Server Request Interrupted" method=GET path="/test_pong/static/libraries/p5.min.js" host=www.nickdima.com request_id=21503aa3-189d-4352-9284-c9e4729358ea fwd="71.206.187.35" dyno=web.1 connect=1ms service=20ms status=503 bytes= protocol=http
2018-09-05T01:49:33.081561+00:00 heroku[router]: at=info method=GET path="/test_pong/test_pong_game" host=www.nickdima.com request_id=330001f4-39f0-4308-b000-029fe40028e0 fwd="71.206.187.35" dyno=web.1 connect=1ms service=12ms status=200 bytes=1176 protocol=http
2018-09-05T01:49:33.156250+00:00 heroku[router]: at=info method=GET path="/test_pong/static/js/sketch.js" host=www.nickdima.com request_id=4ad0a7c4-eee4-45f5-8328-6091278e0a84 fwd="71.206.187.35" dyno=web.1 connect=0ms service=14ms status=200 bytes=3645 protocol=http
2018-09-05T01:49:33.196748+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t=1536112174726-0" host=www.nickdima.com request_id=a86191db-769a-4035-8a76-25a4d6ae4e95 fwd="71.206.187.35" dyno=web.1 connect=1ms service=3ms status=200 bytes=419 protocol=http
2018-09-05T01:49:33.078629+00:00 app[web.1]: 10.101.253.141 - - [05/Sep/2018:01:49:33 +0000] "GET /test_pong/test_pong_game HTTP/1.1" 200 1014 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.142534+00:00 app[web.1]: Traceback (most recent call last):
2018-09-05T01:49:33.142529+00:00 app[web.1]: [2018-09-05 01:49:33 +0000] [8] [ERROR] Socket error processing request.
2018-09-05T01:49:33.142536+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 66, in handle
2018-09-05T01:49:33.142537+00:00 app[web.1]: six.reraise(*sys.exc_info())
2018-09-05T01:49:33.142541+00:00 app[web.1]: raise value
2018-09-05T01:49:33.142539+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/six.py", line 625, in reraise
2018-09-05T01:49:33.142543+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 56, in handle
2018-09-05T01:49:33.142545+00:00 app[web.1]: self.handle_request(listener_name, req, client, addr)
2018-09-05T01:49:33.142547+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 129, in handle_request
2018-09-05T01:49:33.142548+00:00 app[web.1]: six.reraise(*sys.exc_info())
2018-09-05T01:49:33.142550+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/six.py", line 625, in reraise
2018-09-05T01:49:33.142552+00:00 app[web.1]: raise value
2018-09-05T01:49:33.142557+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/http/wsgi.py", line 403, in write_file
2018-09-05T01:49:33.142555+00:00 app[web.1]: resp.write_file(respiter)
2018-09-05T01:49:33.142553+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base_async.py", line 112, in handle_request
2018-09-05T01:49:33.142558+00:00 app[web.1]: if not self.sendfile(respiter):
2018-09-05T01:49:33.142943+00:00 app[web.1]: BlockingIOError: [Errno 11] Resource temporarily unavailable
2018-09-05T01:49:33.142560+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/http/wsgi.py", line 393, in sendfile
2018-09-05T01:49:33.142562+00:00 app[web.1]: sent += sendfile(sockno, fileno, offset + sent, count)
2018-09-05T01:49:33.152718+00:00 app[web.1]: 10.30.67.242 - - [05/Sep/2018:01:49:33 +0000] "GET /test_pong/static/js/sketch.js HTTP/1.1" 200 0 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.156363+00:00 app[web.1]: 10.69.229.32 - - [05/Sep/2018:01:49:33 +0000] "GET /test_pong/static/js/ball.js HTTP/1.1" 200 0 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.159465+00:00 app[web.1]: 10.143.137.225 - - [05/Sep/2018:01:49:33 +0000] "GET /test_pong/static/js/paddle.js HTTP/1.1" 200 0 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.196095+00:00 app[web.1]: 10.143.137.225 - - [05/Sep/2018:01:49:33 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536112174726-0 HTTP/1.1" 200 119 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.290914+00:00 app[web.1]: 10.69.229.32 - - [05/Sep/2018:01:49:33 +0000] "GET /favicon.ico HTTP/1.1" 404 233 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.160071+00:00 heroku[router]: at=info method=GET path="/test_pong/static/js/ball.js" host=www.nickdima.com request_id=8b6f3933-5a17-473c-b9d6-c6bb2838dede fwd="71.206.187.35" dyno=web.1 connect=1ms service=18ms status=200 bytes=454 protocol=http
2018-09-05T01:49:33.294742+00:00 heroku[router]: at=info method=GET path="/favicon.ico" host=www.nickdima.com request_id=a7eaa94f-6ef2-4b9c-a121-54ed25100202 fwd="71.206.187.35" dyno=web.1 connect=1ms service=3ms status=404 bytes=386 protocol=http
2018-09-05T01:49:33.382911+00:00 app[web.1]: 10.143.137.225 - - [05/Sep/2018:01:49:33 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536112174796-1&sid=cf08a35743824c3c97331953a2495b5e HTTP/1.1" 200 4 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T01:49:33.383458+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1536112174796-1&sid=cf08a35743824c3c97331953a2495b5e" host=www.nickdima.com request_id=39a7b0de-e421-494a-b619-6312d73cab03 fwd="71.206.187.35" dyno=web.1 connect=1ms service=133ms status=200 bytes=254 protocol=http
2018-09-05T01:50:03.424073+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1536112174962-2&sid=cf08a35743824c3c97331953a2495b5e" host=www.nickdima.com request_id=8b2628fd-06c4-44b8-9db9-d4487288fa7e fwd="71.206.187.35" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=http
2018-09-05T01:50:28.429256+00:00 heroku[router]: at=error code=H15 desc="Idle connection" method=GET path= "/socket.io/?EIO= 3&transport= websocket&sid=cf08a35743824c3c97331953a2495b5e" host=www.nickdima.com request_id=b134b681-44cd-4a2f-b67a-f74a660a5d4d fwd="71.206.187.35" dyno=web.1 connect=3ms service=55129ms status=503 bytes= protocol=http
2018-09-05T01:50:33.450013+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1536112174962-2&sid=cf08a35743824c3c97331953a2495b5e" host=www.nickdima.com request_id=d2f5ea3e-fa45-41c1-b9a0-79be30409cd7 fwd="71.206.187.35" dyno=web.1 connect=1ms service=30001ms status=503 bytes=0 protocol=http

chrome console (attempt 1):

Consistently getting this error until refresh

chrome console (attempt 2 after refreshing):

When I refresh my javascript black canvas loads but I do not see any errors in developer tab. I host a lot of other simple javascript games on my site and i'm noticing when i add the "--worker-class eventlet -w 1" to my procfile, a lot of these games fail to load and you need to keep refreshing. The errors are always "ERR_CONTENT_MISTMACH" when they don't load.

Added logging / preload to Gunicorn and saw these additional logs:

2018-09-05T03:23:07.362850+00:00 heroku[web.1]: Stopping all processes with SIGTERM
2018-09-05T03:23:07.382021+00:00 app[web.1]: [2018-09-05 03:23:07 +0000] [4] [INFO] Handling signal: term
2018-09-05T03:23:11.503047+00:00 heroku[web.1]: Starting process with command `gunicorn --worker-class eventlet -w 1 --no-sendfile --log-file=- --preload --chdir nickdima wsgi:app`
2018-09-05T03:23:15.192348+00:00 heroku[web.1]: State changed from starting to up
2018-09-05T03:23:14.966375+00:00 app[web.1]: [2018-09-05 03:23:14 +0000] [4] [INFO] Starting gunicorn 19.9.0
2018-09-05T03:23:14.968846+00:00 app[web.1]: [2018-09-05 03:23:14 +0000] [4] [INFO] Listening at: http://0.0.0.0:57792 (4)
2018-09-05T03:23:14.969056+00:00 app[web.1]: [2018-09-05 03:23:14 +0000] [4] [INFO] Using worker: eventlet
2018-09-05T03:23:14.979072+00:00 app[web.1]: [2018-09-05 03:23:14 +0000] [9] [INFO] Booting worker with pid: 9
2018-09-05T03:23:26.714115+00:00 heroku[web.1]: Stopping all processes with SIGTERM
2018-09-05T03:23:37.443586+00:00 heroku[web.1]: Error R12 (Exit timeout) -> At least one process failed to exit within 30 seconds of SIGTERM
2018-09-05T03:23:37.443586+00:00 heroku[web.1]: Stopping remaining processes with SIGKILL
2018-09-05T03:23:37.555124+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= websocket&sid=bde8a4bfe1f747b482f12c8df36370a2" host=www.nickdima.com request_id=39dec25b-b8b2-4c2c-b290-fa30f7077344 fwd="71.206.187.35" dyno=web.1 connect=0ms service=403842ms status=101 bytes=202 protocol=http
2018-09-05T03:23:37.565259+00:00 heroku[web.1]: Process exited with status 137
2018-09-05T03:23:39.081372+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t=1536117820575-3" host=www.nickdima.com request_id=ef81fcd4-a159-49a1-b64b-a96ca9c28eb3 fwd="71.206.187.35" dyno=web.1 connect=1ms service=5ms status=200 bytes=419 protocol=http
2018-09-05T03:23:39.169122+00:00 heroku[router]: at=info method=POST path= "/socket.io/?EIO= 3&transport= polling&t= 1536117820758-4&sid=b13c7d70371145e1b7dc939a83ac835b" host=www.nickdima.com request_id=2e698d4e-1ffc-48ca-99bb-8d7e9d9879ec fwd="71.206.187.35" dyno=web.1 connect=3ms service=4ms status=200 bytes=260 protocol=http
2018-09-05T03:23:39.083359+00:00 app[web.1]: 10.178.65.194 - - [05/Sep/2018:03:23:39 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536117820575-3 HTTP/1.1" 200 119 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T03:23:39.170709+00:00 app[web.1]: 10.178.65.194 - - [05/Sep/2018:03:23:39 +0000] "POST /socket.io/?EIO=3&transport=polling&t=1536117820758-4&sid=b13c7d70371145e1b7dc939a83ac835b HTTP/1.1" 200 2 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T03:23:39.450831+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1536117820764-5&sid=b13c7d70371145e1b7dc939a83ac835b" host=www.nickdima.com request_id=725fd364-b928-4535-9ccb-dd53cca366b2 fwd="71.206.187.35" dyno=web.1 connect=1ms service=248ms status=200 bytes=254 protocol=http
2018-09-05T03:23:39.455779+00:00 app[web.1]: 10.7.181.120 - - [05/Sep/2018:03:23:39 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536117820764-5&sid=b13c7d70371145e1b7dc939a83ac835b HTTP/1.1" 200 4 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T03:23:44.223695+00:00 app[web.1]: 10.7.181.120 - - [05/Sep/2018:03:23:44 +0000] "GET /test_pong/test_pong_game HTTP/1.1" 200 1022 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T03:23:44.218653+00:00 heroku[router]: at=info method=GET path="/test_pong/test_pong_game" host=www.nickdima.com request_id=9ffcf7cc-fdc3-4be0-bc67-379ba33c1b8c fwd="71.206.187.35" dyno=web.1 connect=1ms service=39ms status=200 bytes=1184 protocol=http
2018-09-05T03:23:44.966848+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= websocket&sid=b13c7d70371145e1b7dc939a83ac835b" host=www.nickdima.com request_id=6f1bf11c-136c-4bb5-809b-69ebab24bd48 fwd="71.206.187.35" dyno=web.1 connect=3ms service=5758ms status=101 bytes=202 protocol=http

New Session as of 2018-09-05 --------------------- same requirements.txt as 9/4 update

new procfile:

web: gunicorn --worker-class eventlet -w 1 --no-sendfile --log-level=DEBUG --log-file=- --preload --chdir nickdima wsgi:app

No longer seeing Content mismatch error and my console is logging a message that only should run if the socket connects via the following code:

player_id = Math.round(Math.random() * 5000);
your_sock = io.connect('http://' + document.domain + ':' + location.port + '/');  //io.connect('');  //io.connect('http://' + document.domain + ':' + location.port);
your_sock.on('connect', function(){
    your_sock.emit('player_connect', {'id': player_id});
    console.log('I have connected with ID ' + player_id);
});

But the server is not receiving the 'player_connect' emit:

@socker.on('player_connect')
def handle_player_connect(data):
    print('received player_connect event')
    data_base = get_db()
    if data_base['count'] == 0:
        data_base[data['id']] = {'player_number': 1}
        data_base[data['id']]['x'] = 10
        data_base[data['id']]['y'] = 50
        data_base['count'] += 1
        socker.emit('what_player', {'id': data['id'], 'player_number': data_base['count']})
    elif data_base['count'] == 1:
        data_base[data['id']] = {'player_number': 2}
        data_base[data['id']]['x'] = 375
        data_base[data['id']]['y'] = 50
        data_base['count'] += 1
        socker.emit('what_player', {'id': data['id'], 'player_number': data_base['count']})

        #all players connected
        print('SENDING ALL PLAYERS CONNECTED SIGNAL')
        socker.emit('all_players', data_base)

Heroku logs aren't showing anything helpful from what i can see:

18-09-05T21:54:04.640810+00:00 heroku[router]: at=info method=GET path="/home/" host=www.nickdima.com request_id=445a34ed-abf7-4336-82ab-4aabe79353b8 fwd="71.206.187.35" dyno=web.1 connect=1ms service=20ms status=200 bytes=11179 protocol=http
2018-09-05T21:54:04.568250+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] GET /
2018-09-05T21:54:04.583348+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:04 +0000] "GET / HTTP/1.1" 302 219 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:04.585672+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:04.621195+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] GET /home/
2018-09-05T21:54:04.638969+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:04 +0000] "GET /home/ HTTP/1.1" 200 11016 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:04.639359+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:04.713340+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] GET /home/assets/images/gallery00.jpg
2018-09-05T21:54:04.721688+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:04 +0000] "GET /home/assets/images/gallery00.jpg HTTP/1.1" 404 233 "http://www.nickdima.com/home/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:04.722818+00:00 app[web.1]: [2018-09-05 21:54:04 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:04.721980+00:00 heroku[router]: at=info method=GET path="/home/assets/images/gallery00.jpg" host=www.nickdima.com request_id=1936951c-a1ff-4c3f-b45e-62c05beef586 fwd="71.206.187.35" dyno=web.1 connect=1ms service=28ms status=404 bytes=386 protocol=http
2018-09-05T21:54:07.057783+00:00 heroku[router]: at=info method=GET path="/test_pong/test_pong_game" host=www.nickdima.com request_id=0f55eaef-cee3-42ae-902a-5f0ed2e478a0 fwd="71.206.187.35" dyno=web.1 connect=1ms service=6ms status=200 bytes=1184 protocol=http
2018-09-05T21:54:07.052890+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] GET /test_pong/test_pong_game
2018-09-05T21:54:07.056222+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:07 +0000] "GET /test_pong/test_pong_game HTTP/1.1" 200 1022 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:07.056441+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:07.561324+00:00 heroku[router]: at=info method=POST path= "/socket.io/?EIO= 3&transport= polling&t= 1536184448912-1&sid=f03a4525f29b4ccb852eb78e023f0876" host=www.nickdima.com request_id=222d42b3-3b15-4c22-be91-15f53536525d fwd="71.206.187.35" dyno=web.1 connect=1ms service=6ms status=200 bytes=260 protocol=http
2018-09-05T21:54:07.592902+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t= 1536184448914-2&sid=f03a4525f29b4ccb852eb78e023f0876" host=www.nickdima.com request_id=238b5616-398f-4eef-8f1b-6dc11b89f19c fwd="71.206.187.35" dyno=web.1 connect=0ms service=34ms status=200 bytes=254 protocol=http
2018-09-05T21:54:07.514706+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] GET /socket.io/
2018-09-05T21:54:07.516436+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:07 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536184448866-0 HTTP/1.1" 200 119 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:07.517309+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:07.556698+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] POST /socket.io/
2018-09-05T21:54:07.559278+00:00 app[web.1]: 10.45.224.215 - - [05/Sep/2018:21:54:07 +0000] "POST /socket.io/?EIO=3&transport=polling&t=1536184448912-1&sid=f03a4525f29b4ccb852eb78e023f0876 HTTP/1.1" 200 2 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:07.559734+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:07.561340+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] GET /socket.io/
2018-09-05T21:54:07.572150+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] GET /socket.io/
2018-09-05T21:54:07.593532+00:00 app[web.1]: 10.11.200.153 - - [05/Sep/2018:21:54:07 +0000] "GET /socket.io/?EIO=3&transport=polling&t=1536184448914-2&sid=f03a4525f29b4ccb852eb78e023f0876 HTTP/1.1" 200 4 "http://www.nickdima.com/test_pong/test_pong_game" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36"
2018-09-05T21:54:07.594556+00:00 app[web.1]: [2018-09-05 21:54:07 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:54:07.518196+00:00 heroku[router]: at=info method=GET path= "/socket.io/?EIO= 3&transport= polling&t=1536184448866-0" host=www.nickdima.com request_id=f253094f-a8a5-4572-a751-deca8289c4ea fwd="71.206.187.35" dyno=web.1 connect=1ms service=8ms status=200 bytes=419 protocol=http
2018-09-05T21:54:44.668853+00:00 app[web.1]: [2018-09-05 21:54:44 +0000] [9] [DEBUG] Closing connection.
2018-09-05T21:56:53.121104+00:00 app[web.1]: [2018-09-05 21:56:53 +0000] [9] [DEBUG] Closing connection.

I've added this code to server:

@socker.on('connect')
def handle_connect():
    print('THE HANDLE CONNECT FUNCTION WAS WRITTEN')
    try:
        socker.emit('testing', {'hello': 'hi'})
    except Exception as e:
        print(e)

and it does not get logged to heroku logs yet other logs do. Somehow the javascript socket.on('connect') function is running but the server side function is not running

herokugunicorngeventflask-socketio
The heroku and Chrome logs do not agree with each other. In Chrome you have 400 errors. The Heroku logs show all requests returned 200 (HTTP) or 101 (WebSocket), which are the success status codes. It seems you are pasting logs from different sessions. It would help if you can find logs from the sides for the same session, where the 400 errors can also be seen in the server. – Miguel
@Miguel Thank you so much for responding! Good catch, I went through so much switching around that inconsistently slipped in. I've updated near the bottom a consistent session requirements/procfile/heroku logs/chrome tools. – Nick Dima
Take a look at this issue gunicorn, it seems related to your problem: github.com/benoitc/gunicorn/issues/1797 – Miguel
@Miguel I've now added the --no-sendfile command to gunicorn and it's no longer having issues sending with ERR_CONTENT_MISMATCH, however, and it looks like the client side on('connect') function is running, but not the server side. I've updated the question at the bottom with more details. Any additional help would be so very much appreciated – Nick Dima
@Miguel for some reason when I put the socket decorators inside my application factory it all works perfectly. When i have my socket events inside my blueprints files it does not work. Trying to figure out why – Nick Dima