martynsmith / node-irc

NodeJS IRC client library
GNU General Public License v3.0
1.33k stars 424 forks source link

Ping timeout causes double reconnect #449

Closed FruitieX closed 8 years ago

FruitieX commented 8 years ago

I'm testing in the latest master branch (8e056224cc984b1ebb91ef60ed5c4f18a547270b), after the #418 PR merge.

There seems to be a problem with reconnects after a ping timeout, which results in the library sometimes opening up multiple simultaneous connections to the IRC server.

Here's an easy way to reproduce the issue. I'm using the following simple program:

var IRC = require('irc');

var irc = new IRC.Client('irc.cs.hut.fi', 'nodeirctest', { // replaceme
    userName: 'bot',
    debug: true,
    autoConnect: true,
    channels: ['#nodeirctest'] // replaceme
});

irc.on('error', function(error) {
    console.error('IRC ERROR:');
    console.error(error);
});

irc.on('message', function(user, chanName, message) {
    console.log('MESSAGE: ', user, chanName, message);
});

irc.on('raw', function(command) {
    console.log('RAW: ', command);
});

After running this program, letting it connect to the network, try to disconnect your machine from the network. Wait until node-irc detects a ping timeout and starts reconnecting. I'm getting the following console output:

CyclingPingTimer 0: server silent for too long, let's send a PING
29 Feb 12:50:29 - SEND: PING 18
CyclingPingTimer 0: ping timeout!                // everything is OK up to this point!
29 Feb 12:50:37 - Connection got "close" event
29 Feb 12:50:37 - Disconnected: reconnecting
29 Feb 12:50:37 - Waiting 2000ms before retrying
29 Feb 12:50:37 - Connection got "close" event
29 Feb 12:50:37 - Disconnected: reconnecting
29 Feb 12:50:37 - Waiting 2000ms before retrying
29 Feb 12:50:39 - Network error: Error: getaddrinfo ENOTFOUND irc.cs.hut.fi irc.cs.hut.fi:6667
29 Feb 12:50:39 - Connection got "close" event
29 Feb 12:50:39 - Disconnected: reconnecting
29 Feb 12:50:39 - Waiting 2000ms before retrying
29 Feb 12:50:39 - Connection got "close" event
29 Feb 12:50:39 - Disconnected: reconnecting
29 Feb 12:50:39 - Waiting 2000ms before retrying

Notice how at the exact same time all the events are duplicated. If I now connect the machine to the network and let node-irc perform a reconnect, eventually two bots will show up on my channel. Perform a few more disconnect cycles and even more may show up. All of these duplicated instances will receive events such as on 'message', so try sending a message on the channel and it should be printed out multiple times.

jirwin commented 8 years ago

I've noticed this as well, which is why I haven't published the release containing the new feature. Sadly I haven't had time to dig into it yet.

Hoping I'll be able to take a closer look this weekend.

Thanks for the report.

jirwin commented 8 years ago

@FruitieX can you take a look at #452 and give it a try. In my tests locally it seems to have fixed the issue. I'll be running that version on my bot as well to see if it works out.

Thanks!

jirwin commented 8 years ago

Fixed in #452