Race condition results in orphaned server connection

[jamesshore]

Note: for support questions, please use one of these channels: stackoverflow or slack

You want to:

• report a bug
• request a feature

Current behaviour

When connecting to a Socket.IO server, if the connection is closed on the client after the connection is formed on the server, but before the client connect event occurs, the connection will not be closed. However, the client will treat the connection as closed.

Order of operations:

1. Client initiates connection to server
2. Server fires connect event
3. Client runs socket.disconnect()
4. Race condition Server never fires disconnect event; connection is not closed

Steps to reproduce (if the current behaviour is a bug)

Run the following Node.js code:

(function() {
	"use strict";

	var clientIo = require("socket.io-client");
	var http = require("http");
	var io = require("socket.io");

	var httpServer;
	var ioServer;

	var PORT = 5020;

	startServer(function() {
		console.log("SERVER STARTED");

		var connections = {};
		logAndTrackServerConnections(connections);

		console.log("** connecting client");
		var client = clientIo("http://localhost:" + PORT);
		logClientConnections(client);

		ioServer.once("connect", function() {
			console.log("** disconnecting client");
			client.disconnect();
			console.log("** waiting for server to disconnect");
			setTimeout(function() {
				console.log("#### Does the client think it's connected? (Expect 'false'):", client.connected);
				console.log("#### How many connections does the server have? (Expect 0):", numberOfServerConnections(connections));
				stopServer(function() {
					console.log("** end of test")
				});
			}, 500);
		});
	});

	function logAndTrackServerConnections(connections) {
		ioServer.on("connect", function(socket) {
			var key = socket.id;
			console.log("SERVER CONNECTED", key);
			connections[key] = socket;
			socket.on("disconnect", function() {
				console.log("SERVER DISCONNECTED", key);
				delete connections[key];
			});
		});
	}

	function logClientConnections(socket) {
		var id;
		socket.on("connect", function() {
			id = socket.id;
			console.log("CLIENT CONNECTED", id);
		});
		socket.on("disconnect", function() {
			console.log("CLIENT DISCONNECTED", id);
		});
	}

	function numberOfServerConnections(connections) {
		return Object.keys(connections).length;
	}

	function startServer(callback) {
		console.log("** starting server");
		httpServer = http.createServer();
		ioServer = io(httpServer);
		httpServer.listen(PORT, callback);
	};

	function stopServer(callback) {
		console.log("** stopping server");

		httpServer.on("close", function() {
			console.log("SERVER CLOSED");
			callback();
		});

		ioServer.close();
	};

}());

Example Output:

** starting server
SERVER STARTED
** connecting client
SERVER CONNECTED V86aaI4HQtgGyIZTAAAA
** disconnecting client
** waiting for server to disconnect
#### Does the client think it's connected? (Expect 'false'): false
#### How many connections does the server have? (Expect 0): 1
** stopping server
SERVER DISCONNECTED V86aaI4HQtgGyIZTAAAA
SERVER CLOSED
** end of test

Expected behaviour

The disconnect event should fire on the server and the connection should be closed.

Expected order of operations:

1. Client initiates connection to server
2. Server fires connect event
3. Client runs socket.disconnect()
4. Conection is closed and server fires disconnect event

Expected output from above test case:

** starting server
SERVER STARTED
** connecting client
SERVER CONNECTED cdQ_aBq7SGN3SEveAAAA
** disconnecting client
** waiting for server to disconnect
SERVER DISCONNECTED cdQ_aBq7SGN3SEveAAAA
#### Does the client think it's connected? (Expect 'false'): false
#### How many connections does the server have? (Expect 0): 0
** stopping server
SERVER CLOSED
** end of test

Setup

• OS: MacOS 10.11.6
• browser: n/a
• Node.js: v7.10.0
• socket.io version: 2.0.1

Other information (e.g. stacktraces, related issues, suggestions how to fix)

This issue is very timing sensitive, but it can occur in production depending on how loaded the event loop is. The above test case seems to reliably and deterministicly reproduce the issue.

[darrachequesne]

@jamesshore thanks for the great details, and the way to reproduce 👍

Actually I'm not sure that there is a race condition here. I think what happens is that, when socket.disconnect() gets called the current transport is polling, so closing a polling transport means stopping sending requests (no disconnect packet, since the socket is not yet connected). In that case, the server will eventually notice that the client is gone with the heartbeat.

Example:

ioServer = io(httpServer, {
  pingTimeout: 1000,
  pingInterval: 2000
});
// should properly work with setTimout(/* */, 5000); 

Besides, if the websocket transport is established, the underlying TCP connection is closed so the server immediately knows that the client has left. You should be able to reproduce that behaviour with:

var client = clientIo("http://localhost:" + PORT, {
  transports: [ 'websocket' ]
});

[darrachequesne]

Closed due to inactivity, please reopen if needed.