Socket IO not properly closing connection

Question

I'm tailing a log file and stream the new lines to a websocket.

Since I have multiple logs, I let the user choose the log file and then get the details of that log.

The problem is that when I close a connection in order to see a different log, the connection does something weird, that when I start it again, it streams the data twice. If I close the connection and re-open it again, it streams 3 times the data, so on and so forth.

My package.json:

{
    "socket.io": "^2.0.3",
    "socket.io-client": "^2.0.3"
}

Client side

$("#detailsBtn").click(function (e) {
    e.preventDefault();
    $.get('/get/details', {
        // some-data
    }, () => {
        if (socket) socket.close();
        socket = io('http://localhost:4000', {forceNew: true});
        socket.on('connect', () => {
            console.log('connected');
        });
        socket.on('newLine', function (msg) {
            // do-stuff
        });
    });
});
$('#closeBtn').click(function () {
    socket.disconnect();
    socket.close();
});

Server side

app.get('/details', (req, res) => {
    const tail = spawn('ssh', ['root@' + req.query.srv, req.query.script]);
    io.on('connection', function (socket) {
        console.log(`connect ${socket.id}`);
        socket.on('disconnect', () => {
            console.log(`DISconnected ${socket.id}`);
        });
        tail.stdout.on('data', function (data) {
            socket.emit('newLine', {message: data});
        });
    });
    return res.sendStatus(200);
});

Now when simulating the button click, I expect the socket and connection to be closed, in order to make a new one.

Server console log (each time I click the button only once)

Server listening on localhost:4000

**click on detailsBtn**
GET /get/details?srv=myserver.google.com&script=%2Fusr%2Fbin%2Ftail 304 16.003 ms - -
connect YyYHFI9CARpBHaxoAAAB
**click on closeBtn**
DISconnected YyYHFI9CARpBHaxoAAAB

**click on detailsBtn**
GET /get/details?srv=myserver.google.com&script=%2Fusr%2Fbin%2Ftail 304 6.308 ms - -
connect vzfBnUPHUqYXd5qaAAAC
connect vzfBnUPHUqYXd5qaAAAC
**click on closeBtn**
DISconnected vzfBnUPHUqYXd5qaAAAC
DISconnected vzfBnUPHUqYXd5qaAAAC

**click on detailsBtn**
GET /get/details?srv=myserver.google.com&script=%2Fusr%2Fbin%2Ftail 304 4.677 ms - -
connect 3quEe5G1gFDJ2BvrAAAD
connect 3quEe5G1gFDJ2BvrAAAD
connect 3quEe5G1gFDJ2BvrAAAD
**click on closeBtn**
DISconnected 3quEe5G1gFDJ2BvrAAAD
DISconnected 3quEe5G1gFDJ2BvrAAAD
DISconnected 3quEe5G1gFDJ2BvrAAAD

What am I doing wrong?

Answer 1

So the comments here directed me to the solution.

I had duplicate event handlers for both the socket and the tail.

I called the initiation of the connection each time a user clicked the button, and I spawned a tail child process each time the URL was accessed Here is how I fixed it:

Socket

1.Moved the io.on('connection'...) outside of the app.get handler as suggested by @alex-rokabilis

2.Created an event emmiter of my own:

const events = require('events');
const eventEmitter = new events.EventEmitter();

3.Inside io.on('connection'...), instead of listening to tail.stdout event, I listened to my eventEmitter event in order to be able to use the tail outside of the app.get handler

io.on('connection', function (socket) {
    eventEmitter.on('newLine', (data) => {
        socket.emit('newLine', {line: data});
    });
});

4.In the app.get handler, I listen to tail.stdout.on('data'... and send an eventEmitter event that would be handled inside the io object:

app.get('/details', (req, res) => {
    let tail = spawn('ssh', ['root@' + req.query.srv, req.query.script]);
    tail.stdout.on('data', (data) => {
        eventEmitter.emit('newLine', data.toString().replace(/\n/g, '<br />'));
    });
});

5.On client, I moved the io initialization outside of the ajax call, defined socket in a way I could use further in the script.

let socket = io('http://localhost:4000', {forceNew: true});
socket.on('connect', () => {
    console.log('connected');
});
socket.on('newLine', function (msg) {
    // do-stuff
});

$("#detailsBtn").click(function (e) {
    e.preventDefault();
    $.get('/get/details', {
        // some-data
    });
});

Tail

This was a bit hard to find, I always thought the problem is with the socket-io rather than the tail.

Inside io.on('connection'..., I added a socket listener for an event named closeConnection that emits closeConnection to my eventEmitter, that in turn kills the tail child process:

io.on('connection', function (socket) {
    eventEmitter.on('newLine', (data) => {
        socket.emit('newLine', {line: data});
    });
    socket.on('closeConnection', () =>{
        console.log('got connection close from client');
        eventEmitter.emit('closeConnection');
    });
});

And inside the app.get controller:

app.get('/details', (req, res) => {
    let tail = spawn('ssh', ['root@' + req.query.srv, req.query.script]);
    tail.stdout.on('data', (data) => {
        eventEmitter.emit('newLine', data.toString().replace(/\n/g, '<br />'));
    });
    eventEmitter.on('closeConnection', () => {
        tail.stdin.pause();
        tail.kill();
    });
});

And in the client, each time I want to close the connection, I just:

socket.emit('closeConnection');

That was tough.

Answer 2

As you see in the console logs, the connect and disconnect shows the same socketID. This indicates that the event handler is triggered many times. From your code you define a new event handler for 'connection' every time the '/details' route is getting a request. So a better aproach would be...

io.on('connection', function (socket) {
    console.log(`connect ${socket.id}`);
    socket.on('disconnect', () => {
        console.log(`DISconnected ${socket.id}`);
    });
    tail.stdout.on('data', function (data) {
        socket.emit('newLine', {message: data});
    });
});
app.get('/details', (req, res) => {
   const tail = spawn('ssh', ['root@' + req.query.srv, req.query.script]);
   return res.sendStatus(200);
});