Problem with disconnect - "client error"

[JaroslavKrenar]

Hello,

There is something wrong if connection is closed with reason "client error".

Debug on server side:

socket.io:client client close with reason client error +5s
socket.io:socket closing socket - reason client error +0ms

and only event 'disconnect' is called on server side with reason "client error"

Debug on client side:

log is empty and none event is called on client side ("error", "disconnect" etc...). Client seems to be connected without problem, but only one way communication is working - from client to server. Server is able to receive messages from client, but client receives nothing.

We are using a latest version 1.4.6.

[contrasam]

I had the same issue with v1.4.6, so I rolled back to v1.4.5 in my code, I guess thew new version has some breaking changes

[borisovg]

I have also hit this issue - the client doesn't get the memo that connection is supposed to be closed.

Version is 1.4.8

Code to reproduce:

var i = 0,
    port = 11111,
    server = require('socket.io')(port),
    client = require('socket.io-client')('http://localhost:' + port);

server.on('connect', function (socket) {
    console.log('SERVER :: connect');

    socket.on('error', function () {
        console.log('SERVER :: error');
    });

    socket.on('reconnect', function () {
        console.log('SERVER :: reconnect');
    });

    socket.on('disconnect', function () {
        console.log('SERVER :: disconnect');
    });

    socket.on('/ping', function (i) {
        console.log('SERVER :: ping ' + i);

        if (i > 2) {
            throw 'Spanner';
        }

        socket.emit('/pong', i);
    });
});

client.on('connect', function () {
    console.log('CLIENT :: connect');
});

client.on('error', function (err) {
    console.log('CLIENT :: error');
    console.log(err.code, 'in the works');
});

client.on('reconnect', function () {
    console.log('CLIENT :: reconnect');
});

client.on('disconnect', function () {
    console.log('CLIENT :: disconnect');
});

client.on('/pong', function (i) {
    console.log('CLIENT :: pong ' + i);
});

setInterval(function () {
    console.log('CLIENT :: socket.connected is ' + client.connected);
    client.emit('/ping', i);
    i += 1;
}, 1000);

Relevant log file portion:

[...]
CLIENT :: socket.connected is true
Fri, 16 Sep 2016 11:37:33 GMT socket.io-client:manager writing packet {"type":2,"data":["/ping",3],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:33 GMT socket.io-parser encoding packet {"type":2,"data":["/ping",3],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:33 GMT socket.io-parser encoded {"type":2,"data":["/ping",3],"options":{"compress":true},"nsp":"/"} as 2["/ping",3]
Fri, 16 Sep 2016 11:37:33 GMT engine.io-client:socket flushing 1 packets in socket
Fri, 16 Sep 2016 11:37:33 GMT engine:ws received "42["/ping",3]"
Fri, 16 Sep 2016 11:37:33 GMT engine:socket packet
Fri, 16 Sep 2016 11:37:33 GMT socket.io-parser decoded 2["/ping",3] as {"type":2,"nsp":"/","data":["/ping",3]}
Fri, 16 Sep 2016 11:37:33 GMT socket.io:socket got packet {"type":2,"nsp":"/","data":["/ping",3]}
Fri, 16 Sep 2016 11:37:33 GMT socket.io:socket emitting event ["/ping",3]
SERVER :: ping 3
SERVER :: error
Fri, 16 Sep 2016 11:37:33 GMT socket.io:client client close with reason client error
Fri, 16 Sep 2016 11:37:33 GMT socket.io:socket closing socket - reason client error
SERVER :: disconnect
CLIENT :: socket.connected is true
Fri, 16 Sep 2016 11:37:34 GMT socket.io-client:manager writing packet {"type":2,"data":["/ping",4],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:34 GMT socket.io-parser encoding packet {"type":2,"data":["/ping",4],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:34 GMT socket.io-parser encoded {"type":2,"data":["/ping",4],"options":{"compress":true},"nsp":"/"} as 2["/ping",4]
Fri, 16 Sep 2016 11:37:34 GMT engine.io-client:socket flushing 1 packets in socket
Fri, 16 Sep 2016 11:37:34 GMT engine:ws received "42["/ping",4]"
Fri, 16 Sep 2016 11:37:34 GMT engine:socket packet
CLIENT :: socket.connected is true
Fri, 16 Sep 2016 11:37:35 GMT socket.io-client:manager writing packet {"type":2,"data":["/ping",5],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:35 GMT socket.io-parser encoding packet {"type":2,"data":["/ping",5],"options":{"compress":true},"nsp":"/"}
Fri, 16 Sep 2016 11:37:35 GMT socket.io-parser encoded {"type":2,"data":["/ping",5],"options":{"compress":true},"nsp":"/"} as 2["/ping",5]
Fri, 16 Sep 2016 11:37:35 GMT engine.io-client:socket flushing 1 packets in socket
Fri, 16 Sep 2016 11:37:35 GMT engine:ws received "42["/ping",5]"
Fri, 16 Sep 2016 11:37:35 GMT engine:socket packet
[...]

[borisovg]

So I have done some digging.

The repro code above depends on fix for #1880 (introduced in v1.2.1) which adds a try/catch block whereas before the app would crash. This was not a good idea IMO as it hides unexpected exceptions in user code (expected exceptions are for the user to handle).

Trigger condition aside, the real issue seems to be that neither Socket.disconnect(), nor Socket.close() is ever called during the error handling process. I suspect this code never worked before, just that it was never triggered.

[darrachequesne]

That issue was closed automatically. Please check if your issue is fixed with the latest release, and reopen if needed (with a fiddle reproducing the issue if possible).