socket Error: EPIPE, Broken pipe when closing many clients at once

[tommedema]

When I have a socket.io server running, and then open 1 chrome browser window with 10 tabs to this server, there are 10 connected sockets.

If I then close the window at once, about 4 socket disconnections are correctly displayed on the server side, but then I get the following exception:

DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)
DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at SocketNamespace.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:188:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:35:26)
    at Client.get (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/stores/memory.js:86:3)

Most interestingly of course is clients.js:35:26. This is the corresponding function:

/* when client unregisters */
mediator.on('csio.client.unregistered', function _informClients(csio, socket) {

    /* inform other clients that this client unregistered */
    socket.get('id', function _emitUnreg(err, id) {
        if (err || !id) return mediator.emit('csio.clients.error', 'unreg cannot get id, err: ' + err);

        /* client unregistered */
        if (socket.connected) {
            socket.broadcast.emit('clients.unregistered', id);
        }
        else {
            csio.sockets.emit('clients.unregistered', id); //THIS IS LINE 35
        }
    });
});

I believe that csio.sockets.emit attempts to emit to disconnected (or maybe better: disconnecting) clients. Apparently, because so many clients disconnect at once, things go very wrong here.

This seems like a bug to me. What do you folks think?

[tommedema]

I just realized that I should check for !socket.disconnected rather than socket.connected. However, since io.sockets.emit should always work when this client is not connected, the issue remains (since this call is causing the exception).

For accuracy, I have updated the code to the following:

mediator.on('csio.client.unregistered', function _informClients(csio, socket) {

    /* inform other clients that this client unregistered */
    socket.get('id', function _emitUnreg(err, id) {
        if (err || !id) return mediator.emit('csio.clients.error', 'unreg cannot get id, err: ' + err);

        /* client unregistered */
        if (!socket.disconnected) {
            socket.broadcast.emit('clients.unregistered', id);
        }
        else {
            csio.sockets.emit('clients.unregistered', id);
        }
    });
});

This results in the following exception:

DEBUG: a client emitted an exception: { stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'EPIPE, Broken pipe',
  errno: 32,
  code: 'EPIPE',
  syscall: 'write' }
   info  - socket error Error: EPIPE, Broken pipe
    at Socket._writeImpl (net.js:159:14)
    at Socket._writeOut (net.js:450:25)
    at Socket.write (net.js:377:17)
    at WebSocket.write (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transports/websocket.js:184:23)
    at WebSocket.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/transport.js:222:10)
    at Manager.onDispatch (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/manager.js:342:31)
    at SocketNamespace.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/namespace.js:156:16)
    at Socket.packet (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/socket.js:192:56)
    at Socket.emit (/media/sda3/Workspaces/Node.js/Project/node_modules/socket.io/lib/socket.js:344:15)
    at _emitUnreg (/media/sda3/Workspaces/Node.js/Project/src2/routines/csio/clientinfo/clients.js:32:30)

Repeated 6 times again.

Line 32 is the emit in:

    if (!socket.disconnected) {
        socket.broadcast.emit('clients.unregistered', id);
    }

So, this seems related: when the socket is busy disconnecting, the flag is not yet set to disconnected, but the socket is already broken. So this causes an exception.

Does seem to be a bug.

[tommedema]

Hah! This might not (or may) be a bug.

This was (partly?) the result of a very tricky event loop mechanism. Consider my disconnection code:

/* on disconnect */
    socket.on('disconnect', function _fireDisconnect() {

    /* client disconnected */
    mediator.emit('csio.client.disconnected', csio, socket);
});

The unregister event reacts to this disconnected event emitted by mediator. It appears that disconnection has not finished when the socket.disconnect event is called (hmm, maybe that is a bug?). Thus, I have to continue execution when the at the end of the event loop. The following code makes it function properly:

/* on disconnect */
    socket.on('disconnect', function _fireDisconnect() {

    /* client disconnected */
    process.nextTick(function() {
        mediator.emit('csio.client.disconnected', csio, socket);
    });
});

Notice the process.nextTick.

I am closing this issue, although I have a feeling that the fact that the disconnected flag is not yet set to true while inside the event callback may be a bug. Not sure though.

I have a feeling you fire the .disconnect event before the socket cleanup logic has been executed.