Flask-socketio: Emit seem to work randomly

[Laoup]

Hi @miguelgrinberg and everybody else !

Thanks you for your work. But your work make me crazy ! :/

I was looking for create a server in python he can communicate with a nodejs client using socketio. So i found flask-socketIO.
I just tried some basics things for the moment but it's seems not working. Actually i have a problem with emit().
And i really don't understand what can be the problem, because i read lot of issue about flask-socketio all around internet and never found similar problem than me.

Before i explain let me show the code:
SERVER (python)`

from flask import Flask, render_template
from flask_socketio import SocketIO
from flask_socketio import send, emit
import json
#import eventlet
#import redis
#eventlet.monkey_patch()

#from status.status import Status

app = Flask(__name__)
app.config['SECRET_KEY'] = 'secret!'
socketio = SocketIO(app)
#status = Status()

@socketio.on('connect')
def test_connect():
    emit('my response', {'data': 'Connected'})

@socketio.on('disconnect')
def test_disconnect():
    print('Client disconnected')

def ack():
    print("callback was receipt")
    pass

@socketio.on('transaction')
def test_transaction(data):
    data = json.loads(data)
    print("message from transaction\n")
    print("market id : {}  ".format(data['market_id']))
    print("user id : " + data['user_id'] + "   ")
    print("total price : " + data['total_price'] + "   ")
    emit('succeed', "OK", callback=ack)
    pass

if __name__ == '__main__':
    socketio.run(app, `port=8080)

CLIENT (nodejs)

//client.js
var io = require('socket.io-client');
var json = require('json');
var socket = io.connect('http://localhost:8080', {reconnect: true});

socket.on('succeed', function(message, back) {
  console.log(message);
  console.log('succeed');
  back();
});

socket.on('rejected', function(message) {
  console.log(message);
  console.log('rejected');
});

// Add a connect listener
socket.on('connect', function () {
  var arr = [22334421, 47631470, 12342378, 72430096];
  var ans = {"market_id":"12", "user_id":"1", "total_price":"200", "items": arr};
    console.log('Connected!');



    socket.emit("transaction", JSON.stringify(ans));
});

So, i can connect the client to the server (actually, the client seem to loose connection and connect again after, but that's not my problem for the moment).
I can emit from the client to the server ("transaction") and the server got it. From the moment no problem. But when i tried to send a response ("succeed") with the emit method after receipt "transcation" it's become weird.
Like the most of the times nothing happen, just the client print "Connected!" and the server print all the data receipt by "transaction" but there is no "succeed" message in the client side and there is no use of the callback function ack() on the server side.
But if i let's run the server and the client after a while (and some re-connection), magic ! the client side print "succeed" and the fonction callback in the server side are also called.

So i don't understand what happen, why it's not working simply when i connect the client from the first time ?
I'm doing something wrong ?
I pass next to something important and i'm doing some stupid things ?

I hope i'm clear on my explanation ^^. If you could help me i will be very happy because after lot of research and lot of time i still don't understanding what happen on the code ...

[miguelgrinberg]

I'm not sure where the problem is yet, but the issue appears to be related to the client trying to do an upgrade to websocket in the middle of this transaction event. If I run your client and server using polling only, or using websocket only, then the callback works fine. Will continue investigating.

[Laoup]

Hi sir, thanks you for your help.

Yeah, that's look like if it's doing something like you explain.
I hope you could explain me why it's doing this.

Sorry for this question but what you would mean by using "polling only" or using "websocket only"

Have a good day

[miguelgrinberg]

See the socket.io client docs: https://socket.io/docs/client-api/#With-websocket-transport-only

[Laoup]

Good Morning @miguelgrinberg

Sir, i don't know if just i'm doing idiot things or if there is a real problem for create communication with flask.

I show you the code (not to much different than initial problem)

Server
`
from flask import Flask, render_template
from flask_socketio import SocketIO
from flask_socketio import send, emit
import json

from BigBrother.BigBrother import BigBrother
from serveur.status.status import Status

app = Flask(__name__)
app.config['SECRET_KEY'] = 'secret!'
socketio = SocketIO(app)
status = Status()
bigbrother = BigBrother()
bigbrother.connectOBP()

@socketio.on('connect')
def connect():
bigbrother.reInitialiseAccount()
emit('my response', {'data': 'Connected'})
print('One client is Connectedn')

@socketio.on('disconnect')
def disconnect():
print('One Client is disconnectedn')

@socketio.on("NewCustomerRegister")
def NewCustomerRegister():
id = bigbrother.returnAvailaibleIdAccount()
print(id)
ans = str(id)
emit('newBankId', {'id': ans})
pass

if __name__ == '__main__':
socketio.run(app, port=8080)
`

Client

`
//client.js
var io = require('socket.io-client');
var json = require('json');
var socket = io.connect('http://localhost:8080', {reconnect: true, transports: ['websocket']});
//var socket = io.connect('http://localhost:8080', {reconnect: true});

socket.on('my response', function(data) {
console.log(data);
console.log('my response');
});

socket.on('newBankId', function(id) {
console.log("HERE");
console.log(id);
});

socket.on('connect', function () {
console.log('client Connected to server');

socket.emit("NewCustomerRegister");
});

socket.on('reconnect_attempt', () => {
socket.io.opts.transports = ['polling', 'websocket'];
});

`

Like you can see i use websocket only like you told me but emit continue to do mysterious things...
The emit on 'my response' work correctly, but the one in 'newBankId' seem to not work at all.
Also if i move the 'my response' emit in "NewCustomerRegister", 'my response' stop working.

So, i'm really not understanding... do you see any solution ?

Thakns you for your time, bye

[miguelgrinberg]

Can you get logs from the server and the client? That should help you determine where the emits are getting lost.

[Laoup]

The output i get ?

Yes,

Server Side:

One client is Connected
119

(119 is a value from the python script behind, but no importance here i think)

Client Side:

client Connected to server
{ data: 'Connected' }

[Laoup]

oh damn ! I think i find some solution by using socketio.emit instead of simply "emit".

But maybe before i close this ticket you could explain me for which reason it's working better with socketio.emit ?
(i'm not sure to understand well)

Thank you,

[miguelgrinberg]

The emit() function uses the sender as addressee by default. The socketio.emit() function broadcasts to all clients by default. Were you expecting to get the emits to clients that were not the ones emiting to the server in the first place? You could have done that with emit('newBankId', {'id': ans}, broadcast=True).

[Laoup]

Yeah i saw about broadcast, it was why i not understanding why that's work better with than without. (Because i have only one client so..).

So, in all case. Yesterday when i saw it's work one time i was optimistic, but finally it's continuous to not work well.
It's actually like the first problem i report, sometimes that's work ("Here" and "119" are receipt and print by the client) and sometimes not...

So i'm lost once again :/

[miguelgrinberg]

You may want to enable logs on both ends and share them here.

[Laoup]

Soooooo, i find something it's look like working when i start the server and after client. But it's not working if i start client before the server is ready.

I get the logs on client (nodejs) side. I don't know if there is a way of getting logs on server side (python).

Logs when it's work:

socket.io-client:url parse http://localhost:8080 +0ms
socket.io-client new io instance for http://localhost:8080 +0ms
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "websocket" +0ms
engine.io-client:socket setting transport websocket +9ms
socket.io-client:manager connect attempt will timeout after 20000 +9ms
socket.io-client:manager readyState opening +1ms
engine.io-client:socket socket receive: type "open", data "{"pingInterval":25000,"pingTimeout":60000,"upgrades":[],"sid":"62a39d6f0151427dabbca605820dc89b"}" +7s
engine.io-client:socket socket open +1ms
socket.io-client:manager open +7s
socket.io-client:manager cleanup +0ms
socket.io-client:socket transport is open - connecting +0ms
engine.io-client:socket socket receive: type "message", data "2["my response",{"data":"Connected"}]" +1ms
socket.io-parser decoded 2["my response",{"data":"Connected"}] as {"type":2,"nsp":"/","data":["my response",{"data":"Connected"}]} +0ms
socket.io-client:socket emitting event ["my response",{"data":"Connected"}] +2ms
engine.io-client:socket socket receive: type "message", data "0" +1ms
socket.io-parser decoded 0 as {"type":0,"nsp":"/"} +0ms
client Connected to server
socket.io-client:manager writing packet {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} +3ms
socket.io-parser encoding packet {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} +2ms
socket.io-parser encoded {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} as 2["NewCustomerRegister"] +0ms
engine.io-client:socket flushing 1 packets in socket +2ms
{ data: 'Connected' }
my response
engine.io-client:socket socket receive: type "message", data "2["newBankId",{"id":"120"}]" +714ms
socket.io-parser decoded 2["newBankId",{"id":"120"}] as {"type":2,"nsp":"/","data":["newBankId",{"id":"120"}]} +714ms
socket.io-client:socket emitting event ["newBankId",{"id":"120"}] +716ms
HERE
{ id: '120' }

Logs when that's not work :

socket.io-client:url parse http://localhost:8080 +0ms
socket.io-client new io instance for http://localhost:8080 +0ms
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "websocket" +0ms
engine.io-client:socket setting transport websocket +8ms
socket.io-client:manager connect attempt will timeout after 20000 +9ms
socket.io-client:manager readyState opening +1ms
engine.io-client:socket socket error {"type":"TransportError","description":{"target":{"_events":{},"_eventsCount":4,"readyState":2,"protocol":"","_binaryType":"arraybuffer","_closeFrameReceived":false,"_closeFrameSent":false,"_closeMessage":"","_closeTimer":null,"_closeCode":1006,"_extensions":{},"_isServer":false,"_receiver":null,"_sender":null,"_socket":null,"url":"ws://localhost:8080/socket.io/?EIO=3&transport=websocket","_req":null},"type":"error","message":"connect ECONNREFUSED 127.0.0.1:8080","error":{"errno":"ECONNREFUSED","code":"ECONNREFUSED","syscall":"connect","address":"127.0.0.1","port":8080}}} +5ms
socket.io-client:manager connect_error +4ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager will wait 754ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +2ms
socket.io-client:manager attempting reconnect +756ms
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +755ms
engine.io-client:polling polling +0ms
engine.io-client:polling-xhr xhr poll +0ms
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWSLo&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +1ms
engine.io-client:socket setting transport polling +4ms
socket.io-client:manager connect attempt will timeout after 20000 +4ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +2ms
socket.io-client:manager connect_error +2ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 2745ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +1ms
engine.io-client:polling transport not open - deferring close +6ms
socket.io-client:manager attempting reconnect +3s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +3s
engine.io-client:polling polling +3s
engine.io-client:polling-xhr xhr poll +3s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWT0r&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +2ms
socket.io-client:manager connect attempt will timeout after 20000 +3ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +2ms
socket.io-client:manager connect_error +1ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 2219ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +1ms
engine.io-client:polling transport not open - deferring close +4ms
socket.io-client:manager attempting reconnect +2s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +2s
engine.io-client:polling polling +2s
engine.io-client:polling-xhr xhr poll +2s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWTZb&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +1ms
socket.io-client:manager connect attempt will timeout after 20000 +1ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +2ms
socket.io-client:manager connect_error +2ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +0ms
engine.io-client:polling transport not open - deferring close +2ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +1ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWUnp&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +0ms
socket.io-client:manager connect attempt will timeout after 20000 +0ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +2ms
socket.io-client:manager connect_error +2ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +0ms
engine.io-client:polling transport not open - deferring close +2ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWV__&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +1ms
socket.io-client:manager connect attempt will timeout after 20000 +1ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +2ms
socket.io-client:manager connect_error +2ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +0ms
engine.io-client:polling transport not open - deferring close +2ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +1ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWXEF&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +0ms
socket.io-client:manager connect attempt will timeout after 20000 +1ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +1ms
socket.io-client:manager connect_error +0ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +0ms
engine.io-client:polling transport not open - deferring close +1ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +1ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWYSU&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +0ms
socket.io-client:manager connect attempt will timeout after 20000 +0ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +1ms
socket.io-client:manager connect_error +1ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +1ms
engine.io-client:polling transport not open - deferring close +2ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWZgj&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +1ms
socket.io-client:manager connect attempt will timeout after 20000 +1ms
engine.io-client:socket socket error {"type":"TransportError","description":503} +1ms
socket.io-client:manager connect_error +1ms
socket.io-client:manager cleanup +0ms
socket.io-client:manager reconnect attempt error +0ms
socket.io-client:manager will wait 5000ms before reconnect attempt +0ms
engine.io-client:socket socket close with reason: "transport error" +0ms
engine.io-client:polling transport not open - deferring close +3ms
socket.io-client:manager attempting reconnect +5s
socket.io-client:manager readyState closed +0ms
socket.io-client:manager opening http://localhost:8080 +0ms
engine.io-client:socket creating transport "polling" +5s
engine.io-client:polling polling +5s
engine.io-client:polling-xhr xhr poll +5s
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWauz&b64=1 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket setting transport polling +0ms
socket.io-client:manager connect attempt will timeout after 20000 +0ms
engine.io-client:polling polling got data 109:0{"sid":"a3d46685bc1d4051a8f4a86d243bfbd0","pingInterval":25000,"pingTimeout":60000,"upgrades":["websocket"]}38:42["my response",{"data":"Connected"}]2:40 +8s
engine.io-client:socket socket receive: type "open", data "{"sid":"a3d46685bc1d4051a8f4a86d243bfbd0","pingInterval":25000,"pingTimeout":60000,"upgrades":["websocket"]}" +8s
engine.io-client:socket socket open +1ms
socket.io-client:manager open +8s
socket.io-client:manager cleanup +0ms
socket.io-client:socket transport is open - connecting +0ms
socket.io-client:manager reconnect success +0ms
engine.io-client:socket starting upgrade probes +1ms
engine.io-client:socket probing transport "websocket" +1ms
engine.io-client:socket creating transport "websocket" +0ms
engine.io-client:socket socket receive: type "message", data "2["my response",{"data":"Connected"}]" +1ms
socket.io-parser decoded 2["my response",{"data":"Connected"}] as {"type":2,"nsp":"/","data":["my response",{"data":"Connected"}]} +0ms
socket.io-client:socket emitting event ["my response",{"data":"Connected"}] +4ms
engine.io-client:socket socket receive: type "message", data "0" +2ms
socket.io-parser decoded 0 as {"type":0,"nsp":"/"} +1ms
client Connected to server
socket.io-client:manager writing packet {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} +5ms
socket.io-parser encoding packet {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} +1ms
socket.io-parser encoded {"type":2,"data":["NewCustomerRegister"],"options":{"compress":true},"nsp":"/"} as 2["NewCustomerRegister"] +1ms
engine.io-client:socket flushing 1 packets in socket +2ms
engine.io-client:polling-xhr xhr open POST: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWcun&b64=1&sid=a3d46685bc1d4051a8f4a86d243bfbd0 +8s
engine.io-client:polling-xhr xhr data 25:42["NewCustomerRegister"] +0ms
{ data: 'Connected' }
my response
engine.io-client:polling polling +12ms
engine.io-client:polling-xhr xhr poll +3ms
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWcuq&b64=1&sid=a3d46685bc1d4051a8f4a86d243bfbd0 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket probe transport "websocket" opened +8ms
engine.io-client:polling polling got data 1:6 +704ms
engine.io-client:socket socket receive: type "noop", data "undefined" +700ms
engine.io-client:polling polling +0ms
engine.io-client:polling-xhr xhr poll +704ms
engine.io-client:polling-xhr xhr open GET: http://localhost:8080/socket.io/?EIO=3&transport=polling&t=MbMWd3q&b64=1&sid=a3d46685bc1d4051a8f4a86d243bfbd0 +0ms
engine.io-client:polling-xhr xhr data null +0ms
engine.io-client:socket probe transport "websocket" pong +2ms
engine.io-client:socket pausing current transport "polling" +0ms
engine.io-client:polling we are currently polling - waiting to pause +2ms
engine.io-client:socket writing ping packet - expecting pong within 60000ms +24s

[miguelgrinberg]

And why are you starting the client before the server? The server is supposed to be running all the time right?

[Laoup]

Yeah, for sure ^^.

It's also sure, that's more logical to start server before client.
But when i was coding them, when i tried them, basically i was not paying attention to that and launched the two (server & client) same time, sometime server before, sometime after probably.

So.. it's working for the moment.
Thanks for your help !

I close the ticket, i open a new one if something going wrong.