Flask-SocketIO: Server hangs intermittently immediately after WS upgrade
First of all, thanks so much for everything you do Miguel. your Pycon presentations are great, and I really appreciate your willingness to share your knowledge.
I’m using Flask-SocketIO with a fairly straight forward configuration, but the socket is hanging intermittently while trying to upgrade. I’ve tried multiple versions of socket.io, and I get the same behavior. It seems to happen to approximately 1 out of 5 connections.
Below is the server log, you can see @ 17:35:56 that the socket hangs for 1 minute before re-connecting.
(27489) accepted ('127.0.0.1', 54260)
127.0.0.1 - - [09/May/2017 17:35:52] "GET /ps/sso/dashboard/add_devices/ HTTP/1.1" 200 2175 0.000877
(27489) accepted ('127.0.0.1', 54261)
127.0.0.1 - - [09/May/2017 17:35:52] "GET /static/handsontable.bootstrap.css HTTP/1.1" 200 2600 0.001699
127.0.0.1 - - [09/May/2017 17:35:52] "GET /static/dashboard.css HTTP/1.1" 200 1883 0.001874
(27489) accepted ('127.0.0.1', 54265)
127.0.0.1 - - [09/May/2017 17:35:52] "GET /static/auth.js HTTP/1.1" 200 1577 0.001757
127.0.0.1 - - [09/May/2017 17:35:55] "GET /securechangeworkflow/ps/psauthtoken/getpsauthtoken?realm=dashboard HTTP/1.1" 200 992 0.002724
127.0.0.1 - - [09/May/2017 17:35:55] "GET /ps/sso/protected/dashboard/add_devices/ HTTP/1.1" 200 5435 0.003678
127.0.0.1 - - [09/May/2017 17:35:55] "GET /static/socket.js/?_=1494340555043 HTTP/1.1" 200 945 0.001240
c01e1bdab22c45faaccc491dcc34e1b6: Sending packet OPEN data {'sid': 'c01e1bdab22c45faaccc491dcc34e1b6', 'upgrades': ['websocket'], 'pingTimeout': 60000, 'pingInterval': 25000}
c01e1bdab22c45faaccc491dcc34e1b6: Sending packet MESSAGE data 0
127.0.0.1 - - [09/May/2017 17:35:55] "GET /socket.io/?EIO=3&transport=polling&t=LljerG8 HTTP/1.1" 200 381 0.000625
c01e1bdab22c45faaccc491dcc34e1b6: Received packet MESSAGE data 2["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"]
127.0.0.1 - - [09/May/2017 17:35:55] "POST /socket.io/?EIO=3&transport=polling&t=LljerIa&sid=c01e1bdab22c45faaccc491dcc34e1b6 HTTP/1.1" 200 199 0.001856
c01e1bdab22c45faaccc491dcc34e1b6: Sending packet MESSAGE data 2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]
127.0.0.1 - - [09/May/2017 17:35:55] "GET /socket.io/?EIO=3&transport=polling&t=LljerIf&sid=c01e1bdab22c45faaccc491dcc34e1b6 HTTP/1.1" 200 591 0.000965
(27489) accepted ('127.0.0.1', 54274)
c01e1bdab22c45faaccc491dcc34e1b6: Received request to upgrade to websocket
c01e1bdab22c45faaccc491dcc34e1b6: Sending packet NOOP data None
127.0.0.1 - - [09/May/2017 17:35:56] "GET /socket.io/?EIO=3&transport=polling&t=LljerMA&sid=c01e1bdab22c45faaccc491dcc34e1b6 HTTP/1.1" 200 215 0.009547
c01e1bdab22c45faaccc491dcc34e1b6: Client is gone, closing socket
127.0.0.1 - - [09/May/2017 17:36:56] "GET /socket.io/?EIO=3&transport=polling&t=LljerNJ&sid=c01e1bdab22c45faaccc491dcc34e1b6 HTTP/1.1" 400 218 60.005002
c01e1bdab22c45faaccc491dcc34e1b6: Failed websocket upgrade, expected UPGRADE packet, received None instead.
127.0.0.1 - - [09/May/2017 17:36:56] "GET /socket.io/?EIO=3&transport=websocket&sid=c01e1bdab22c45faaccc491dcc34e1b6 HTTP/1.1" 200 0 60.313282
38ead3dbaf084e7b8fd312e8260df9ca: Sending packet OPEN data {'sid': '38ead3dbaf084e7b8fd312e8260df9ca', 'upgrades': ['websocket'], 'pingTimeout': 60000, 'pingInterval': 25000}
38ead3dbaf084e7b8fd312e8260df9ca: Sending packet MESSAGE data 0
127.0.0.1 - - [09/May/2017 17:36:57] "GET /socket.io/?EIO=3&transport=polling&t=Lljf4H2 HTTP/1.1" 200 381 0.000808
(27489) accepted ('127.0.0.1', 54306)
38ead3dbaf084e7b8fd312e8260df9ca: Received request to upgrade to websocket
38ead3dbaf084e7b8fd312e8260df9ca: Received packet MESSAGE data 2["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"]
38ead3dbaf084e7b8fd312e8260df9ca: Sending packet MESSAGE data 2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]
127.0.0.1 - - [09/May/2017 17:36:57] "POST /socket.io/?EIO=3&transport=polling&t=Lljf4HN&sid=38ead3dbaf084e7b8fd312e8260df9ca HTTP/1.1" 200 199 0.002162
127.0.0.1 - - [09/May/2017 17:36:57] "GET /socket.io/?EIO=3&transport=polling&t=Lljf4HR&sid=38ead3dbaf084e7b8fd312e8260df9ca HTTP/1.1" 200 591 0.000838
38ead3dbaf084e7b8fd312e8260df9ca: Sending packet NOOP data None
127.0.0.1 - - [09/May/2017 17:36:57] "GET /socket.io/?EIO=3&transport=polling&t=Lljf4Ic&sid=38ead3dbaf084e7b8fd312e8260df9ca HTTP/1.1" 200 215 0.000209
38ead3dbaf084e7b8fd312e8260df9ca: Upgrade to websocket successful
38ead3dbaf084e7b8fd312e8260df9ca: Received packet PING data None
38ead3dbaf084e7b8fd312e8260df9ca: Sending packet PONG data None
Here is the client debug log, it gets stuck @
engine.io-client:polling we are currently polling - waiting to pause +1ms socket.io.js:416:9
Any help would be greatly appreciated, because I’ve exhausted my limited knowledge of socket.io inner workings.
socket.io-client:manager onclose +4ms socket.io.js:416:9
socket.io-client:manager cleanup +1ms socket.io.js:416:9
socket.io-client:socket close (transport close) +2ms socket.io.js:416:9
socket.io-client:manager will wait 962ms before reconnect attempt +2ms socket.io.js:416:9
socket.io-client:url parse ws://localhost:5000 +0ms socket.io.js:416:9
socket.io-client new io instance for ws://localhost:5000 +3ms socket.io.js:416:9
socket.io-client:manager readyState closed +1ms socket.io.js:416:9
socket.io-client:manager opening ws://localhost:5000 +2ms socket.io.js:416:9
engine.io-client:socket creating transport "polling" +1ms socket.io.js:416:9
engine.io-client:polling polling +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +1ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=LljerG8" +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +1ms socket.io.js:416:9
engine.io-client:socket setting transport polling +1ms socket.io.js:416:9
socket.io-client:manager connect attempt will timeout after 20000 +1ms socket.io.js:416:9
socket.io-client:manager readyState opening +1ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +131ms socket.io.js:416:9
engine.io-client:socket socket receive: type "open", data "{"sid":"c01e1bdab22c45faaccc491dcc34e1b6","upgrades":["websocket"],"pingTimeout":60000,"pingInterval":25000}" +5ms socket.io.js:416:9
engine.io-client:socket socket open +1ms socket.io.js:416:9
socket.io-client:manager open +1ms socket.io.js:416:9
socket.io-client:manager cleanup +0ms socket.io.js:416:9
socket.io-client:socket transport is open - connecting +1ms socket.io.js:416:9
engine.io-client:socket starting upgrade probes +1ms socket.io.js:416:9
engine.io-client:socket probing transport "websocket" +0ms socket.io.js:416:9
engine.io-client:socket creating transport "websocket" +1ms socket.io.js:416:9
engine.io-client:socket socket receive: type "message", data "0" +1ms socket.io.js:416:9
socket.io-parser decoded 0 as {"type":0,"nsp":"/"} +0ms socket.io.js:1552:9
socket.io-client:manager writing packet {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} +5ms socket.io.js:416:9
socket.io-parser encoding packet {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} +3ms socket.io.js:1552:9
socket.io-parser encoded {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} as 2["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"] +1ms socket.io.js:1552:9
engine.io-client:socket flushing 1 packets in socket +3ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open POST: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=LljerIa&sid=c01e1bdab22c45faaccc491dcc34e1b6" +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data 354:42["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"] +1ms socket.io.js:416:9
engine.io-client:polling polling +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +1ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=LljerIf&sid=c01e1bdab22c45faaccc491dcc34e1b6" +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +1ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +207ms socket.io.js:416:9
engine.io-client:socket socket receive: type "message", data "2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]" +5ms socket.io.js:416:9
socket.io-parser decoded 2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"] as {"type":2,"nsp":"/","data":["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]} +223ms socket.io.js:1552:9
socket.io-client:socket emitting event ["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"] +4ms socket.io.js:416:9
joined user room add_devices:6:7
engine.io-client:polling polling +3ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +4ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=LljerMA&sid=c01e1bdab22c45faaccc491dcc34e1b6" +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +0ms socket.io.js:416:9
engine.io-client:socket probe transport "websocket" opened +52ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +12ms socket.io.js:416:9
engine.io-client:socket socket receive: type "noop", data "undefined" +2ms socket.io.js:416:9
engine.io-client:polling polling +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +3ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=LljerNJ&sid=c01e1bdab22c45faaccc491dcc34e1b6" +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +1ms socket.io.js:416:9
engine.io-client:socket probe transport "websocket" pong +8ms socket.io.js:416:9
engine.io-client:socket pausing current transport "polling" +2ms socket.io.js:416:9
engine.io-client:polling we are currently polling - waiting to pause +1ms socket.io.js:416:9
engine.io-client:socket writing ping packet - expecting pong within 60000ms +25s socket.io.js:416:9
engine.io-client:socket socket error {"type":"TransportError","description":400} +35s socket.io.js:416:9
socket.io-client:manager error +3ms Error: xhr poll error
Stack trace:
Transport.prototype.onError@https://cdnjs.cloudflare.com/ajax/libs/socket.io/1.7.3/socket.io.js:5433:14
XHR.prototype.doPoll/<@https://cdnjs.cloudflare.com/ajax/libs/socket.io/1.7.3/socket.io.js:4816:6
Emitter.prototype.emit@https://cdnjs.cloudflare.com/ajax/libs/socket.io/1.7.3/socket.io.js:6856:8
Request.prototype.onError@https://cdnjs.cloudflare.com/ajax/libs/socket.io/1.7.3/socket.io.js:4994:4
Request.prototype.create/xhr.onreadystatechange/<@https://cdnjs.cloudflare.com/ajax/libs/socket.io/1.7.3/socket.io.js:4941:14
socket.io.js:416:9
engine.io-client:socket socket close with reason: "transport error" +3ms socket.io.js:416:9
socket.io-client:manager onclose +2ms socket.io.js:416:9
socket.io-client:manager cleanup +1ms socket.io.js:416:9
socket.io-client:socket close (transport error) +3ms socket.io.js:416:9
socket.io-client:manager will wait 958ms before reconnect attempt +1ms socket.io.js:416:9
engine.io-client:socket probe transport "websocket" failed because of error: socket closed +1ms socket.io.js:416:9
socket.io-client:manager attempting reconnect +960ms socket.io.js:416:9
socket.io-client:manager readyState closed +1ms socket.io.js:416:9
socket.io-client:manager opening ws://localhost:5000 +2ms socket.io.js:416:9
engine.io-client:socket creating transport "polling" +2ms socket.io.js:416:9
engine.io-client:polling polling +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +0ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=Lljf4H2" +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +1ms socket.io.js:416:9
engine.io-client:socket setting transport polling +1ms socket.io.js:416:9
socket.io-client:manager connect attempt will timeout after 20000 +1ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +3ms socket.io.js:416:9
engine.io-client:socket socket receive: type "open", data "{"sid":"38ead3dbaf084e7b8fd312e8260df9ca","upgrades":["websocket"],"pingTimeout":60000,"pingInterval":25000}" +2ms socket.io.js:416:9
engine.io-client:socket socket open +1ms socket.io.js:416:9
socket.io-client:manager open +0ms socket.io.js:416:9
socket.io-client:manager cleanup +1ms socket.io.js:416:9
socket.io-client:socket transport is open - connecting +1ms socket.io.js:416:9
socket.io-client:manager reconnect success +1ms socket.io.js:416:9
engine.io-client:socket starting upgrade probes +0ms socket.io.js:416:9
engine.io-client:socket probing transport "websocket" +1ms socket.io.js:416:9
engine.io-client:socket creating transport "websocket" +1ms socket.io.js:416:9
engine.io-client:socket socket receive: type "message", data "0" +1ms socket.io.js:416:9
socket.io-parser decoded 0 as {"type":0,"nsp":"/"} +1m socket.io.js:1552:9
socket.io-client:manager writing packet {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} +1ms socket.io.js:416:9
socket.io-parser encoding packet {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} +2ms socket.io.js:1552:9
socket.io-parser encoded {"type":2,"data":["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"],"options":{"compress":true},"nsp":"/"} as 2["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"] +1ms socket.io.js:1552:9
engine.io-client:socket flushing 1 packets in socket +3ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open POST: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=Lljf4HN&sid=38ead3dbaf084e7b8fd312e8260df9ca" +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data 354:42["join","eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI"] +1ms socket.io.js:416:9
engine.io-client:polling polling +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +1ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=Lljf4HR&sid=38ead3dbaf084e7b8fd312e8260df9ca" +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +0ms socket.io.js:416:9
engine.io-client:socket probe transport "websocket" opened +62ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +7ms socket.io.js:416:9
engine.io-client:socket socket receive: type "message", data "2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]" +1ms socket.io.js:416:9
socket.io-parser decoded 2["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"] as {"type":2,"nsp":"/","data":["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"]} +77ms socket.io.js:1552:9
socket.io-client:socket emitting event ["message","{\"data\": \"eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJleHAiOjE0OTQzNDE0NTUsImlhdCI6MTQ5NDM0MDU1NSwibmJmIjoxNDk0MzQwNTU1LCJqdGkiOiIzMDVlYzk4Zi1lY2MyLTQxZjUtODQ3NC00NTM3ZjQ2NTFkMjgiLCJpZGVudGl0eSI6eyJyZWFsbSI6ImRhc2hib2FyZCIsInVzZXJuYW1lIjoiTmF0ZSJ9LCJmcmVzaCI6ZmFsc2UsInR5cGUiOiJhY2Nlc3MiLCJ1c2VyX2NsYWltcyI6e319.B6YEh3adgTX70UTdfAxJ4kw20janqrTGSVO3VgDGNTI\"}"] +1ms socket.io.js:416:9
joined user room add_devices:6:7
engine.io-client:polling polling +2ms socket.io.js:416:9
engine.io-client:polling-xhr xhr poll +1ms socket.io.js:416:9
engine.io-client:polling-xhr "xhr open GET: http://localhost:5000/socket.io/?EIO=3&transport=polling&t=Lljf4Ic&sid=38ead3dbaf084e7b8fd312e8260df9ca" +1ms socket.io.js:416:9
engine.io-client:polling-xhr xhr data null +1ms socket.io.js:416:9
engine.io-client:socket probe transport "websocket" pong +1ms socket.io.js:416:9
engine.io-client:socket pausing current transport "polling" +1ms socket.io.js:416:9
engine.io-client:polling we are currently polling - waiting to pause +0ms socket.io.js:416:9
engine.io-client:polling polling got data [object ArrayBuffer] +4ms socket.io.js:416:9
engine.io-client:socket socket receive: type "noop", data "undefined" +1ms socket.io.js:416:9
engine.io-client:polling pre-pause polling complete +1ms socket.io.js:416:9
engine.io-client:polling paused +2ms socket.io.js:416:9
engine.io-client:socket changing transport and sending upgrade packet +0ms socket.io.js:416:9
engine.io-client:socket setting transport websocket +1ms socket.io.js:416:9
engine.io-client:socket clearing existing transport polling +0ms socket.io.js:416:9
engine.io-client:polling ignoring poll - transport state "paused" +1ms socket.io.js:416:9
engine.io-client:socket writing ping packet - expecting pong within 60000ms +25s socket.io.js:416:9
engine.io-client:socket flushing 1 packets in socket +5ms socket.io.js:416:9
engine.io-client:socket socket receive: type "pong", data "undefined" +4ms socket.io.js:416:9```
About this issue
- Original URL
- State: closed
- Created 7 years ago
- Comments: 24 (11 by maintainers)
@miguelgrinberg,
I’m in the middle of a 24hour hackathon at work, so I stopped trying to test, and started trying to workaround it.
It does happen a lot more when reloading, but also sometimes happens on a fresh load from a new browser window.
I should have a complete app in about 8 hours, I’ll try to upload it then.