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

Run error with uwsgi and gevent #381

Closed
wwqgtxx opened this issue Dec 14, 2016 · 25 comments
Closed

Run error with uwsgi and gevent #381

wwqgtxx opened this issue Dec 14, 2016 · 25 comments
Assignees

Comments

@wwqgtxx
Copy link

wwqgtxx commented Dec 14, 2016

When I run my flask app with uwsgi and gevent,It always throw those exception

20:20:30{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : d6a02d68ab4e4b9688186077ba4164a2: Received packet MESSAGE data 2/debug,["move",{"which":"X","dir":"up","speed":"","length":""}]
20:20:30{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "move" from d6a02d68ab4e4b9688186077ba4164a2 [/debug]
Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
    return self.engineio_app.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
    return self.eio.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
    environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
    return ws(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
    return self.app(self)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
    self.receive(pkt)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
    async=self.server.async_handlers)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
    self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
    self._handle_event_internal(self, sid, data, namespace, id)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
    r = server._trigger_event(data[0], namespace, sid, *data[1:])
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
    return self.handlers[namespace][event](*args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
    *args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
    app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'

And

[pid: 17560|app: 0|req: 19/18] 192.168.1.100 () {40 vars in 878 bytes} [Wed Dec 14 20:19:18 2016] GET / => generated 2912 bytes in 12 msecs (HTTP/1.1 200) 4 headers in 242 bytes (3 switches on core 999)
Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
    return self.engineio_app.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
    return self.eio.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 279, in handle_request
    start_response(r['status'], r['headers'] + cors_headers)
OSError: headers already sent

I'm only use the code like this

app = Flask(__name__)
app.secret_key = os.urandom(24)
socketio = SocketIO(app, async_mode="gevent_uwsgi")

And start my program by

uwsgi --http 0.0.0.0:8070 --chdir /ST --gevent 1000 --http-websockets --master --wsgi-file server.py --callable app

the uwsgi's start info is

*** Starting uWSGI 2.0.14 (32bit) on [Wed Dec 14 19:10:34 2016] ***
compiled with version: 4.9.2 on 14 December 2016 16:29:43
os: Linux-4.4.34-v7+ #930 SMP Wed Nov 23 15:20:41 GMT 2016
nodename: raspberrypi
machine: armv7l
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /
detected binary path: /usr/local/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
chdir() to /ST
your processes number limit is 7336
your memory page size is 4096 bytes
detected max file descriptor number: 65536
- async cores set to 1000 - fd table size: 65536
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on 0.0.0.0:8070 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:46388 (port auto-assigned) fd 3
Python version: 3.4.2 (default, Oct 19 2014, 14:03:53)  [GCC 4.9.1]
Python main interpreter initialized at 0x14f5558
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 14961664 bytes (14611 KB) for 1000 cores
*** Operational MODE: async ***

If I run this code without uwsgi and set async_code to eventlet,every thing work well.
Please help me found the reason.
Thanks

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 14, 2016

The second exception only show when client disconnect like the browser redirect to the other page.It is look same with #377

The first exception show when client send a message to server,it cause the server throw a error and will cut down the connect before the client auto reconnect.But in my program only use a function which do nothing,so I think it's not my code cause this execption.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 14, 2016

After more test I found the second exception must show when client disconnect.

But the first exception show random.Some time it works well,sometime it cause this error.And also some time after random times failed,it can work normal,than after a server reboot,it cause that error again.

@miguelgrinberg
Copy link
Owner

Please initialize SocketIO with additional logging, as follows:

socketio = SocketIO(app, async_mode="gevent_uwsgi", engineio_logger=True)

Run the server and keep it running until it fails. Then please send me the complete log from the start to the point in which it failed.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 15, 2016

08:03:45{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 8cc6c75f31ee438ba5fc91991c6ebe0e [/debug]
08:03:45{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481760225145}]
08:03:45{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Sending packet MESSAGE data 0/debug
[pid: 25364|app: 0|req: 6/6] 192.168.1.100 () {44 vars in 1065 bytes} [Thu Dec 15 08:03:45 2016] POST /socket.io/?EIO=3&transport=polling&t=LZ_oi5Q&sid=8cc6c75f31ee438ba5fc91991c6ebe0e => generated 2 bytes in 17 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
08:03:45{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Received request to upgrade to websocket
08:03:45{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Sending packet NOOP data None
[pid: 25364|app: 0|req: 8/7] 192.168.1.100 () {38 vars in 970 bytes} [Thu Dec 15 08:03:45 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_oi5R&sid=8cc6c75f31ee438ba5fc91991c6ebe0e => generated 94 bytes in 4 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
08:03:45{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Upgrade to websocket successful
08:04:01{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 8cc6c75f31ee438ba5fc91991c6ebe0e: Received packet MESSAGE data 2/debug,["move",{"which":"X","dir":"up","speed":"","length":""}]
08:04:01{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "move" from 8cc6c75f31ee438ba5fc91991c6ebe0e [/debug]
Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
    return self.engineio_app.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
    return self.eio.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
    environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
    return ws(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
    return self.app(self)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
    self.receive(pkt)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
    async=self.server.async_handlers)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
    self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
    self._handle_event_internal(self, sid, data, namespace, id)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
    r = server._trigger_event(data[0], namespace, sid, *data[1:])
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
    return self.handlers[namespace][event](*args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
    *args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
    app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 25364|app: 0|req: 8/8] 192.168.1.100 () {48 vars in 1155 bytes} [Thu Dec 15 08:03:45 2016] GET /socket.io/?EIO=3&transport=websocket&sid=8cc6c75f31ee438ba5fc91991c6ebe0e => generated 13 bytes in 16666 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
08:04:02{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet OPEN data {'pingInterval': 25000, 'upgrades': ['websocket'], 'sid': '692a5f318a564cc892834d8a06989fea', 'pingTimeout': 60000}
08:04:02{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet MESSAGE data 0
[pid: 25364|app: 0|req: 9/9] 192.168.1.100 () {38 vars in 896 bytes} [Thu Dec 15 08:04:02 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_omPA => generated 119 bytes in 7 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
08:04:02{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet MESSAGE data 0/debug
08:04:02{ST}loginchecker.py[line:55]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=17e194da-c1f7-11e6-83a6-b827eb66cb0d> pass login with mongodb
08:04:02{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 692a5f318a564cc892834d8a06989fea [/debug]
08:04:02{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481760242804}]
08:04:02{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet MESSAGE data 0/debug
[pid: 25364|app: 0|req: 10/10] 192.168.1.100 () {44 vars in 1065 bytes} [Thu Dec 15 08:04:02 2016] POST /socket.io/?EIO=3&transport=polling&t=LZ_omPL&sid=692a5f318a564cc892834d8a06989fea => generated 2 bytes in 18 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
08:04:02{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received request to upgrade to websocket
08:04:02{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet NOOP data None
[pid: 25364|app: 0|req: 12/11] 192.168.1.100 () {38 vars in 974 bytes} [Thu Dec 15 08:04:02 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_omPL.0&sid=692a5f318a564cc892834d8a06989fea => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
08:04:02{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Upgrade to websocket successful

And

08:04:52{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet PING data None
08:04:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet PONG data None
08:05:17{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet PING data None
08:05:17{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet PONG data None
08:05:42{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet PING data None
08:05:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet PONG data None
08:06:07{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet PING data None
08:06:07{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet PONG data None
08:06:32{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet PING data None
08:06:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Sending packet PONG data None
08:06:38{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 692a5f318a564cc892834d8a06989fea: Received packet MESSAGE data 2/debug,["pressclear",""]
08:06:38{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from 692a5f318a564cc892834d8a06989fea [/debug]
Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
    return self.engineio_app.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
    return self.eio.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
    environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
    return ws(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
    return self.app(self)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
    self.receive(pkt)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
    async=self.server.async_handlers)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
    self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
    self._handle_event_internal(self, sid, data, namespace, id)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
    r = server._trigger_event(data[0], namespace, sid, *data[1:])
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
    return self.handlers[namespace][event](*args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
    *args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
    app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 25364|app: 0|req: 12/12] 192.168.1.100 () {48 vars in 1155 bytes} [Thu Dec 15 08:04:02 2016] GET /socket.io/?EIO=3&transport=websocket&sid=692a5f318a564cc892834d8a06989fea => generated 39 bytes in 155867 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 999)
08:06:39{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Sending packet OPEN data {'pingInterval': 25000, 'upgrades': ['websocket'], 'sid': 'e57ffa9a583d4b6480ddc38e858b3ed5', 'pingTimeout': 60000}
08:06:39{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Sending packet MESSAGE data 0
[pid: 25364|app: 0|req: 13/13] 192.168.1.100 () {38 vars in 896 bytes} [Thu Dec 15 08:06:39 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_pMfM => generated 119 bytes in 7 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
08:06:39{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Received packet MESSAGE data 0/debug
08:06:39{ST}loginchecker.py[line:55]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=17e194da-c1f7-11e6-83a6-b827eb66cb0d> pass login with mongodb
08:06:39{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to e57ffa9a583d4b6480ddc38e858b3ed5 [/debug]
08:06:39{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481760399487}]
08:06:39{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Sending packet MESSAGE data 0/debug
[pid: 25364|app: 0|req: 14/14] 192.168.1.100 () {44 vars in 1065 bytes} [Thu Dec 15 08:06:39 2016] POST /socket.io/?EIO=3&transport=polling&t=LZ_pMfY&sid=e57ffa9a583d4b6480ddc38e858b3ed5 => generated 2 bytes in 20 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
[pid: 25364|app: 0|req: 15/15] 192.168.1.100 () {38 vars in 974 bytes} [Thu Dec 15 08:06:39 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_pMfY.0&sid=e57ffa9a583d4b6480ddc38e858b3ed5 => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
08:06:39{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Received request to upgrade to websocket
08:06:39{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Sending packet NOOP data None
[pid: 25364|app: 0|req: 17/16] 192.168.1.100 () {38 vars in 970 bytes} [Thu Dec 15 08:06:39 2016] GET /socket.io/?EIO=3&transport=polling&t=LZ_pMg0&sid=e57ffa9a583d4b6480ddc38e858b3ed5 => generated 4 bytes in 3 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
08:06:39{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : e57ffa9a583d4b6480ddc38e858b3ed5: Upgrade to websocket successful

Are those info enough?
And I see this exception is soo like #330

@miguelgrinberg
Copy link
Owner

You did not give me a complete session. Please give me the complete logs, from where you start the server, not just the section of the error.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 15, 2016

root@raspberrypi:/# python3 ST uwsgi
13:06:42{ST}__main__.py[line:50]<<module>> MainThread INFO : start uwsgi server
13:06:42{ST}utils.py[line:82]<run_process> MainThread INFO : launch {uwsgi --http 0.0.0.0:8070 --chdir /ST --gevent 1000 --http-websockets --master --wsgi-file server.py --callable app}
*** Starting uWSGI 2.0.14 (32bit) on [Thu Dec 15 13:06:42 2016] ***
compiled with version: 4.9.2 on 14 December 2016 16:29:43
os: Linux-4.4.34-v7+ #930 SMP Wed Nov 23 15:20:41 GMT 2016
nodename: raspberrypi
machine: armv7l
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /
detected binary path: /usr/local/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
chdir() to /ST
your processes number limit is 7336
your memory page size is 4096 bytes
detected max file descriptor number: 65536
- async cores set to 1000 - fd table size: 65536
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on 0.0.0.0:8070 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:46292 (port auto-assigned) fd 3
Python version: 3.4.2 (default, Oct 19 2014, 14:03:53)  [GCC 4.9.1]
Python main interpreter initialized at 0xebc558
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 14961664 bytes (14611 KB) for 1000 cores
*** Operational MODE: async ***
13:06:48{ST}server.py[line:54]<<module>> MainThread INFO : Start server with UWSGI!
13:06:48{ST}loginchecker.py[line:158]<delete_timeout_data> Thread-1 INFO : delete 0 timeout data
13:06:49{ST}server.py[line:39]<remove_eventlet> MainThread INFO : set sys.modules["eventlet"] = None
13:06:49{engineio}server.py[line:111]<__init__> MainThread INFO : Server initialized for gevent_uwsgi.
WSGI app 0 (mountpoint='') ready in 7 seconds on interpreter 0xebc558 pid: 27351 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 27351)
spawned uWSGI worker 1 (pid: 27360, cores: 1000)
spawned uWSGI http 1 (pid: 27361)
*** running gevent loop engine [addr:0x9bbb8] ***
13:06:49{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Sending packet OPEN data {'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000, 'sid': 'a52160b9313844d08cc4d7897248176b'}
13:06:49{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Sending packet MESSAGE data 0
[pid: 27360|app: 0|req: 1/1] 192.168.1.100 () {38 vars in 896 bytes} [Thu Dec 15 13:06:49 2016] GET /socket.io/?EIO=3&transport=polling&t=La0u36C => generated 119 bytes in 17 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
13:06:49{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Received packet MESSAGE data 0/debug
/usr/local/lib/python3.4/dist-packages/pymongo/topology.py:145: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#pymongo-fork-safe>
  "MongoClient opened before fork. Create MongoClient "
13:06:49{ST}loginchecker.py[line:55]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=17e194da-c1f7-11e6-83a6-b827eb66cb0d> pass login with mongodb
13:06:49{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to a52160b9313844d08cc4d7897248176b [/debug]
13:06:49{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Sending packet MESSAGE data 2/debug,["info",{"lastTimestamp":1481778409235,"dataList":null,"type":"data"}]
13:06:49{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Sending packet MESSAGE data 0/debug
[pid: 27360|app: 0|req: 2/2] 192.168.1.100 () {44 vars in 1065 bytes} [Thu Dec 15 13:06:49 2016] POST /socket.io/?EIO=3&transport=polling&t=La0u3ep&sid=a52160b9313844d08cc4d7897248176b => generated 2 bytes in 38 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
13:06:49{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Received request to upgrade to websocket
13:06:49{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Sending packet NOOP data None
[pid: 27360|app: 0|req: 4/3] 192.168.1.100 () {38 vars in 974 bytes} [Thu Dec 15 13:06:49 2016] GET /socket.io/?EIO=3&transport=polling&t=La0u3ep.0&sid=a52160b9313844d08cc4d7897248176b => generated 94 bytes in 4 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
13:06:49{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Upgrade to websocket successful
13:06:50{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : a52160b9313844d08cc4d7897248176b: Received packet MESSAGE data 2/debug,["pressclear",""]
13:06:50{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from a52160b9313844d08cc4d7897248176b [/debug]
Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
    return self.engineio_app.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
    return self.eio.handle_request(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
    environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
    start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
    return ws(environ, start_response)
  File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
    return self.app(self)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
    self.receive(pkt)
  File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
    async=self.server.async_handlers)
  File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
    return self.handlers[event](*args)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
    self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
    self._handle_event_internal(self, sid, data, namespace, id)
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
    r = server._trigger_event(data[0], namespace, sid, *data[1:])
  File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
    return self.handlers[namespace][event](*args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
    *args)
  File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
    app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 27360|app: 0|req: 4/4] 192.168.1.100 () {48 vars in 1155 bytes} [Thu Dec 15 13:06:49 2016] GET /socket.io/?EIO=3&transport=websocket&sid=a52160b9313844d08cc4d7897248176b => generated 13 bytes in 1491 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
13:06:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Sending packet OPEN data {'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000, 'sid': 'ecafe49c2d394417a06bc2f3b3e84ca7'}
13:06:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Sending packet MESSAGE data 0
[pid: 27360|app: 0|req: 5/5] 192.168.1.100 () {38 vars in 894 bytes} [Thu Dec 15 13:06:52 2016] GET /socket.io/?EIO=3&transport=polling&t=La0u4M8 => generated 119 bytes in 6 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
13:06:52{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Received packet MESSAGE data 0/debug
13:06:52{ST}loginchecker.py[line:55]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=17e194da-c1f7-11e6-83a6-b827eb66cb0d> pass login with mongodb
13:06:52{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to ecafe49c2d394417a06bc2f3b3e84ca7 [/debug]
13:06:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Sending packet MESSAGE data 2/debug,["info",{"lastTimestamp":1481778412125,"dataList":null,"type":"data"}]
13:06:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Sending packet MESSAGE data 0/debug
[pid: 27360|app: 0|req: 6/6] 192.168.1.100 () {44 vars in 1064 bytes} [Thu Dec 15 13:06:52 2016] POST /socket.io/?EIO=3&transport=polling&t=La0u4MG&sid=ecafe49c2d394417a06bc2f3b3e84ca7 => generated 2 bytes in 18 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
13:06:52{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Received request to upgrade to websocket
13:06:52{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Sending packet NOOP data None
[pid: 27360|app: 0|req: 8/7] 192.168.1.100 () {38 vars in 973 bytes} [Thu Dec 15 13:06:52 2016] GET /socket.io/?EIO=3&transport=polling&t=La0u4MG.0&sid=ecafe49c2d394417a06bc2f3b3e84ca7 => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
13:06:52{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : ecafe49c2d394417a06bc2f3b3e84ca7: Upgrade to websocket successful

@miguelgrinberg
Copy link
Owner

Thanks, I'm able to reproduce the problem now. I'll let you know once I figure out what's going on.

@miguelgrinberg
Copy link
Owner

Can I ask you to test your application with uwsgi 2.0.13.1? There are a couple of changes in 2.0.14 that cause some issues in the uwsgi integration code. I have to figure out exactly what changed and determine if the bug is theirs or mine.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 16, 2016

Please wait for me to rebuild uwsgi 2.0.13.1 on raspberrypi

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 16, 2016

It has the same error with uwsgi 2.0.13.1

10:46:05{ST}__main__.py[line:50]<<module>> MainThread INFO : start uwsgi server
10:46:05{ST}utils.py[line:82]<run_process> MainThread INFO : launch {uwsgi --http 0.0.0.0:8070 --chdir /home/pi/SwitchTester --gevent 1000 --http-websockets --master --wsgi-file server.py --callable app}
*** Starting uWSGI 2.0.13.1 (32bit) on [Fri Dec 16 10:46:05 2016] ***
compiled with version: 4.9.2 on 16 December 2016 10:18:16
os: Linux-4.4.34-v7+ #930 SMP Wed Nov 23 15:20:41 GMT 2016
nodename: raspberrypi
machine: armv7l
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /
detected binary path: /usr/local/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
chdir() to /home/pi/SwitchTester
your processes number limit is 7336
your memory page size is 4096 bytes
detected max file descriptor number: 1024
- async cores set to 1000 - fd table size: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on 0.0.0.0:8070 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:34052 (port auto-assigned) fd 3
Python version: 3.4.2 (default, Oct 19 2014, 14:03:53)  [GCC 4.9.1]
Python main interpreter initialized at 0x909da0
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 14961664 bytes (14611 KB) for 1000 cores
*** Operational MODE: async ***
10:46:07{ST}server.py[line:49]<<module>> MainThread INFO : Start server with UWSGI!
10:46:08{ST}server.py[line:34]<remove_eventlet> MainThread INFO : set sys.modules["eventlet"] = None
10:46:08{engineio}server.py[line:111]<__init__> MainThread INFO : Server initialized for gevent_uwsgi.
10:46:12{ST}loginchecker.py[line:169]<delete_timeout_data> Thread-1 INFO : delete 0 timeout data
WSGI app 0 (mountpoint='') ready in 7 seconds on interpreter 0x909da0 pid: 6666 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 6666)
spawned uWSGI worker 1 (pid: 6675, cores: 1000)
spawned uWSGI http 1 (pid: 6676)
*** running gevent loop engine [addr:0x9b274] ***
10:46:12{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Sending packet OPEN data {'pingTimeout': 60000, 'sid': 'bf7f324043044b128b0283814f9df80b', 'pingInterval': 25000, 'upgrades': ['websocket']}
10:46:12{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Sending packet MESSAGE data 0
[pid: 6675|app: 0|req: 1/1] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:46:12 2016] GET /socket.io/?EIO=3&transport=polling&t=La5XSJ5 => generated 119 bytes in 18 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
10:46:12{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Received packet MESSAGE data 0/debug
/usr/local/lib/python3.4/dist-packages/pymongo/topology.py:145: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#pymongo-fork-safe>
"MongoClient opened before fork. Create MongoClient "
10:46:12{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:46:12{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to bf7f324043044b128b0283814f9df80b [/debug]
10:46:12{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Sending packet MESSAGE data 2/debug,["info",{"dataList":null,"lastTimestamp":1481856372473,"type":"data"}]
10:46:12{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Sending packet MESSAGE data 0/debug
[pid: 6675|app: 0|req: 2/2] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:46:12 2016] POST /socket.io/?EIO=3&transport=polling&t=La5XTuv&sid=bf7f324043044b128b0283814f9df80b => generated 2 bytes in 43 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
10:46:12{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Received request to upgrade to websocket
10:46:12{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Sending packet NOOP data None
[pid: 6675|app: 0|req: 4/3] 192.168.1.100 () {38 vars in 974 bytes} [Fri Dec 16 10:46:12 2016] GET /socket.io/?EIO=3&transport=polling&t=La5XTuv.0&sid=bf7f324043044b128b0283814f9df80b => generated 94 bytes in 4 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:46:12{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Upgrade to websocket successful
10:46:22{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : bf7f324043044b128b0283814f9df80b: Received packet MESSAGE data 2/debug,["pressclear",""]
10:46:22{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from bf7f324043044b128b0283814f9df80b [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6675|app: 0|req: 4/4] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:46:12 2016] GET /socket.io/?EIO=3&transport=websocket&sid=bf7f324043044b128b0283814f9df80b => generated 13 bytes in 9734 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
10:46:23{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Sending packet OPEN data {'pingTimeout': 60000, 'sid': '260b7b9536104329bfa5430fa49e2ad0', 'pingInterval': 25000, 'upgrades': ['websocket']}
10:46:23{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Sending packet MESSAGE data 0
[pid: 6675|app: 0|req: 5/5] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:46:23 2016] GET /socket.io/?EIO=3&transport=polling&t=La5XWWc => generated 119 bytes in 6 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
10:46:23{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Received packet MESSAGE data 0/debug
10:46:23{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:46:23{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 260b7b9536104329bfa5430fa49e2ad0 [/debug]
10:46:23{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Sending packet MESSAGE data 2/debug,["info",{"dataList":null,"lastTimestamp":1481856383196,"type":"data"}]
10:46:23{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Sending packet MESSAGE data 0/debug
[pid: 6675|app: 0|req: 6/6] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:46:23 2016] POST /socket.io/?EIO=3&transport=polling&t=La5XWWn&sid=260b7b9536104329bfa5430fa49e2ad0 => generated 2 bytes in 22 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
10:46:23{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Received request to upgrade to websocket
10:46:23{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Sending packet NOOP data None
[pid: 6675|app: 0|req: 8/7] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:46:23 2016] GET /socket.io/?EIO=3&transport=polling&t=La5XWWo&sid=260b7b9536104329bfa5430fa49e2ad0 => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:46:23{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 260b7b9536104329bfa5430fa49e2ad0: Upgrade to websocket successful

And

10:56:25{ST}__main__.py[line:50]<<module>> MainThread INFO : start uwsgi server
10:56:25{ST}utils.py[line:82]<run_process> MainThread INFO : launch {uwsgi --http 0.0.0.0:8070 --chdir /home/pi/SwitchTester --gevent 1000 --http-websockets --master --wsgi-file server.py --callable app}
*** Starting uWSGI 2.0.13.1 (32bit) on [Fri Dec 16 10:56:25 2016] ***
compiled with version: 4.9.2 on 16 December 2016 10:18:16
os: Linux-4.4.34-v7+ #930 SMP Wed Nov 23 15:20:41 GMT 2016
nodename: raspberrypi
machine: armv7l
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /
detected binary path: /usr/local/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
chdir() to /home/pi/SwitchTester
your processes number limit is 7336
your memory page size is 4096 bytes
detected max file descriptor number: 1024
- async cores set to 1000 - fd table size: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on 0.0.0.0:8070 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:40647 (port auto-assigned) fd 3
Python version: 3.4.2 (default, Oct 19 2014, 14:03:53)  [GCC 4.9.1]
Python main interpreter initialized at 0x201dda0
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 14961664 bytes (14611 KB) for 1000 cores
*** Operational MODE: async ***
10:56:28{ST}server.py[line:49]<<module>> MainThread INFO : Start server with UWSGI!
10:56:28{ST}server.py[line:34]<remove_eventlet> MainThread INFO : set sys.modules["eventlet"] = None
10:56:28{engineio}server.py[line:111]<__init__> MainThread INFO : Server initialized for gevent_uwsgi.
10:56:32{ST}loginchecker.py[line:169]<delete_timeout_data> Thread-1 INFO : delete 0 timeout data
WSGI app 0 (mountpoint='') ready in 7 seconds on interpreter 0x201dda0 pid: 6787 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 6787)
spawned uWSGI worker 1 (pid: 6796, cores: 1000)
spawned uWSGI http 1 (pid: 6797)
*** running gevent loop engine [addr:0x9b274] ***
10:56:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Sending packet OPEN data {'sid': 'acd597263c40443e9764d2ca1bad2722', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 1/1] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:32 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zpli => generated 119 bytes in 20 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
10:56:32{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Received packet MESSAGE data 0/debug
/usr/local/lib/python3.4/dist-packages/pymongo/topology.py:145: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#pymongo-fork-safe>
"MongoClient opened before fork. Create MongoClient "
10:56:32{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:56:32{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to acd597263c40443e9764d2ca1bad2722 [/debug]
10:56:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481856992789}]
10:56:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 2/2] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:32 2016] POST /socket.io/?EIO=3&transport=polling&t=La5ZrLN&sid=acd597263c40443e9764d2ca1bad2722 => generated 2 bytes in 48 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
10:56:32{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Received request to upgrade to websocket
10:56:32{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Sending packet NOOP data None
[pid: 6796|app: 0|req: 4/3] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:56:32 2016] GET /socket.io/?EIO=3&transport=polling&t=La5ZrLO&sid=acd597263c40443e9764d2ca1bad2722 => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:56:32{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Upgrade to websocket successful
10:56:37{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : acd597263c40443e9764d2ca1bad2722: Received packet MESSAGE data 2/debug,["pressclear",""]
10:56:37{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from acd597263c40443e9764d2ca1bad2722 [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6796|app: 0|req: 4/4] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:32 2016] GET /socket.io/?EIO=3&transport=websocket&sid=acd597263c40443e9764d2ca1bad2722 => generated 13 bytes in 4695 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
10:56:38{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Sending packet OPEN data {'sid': 'c42cea1a92b947d490473cee595db403', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:38{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 5/5] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:38 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zsme => generated 119 bytes in 7 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
10:56:38{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Received packet MESSAGE data 0/debug
10:56:38{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:56:38{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to c42cea1a92b947d490473cee595db403 [/debug]
10:56:38{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481856998619}]
10:56:38{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 6/6] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:38 2016] POST /socket.io/?EIO=3&transport=polling&t=La5Zsmq&sid=c42cea1a92b947d490473cee595db403 => generated 2 bytes in 25 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
10:56:38{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Received request to upgrade to websocket
10:56:38{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Sending packet NOOP data None
[pid: 6796|app: 0|req: 8/7] 192.168.1.100 () {38 vars in 974 bytes} [Fri Dec 16 10:56:38 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zsmq.0&sid=c42cea1a92b947d490473cee595db403 => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
10:56:38{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Upgrade to websocket successful
10:56:39{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : c42cea1a92b947d490473cee595db403: Received packet MESSAGE data 2/debug,["pressclear",""]
10:56:39{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from c42cea1a92b947d490473cee595db403 [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6796|app: 0|req: 8/8] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:38 2016] GET /socket.io/?EIO=3&transport=websocket&sid=c42cea1a92b947d490473cee595db403 => generated 13 bytes in 752 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 999)
10:56:40{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Sending packet OPEN data {'sid': '0bb094454886425d8ff2abdf18389e07', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:40{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 9/9] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:40 2016] GET /socket.io/?EIO=3&transport=polling&t=La5ZtKM => generated 119 bytes in 7 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
10:56:40{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Received packet MESSAGE data 0/debug
10:56:40{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:56:40{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 0bb094454886425d8ff2abdf18389e07 [/debug]
10:56:40{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481857000906}]
10:56:40{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 10/10] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:40 2016] POST /socket.io/?EIO=3&transport=polling&t=La5ZtKY&sid=0bb094454886425d8ff2abdf18389e07 => generated 2 bytes in 25 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
10:56:40{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Received request to upgrade to websocket
10:56:40{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Sending packet NOOP data None
[pid: 6796|app: 0|req: 12/11] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:56:40 2016] GET /socket.io/?EIO=3&transport=polling&t=La5ZtKZ&sid=0bb094454886425d8ff2abdf18389e07 => generated 94 bytes in 6 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:56:40{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Upgrade to websocket successful
10:56:41{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 0bb094454886425d8ff2abdf18389e07: Received packet MESSAGE data 2/debug,["pressclear",""]
10:56:41{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from 0bb094454886425d8ff2abdf18389e07 [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6796|app: 0|req: 12/12] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:40 2016] GET /socket.io/?EIO=3&transport=websocket&sid=0bb094454886425d8ff2abdf18389e07 => generated 13 bytes in 865 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
10:56:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Sending packet OPEN data {'sid': '2f381bd7daa340f88c79cda5b1fe0f9a', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 13/13] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:42 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Ztpb => generated 119 bytes in 7 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
10:56:42{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Received packet MESSAGE data 0/debug
10:56:42{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
10:56:42{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 2f381bd7daa340f88c79cda5b1fe0f9a [/debug]
10:56:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481857002905}]
10:56:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 14/14] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:42 2016] POST /socket.io/?EIO=3&transport=polling&t=La5Ztpn&sid=2f381bd7daa340f88c79cda5b1fe0f9a => generated 2 bytes in 26 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
10:56:42{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Received request to upgrade to websocket
10:56:42{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Sending packet NOOP data None
[pid: 6796|app: 0|req: 16/15] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:56:42 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Ztpo&sid=2f381bd7daa340f88c79cda5b1fe0f9a => generated 94 bytes in 6 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
10:56:42{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 2f381bd7daa340f88c79cda5b1fe0f9a: Upgrade to websocket successful
10:56:43{ST}loginchecker.py[line:71]<check_login> b'uWSGIWorker1Core0' INFO : <username=None,uid=4b93d572-c288-11e6-8f9d-b827eb66cb0d> pass login with mongodb
[pid: 6796|app: 0|req: 17/16] 192.168.1.100 () {42 vars in 926 bytes} [Fri Dec 16 10:56:43 2016] GET /mode/debug/ => generated 15761 bytes in 169 msecs (HTTP/1.1 200) 3 headers in 243 bytes (3 switches on core 998)
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 279, in handle_request
start_response(r['status'], r['headers'] + cors_headers)
OSError: headers already sent
[pid: 6796|app: 0|req: 17/17] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:42 2016] GET /socket.io/?EIO=3&transport=websocket&sid=2f381bd7daa340f88c79cda5b1fe0f9a => generated 13 bytes in 929 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 999)
10:56:43{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Sending packet OPEN data {'sid': '3c0c61bd20674e03935c22568801e5ce', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:43{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 18/18] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:43 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zu4I => generated 119 bytes in 8 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
10:56:43{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Received packet MESSAGE data 0/debug
10:56:43{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 3c0c61bd20674e03935c22568801e5ce [/debug]
10:56:43{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481857003972}]
10:56:43{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 19/19] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:43 2016] POST /socket.io/?EIO=3&transport=polling&t=La5Zu4a&sid=3c0c61bd20674e03935c22568801e5ce => generated 2 bytes in 16 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
10:56:43{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Received request to upgrade to websocket
10:56:43{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Sending packet NOOP data None
[pid: 6796|app: 0|req: 21/20] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:56:43 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zu4d&sid=3c0c61bd20674e03935c22568801e5ce => generated 94 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:56:43{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Upgrade to websocket successful
10:56:45{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 3c0c61bd20674e03935c22568801e5ce: Received packet MESSAGE data 2/debug,["pressclear",""]
10:56:45{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from 3c0c61bd20674e03935c22568801e5ce [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6796|app: 0|req: 21/21] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:43 2016] GET /socket.io/?EIO=3&transport=websocket&sid=3c0c61bd20674e03935c22568801e5ce => generated 13 bytes in 1235 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 998)
10:56:46{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Sending packet OPEN data {'sid': 'ad17b299b76e46a3a508b2cc3b19ec5c', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:46{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 22/22] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:46 2016] GET /socket.io/?EIO=3&transport=polling&t=La5ZugL => generated 119 bytes in 8 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 998)
10:56:46{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Received packet MESSAGE data 0/debug
10:56:46{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to ad17b299b76e46a3a508b2cc3b19ec5c [/debug]
10:56:46{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481857006404}]
10:56:46{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 23/23] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:46 2016] POST /socket.io/?EIO=3&transport=polling&t=La5ZugZ&sid=ad17b299b76e46a3a508b2cc3b19ec5c => generated 2 bytes in 16 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 998)
10:56:46{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Received request to upgrade to websocket
10:56:46{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Sending packet NOOP data None
[pid: 6796|app: 0|req: 25/24] 192.168.1.100 () {38 vars in 970 bytes} [Fri Dec 16 10:56:46 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zuga&sid=ad17b299b76e46a3a508b2cc3b19ec5c => generated 94 bytes in 7 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 998)
10:56:46{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Upgrade to websocket successful
10:56:47{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : ad17b299b76e46a3a508b2cc3b19ec5c: Received packet MESSAGE data 2/debug,["pressclear",""]
10:56:47{socketio}server.py[line:443]<_handle_event> b'uWSGIWorker1Core0' INFO : received event "pressclear" from ad17b299b76e46a3a508b2cc3b19ec5c [/debug]
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 41, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 241, in handle_request
environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 81, in handle_get_request
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 122, in _upgrade_websocket
return ws(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/async_gevent_uwsgi.py", line 58, in __call__
return self.app(self)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 188, in _websocket_handler
self.receive(pkt)
File "/usr/local/lib/python3.4/dist-packages/engineio/socket.py", line 50, in receive
async=self.server.async_handlers)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 359, in _trigger_event
return self.handlers[event](*args)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 509, in _handle_eio_message
self._handle_event(sid, pkt.namespace, pkt.id, pkt.data)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 448, in _handle_event
self._handle_event_internal(self, sid, data, namespace, id)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 451, in _handle_event_internal
r = server._trigger_event(data[0], namespace, sid, *data[1:])
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 480, in _trigger_event
return self.handlers[namespace][event](*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 221, in _handler
*args)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 575, in _handle_event
app = self.server.environ[sid]['flask.app']
KeyError: 'flask.app'
[pid: 6796|app: 0|req: 25/25] 192.168.1.100 () {48 vars in 1155 bytes} [Fri Dec 16 10:56:46 2016] GET /socket.io/?EIO=3&transport=websocket&sid=ad17b299b76e46a3a508b2cc3b19ec5c => generated 13 bytes in 818 msecs (HTTP/1.1 101) 4 headers in 188 bytes (1 switches on core 999)
10:56:48{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Sending packet OPEN data {'sid': '0ebd9880b06346f780b07414dd3e4316', 'pingInterval': 25000, 'upgrades': ['websocket'], 'pingTimeout': 60000}
10:56:48{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Sending packet MESSAGE data 0
[pid: 6796|app: 0|req: 26/26] 192.168.1.100 () {38 vars in 896 bytes} [Fri Dec 16 10:56:48 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zv8P => generated 119 bytes in 8 msecs (HTTP/1.1 200) 4 headers in 180 bytes (3 switches on core 999)
10:56:48{engineio}socket.py[line:44]<receive> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Received packet MESSAGE data 0/debug
10:56:48{socketio}server.py[line:215]<emit> b'uWSGIWorker1Core0' INFO : emitting event "info" to 0ebd9880b06346f780b07414dd3e4316 [/debug]
10:56:48{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Sending packet MESSAGE data 2/debug,["info",{"type":"data","dataList":null,"lastTimestamp":1481857008328}]
10:56:48{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Sending packet MESSAGE data 0/debug
[pid: 6796|app: 0|req: 27/27] 192.168.1.100 () {44 vars in 1065 bytes} [Fri Dec 16 10:56:48 2016] POST /socket.io/?EIO=3&transport=polling&t=La5Zv8d&sid=0ebd9880b06346f780b07414dd3e4316 => generated 2 bytes in 17 msecs (HTTP/1.1 200) 3 headers in 141 bytes (3 switches on core 999)
10:56:48{engineio}socket.py[line:79]<handle_get_request> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Received request to upgrade to websocket
10:56:48{engineio}socket.py[line:69]<send> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Sending packet NOOP data None
[pid: 6796|app: 0|req: 29/28] 192.168.1.100 () {38 vars in 974 bytes} [Fri Dec 16 10:56:48 2016] GET /socket.io/?EIO=3&transport=polling&t=La5Zv8d.0&sid=0ebd9880b06346f780b07414dd3e4316 => generated 94 bytes in 7 msecs (HTTP/1.1 200) 3 headers in 131 bytes (3 switches on core 999)
10:56:48{engineio}socket.py[line:174]<_websocket_handler> b'uWSGIWorker1Core0' INFO : 0ebd9880b06346f780b07414dd3e4316: Upgrade to websocket successful

@miguelgrinberg
Copy link
Owner

Any improvement if you upgrade to Flask-SocketIO 2.8.2?

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 16, 2016

It seems OK.I will try more times to confirm this exception

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 16, 2016

But the OSError: headers already sent still throw in disconnect.And if close the server and restart it,after the client auto reconnect to server,the first connect will can't receive anything.It must do a browser reflush or wait the first websocket connect timeout to recevied the message from server

[pid: 8475|app: 0|req: 11/10] 192.168.1.100 () {40 vars in 878 bytes} [Fri Dec 16 12:19:38 2016] GET / => generated 2912 bytes in 46 msecs (HTTP/1.1 200) 4 headers in 242 bytes (3 switches on core 998)
Traceback (most recent call last):
File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 2000, in __call__
return self.wsgi_app(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/flask_socketio/__init__.py", line 42, in __call__
start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/middleware.py", line 47, in __call__
return self.engineio_app.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/socketio/server.py", line 352, in handle_request
return self.eio.handle_request(environ, start_response)
File "/usr/local/lib/python3.4/dist-packages/engineio/server.py", line 279, in handle_request
start_response(r['status'], r['headers'] + cors_headers)
OSError: headers already sent

@miguelgrinberg
Copy link
Owner

Yes, I've seen this one too. It is benign, meaning that it does not interfere with the application. A similar error sometimes occurs with gunicorn as well.

The problem comes from the fact that WebSocket does not fit well with the WSGI protocol. The error occurs when a standard WSGI response is issued when a WebSocket request ends. Web servers usually have a non-standard mechanism to indicate that the WSGI response should be omitted for those requests, but since that is done outside of the WSGI protocol and there are several different ways this was implemented by webservers, it tends to not work too well.

I was thinking that maybe I should implement my own way to detect these cases, but I haven't done that yet, since the error can be ignored.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 16, 2016

I know that exception had no effect with normal use,only seem that not good,so I suggest can use a try-except to avoid display that.
The other question I had said above is that if close the server and restart it,after the client auto reconnect to server,the first connect will can't receive anything.It must do a browser reflush or wait the first websocket connect timeout to recevied the message from server.
This problem is need to fix and only show on use uwsgi+gevent, not show with eventlet or geventwebsocket.

@miguelgrinberg
Copy link
Owner

A try-catch exception in that place is not a good idea, because I really have no way to distinguish between an exception raised due to this issue, or by any other problems. If I do this, I risk masking other errors. Also, while uwsgi errors when start_response is called, gunicorn has a different manifestation of this issue, which causes an error that is internal to gunicorn, so I would have nothing to catch (see benoitc/gunicorn#1210 if you are curious about the details).

I had said above is that if close the server and restart it,after the client auto reconnect to server,the first connect will can't receive anything.

Hmm. I do not see this here. What I did is simply Ctrl-C the uwsgi process while a client was connected, then run it again. The client reconnected immediately and everything works fine. Are you doing anything different?

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 17, 2016

I only use a emit() and set a flask session in server's connect().Does it will cause some exception only with uwsgi?
In the server,I use the background task to broadcast message to every client.
Ang I look in chrome's developer tools' network page show the first auto reconnect websocket only have the shakehand like 2probe and no other any message.The client can't send any message to server too.But after a page reflush, every thing will be fine.

@miguelgrinberg
Copy link
Owner

@wwqgtxx does this happen when you use the example app in this repository? That's the app I tested this with.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 17, 2016

Sorry,I hadn't test the example app.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 17, 2016

I know that I call a init() function write by myself in connect().It cause connect() be so slow to cause this websocket connect timeout.I think the uwsgi may be has some time limit for a websocket parse time to cause this problem.
But I call init() function in connect because the falsk-websocket don't call flask's app.before_first_request function and also not provide the similar function to init the app.

@miguelgrinberg
Copy link
Owner

@wwqgtxx yes, a slow connect handler can cause trouble, these are supposed to be quick. Consider that when the connect handler is invoked on the server, the client is already connected, but the server is not going to accept anything until the connect handler ends and accepts the connection. You may want to consider offloading this work that you are doing to an event that fires after the connection is fully established.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 17, 2016

So can we support app.before_first_request() or Flask-SocketIO provide a function can do same things for server init?

@miguelgrinberg
Copy link
Owner

The concept of requests does not exist in Socket.IO, so Flask's before_first_request does not really apply here. Besides, you don't want this function to be called only the first time, you want it called for every connection.

The easiest way to implement what you need is to have the client send an event immediately after connecting. You can do what you need in the handler of the event. It's still not a good idea to make it a very long task, but at least it is not stopping the connection process.

@wwqgtxx
Copy link
Author

wwqgtxx commented Dec 17, 2016

In fact I only need do a init() once,whatever the flask or flask-socketio do.
As you know,uwsgi use fork to start the wsgi application.But the lock is unsafe in fork because I need use pymongo to connect server and do other things ready only once.
If only in flask,the flask's before_first_request work fine.But in Flask-socketio,I need to confirm is my own init() has been called.It makes my app be complicated.And because the gevent.spawn() default run task immeditely,if not use spawn_later(),it still cause the connect() timeout.
That make my app must take care about what's flask_socketio's loop engine used and do special parse for it.

@miguelgrinberg
Copy link
Owner

I'm closing this, as the headers already sent error is now fixed in package python-engineio. Please reopen if there are any outstanding issues.

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

No branches or pull requests

2 participants