IRC Drops out with no message and then won't reconnect

[sigmantium]

Bot seems to work fine for about a day and then drops off the IRC server.
People have reported the quit message as "connection reset by peer".
In the node console there is no mention of a disconnect or an attempt to reconnect.
After this if i shut down the bot and start it again i get the message "Non-latest connection is being discarded, not reconnected"
I've turned on the debugging and the dev environment and it doesn't show any information about the IRC connection other than that above message. There is a bit of information about the discord connection but nothing for IRC.

After rebooting the PC as a seems to fix it.

Running on Windows Server 2012r2 x64
Node.js v8.1.3

[Throne3d]

… Huh. The above message should occur when the connection resets but the old connection is trying to reconnect erroneously (erroneously because that causes duplicate connections – only the most recent connection should connect). I don't think it is (or at least it shouldn't be) problematic itself.

When you say you've enabled debugging and dev, do you mean putting debug: true into ircOptions and adding NODE_ENV=development as an environment variable? (I'm not super sure how to do that on Windows.) If so, is there any content around the time about a ping timeout, or some sort of error event from the server…? (And even if not, can you still paste some stuff from around the time, in case there's something to be seen?)

[sigmantium]

This is the first time its failed since i've had the debug running. I get the following code:

`10 Jul 06:43:24 - Non-latest connection is being discarded, not reconnected
c:\discord-irc\node_modules\discord.js\src\client\Client.js:422
fn();
^

TypeError: fn is not a function
at Timeout.setTimeout [as _onTimeout] (c:\discord-irc\node_modules\discord.j
s\src\client\Client.js:422:7)
at ontimeout (timers.js:488:11)
at tryOnTimeout (timers.js:323:5)
at Timer.listOnTimeout (timers.js:283:5)
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! discord-irc@2.4.0 start: node dist/index.js "discord-irc" "--config" " config.json"
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the discord-irc@2.4.0 start script.
npm ERR! This is probably not a problem with npm. There is likely additional log
ging output above.

npm ERR! A complete log of this run can be found in:
npm ERR! C:\Users\sysadmin\AppData\Roaming\npm-cache_logs\2017-07-09T22_47_
45_545Z-debug.log
`
but this might not be related as the actual app crashed where as in the past the app hasn't crashed its kept running just with no IRC connection.

[Throne3d]

That error looks like it's from and wholly contained in the discord.js module, and as you mentioned this 13 hours ago and Discord experienced a server outage about 14 hours ago, I'd expect it to be related to that instead.

[ensiform]

While I don't have log data to verify or know if its related at all, I can definitely confirm that the IRC side of things (at least as of the first commit switching to irc-upd) definitely still has a lot of issues where the IRC side just drops off but still relays information to discord from IRC or just stops all together. I have seen these behaviors in several different irc servers/channels that are using this particular bot.

If you have any ways to generate some info for this, please let me know and I can pass it on to some folks who have it happen more frequently.

Edit: I actually just saw this right now in my git bash shell from earlier today:
11 Jul 12:58:07 - Non-latest connection is being discarded, not reconnected

[sigmantium]

I seem to have some fairly good consistency now that i have rebooted my server.
I'm wondering if its related to the server not having been rebooted since i'd installed node.js

If the issue happens again i'm happy to submit more logs and data.

[Throne3d]

Agh, I'm pretty sure the Non-latest connection is being discarded, not reconnected thing is normal and is an indicator of the upstream library doing something approximately normal in its operation. (It resolves an issue I encountered while trying the library out, which had it sometimes connect twice or more.) I'm probably gonna make it into a debug message instead of an info one because people report it like it's unexpected, which is probably fair, since it looks slightly scary, but it shouldn't affect normal use and so should be debug.

I am pretty sure the IRC side is not the issue when "the IRC side just drops off but still relays information" – if I recall correctly I investigated a little and discord.js was failing to trigger the events for the discord-irc bot and then that means the IRC library doesn't get the relevant information, but I don't remember how I decided this so I might be wrong.

To generate more info, as I said above you should be able to set the environment variable NODE_ENV to development (if you're in a bash shell, prefix your command with NODE_ENV=development, like: NODE_ENV=development npm start -- --config conf.json). You should also add debug: true to the ircOptions object in the config (this it says in the README). There is not to my knowledge any way to generate further information but really that should give most of the information? (I guess you could go adding a logger on the raw event from irc-upd in discord-irc but that requires you modify the code slightly. Something like this.ircClient.on('raw', (message) => console.log(message)); would do this?)

I'm not sure why it would be affected by rebooting after installing node.js or not, but I guess Windows can handle things weirdly around installation.

[microburst]

I've been having a similar issue recently with discord-irc. At seemingly random, it will disconnect from IRC. The node process remains active, and will continue to receive information from and ping Discord, but will completely disconnect from IRC and not attempt a reconnect.

I was seeing the same error that @sigmantium and @ensiform listed above:

11 Jul 12:58:07 - Non-latest connection is being discarded, not reconnected

I ran discord-irc in debug mode in the node development environment as suggested, and waited for a DC. It returned this:

CyclingPingTimer 0: server silent for too long, let's send a PING
15 Jul 16:49:41 - SEND: PING 67
debug: Received debug event from Discord [ws] [connection] Sending a heartbeat
debug: Received debug event from Discord [ws] [connection] Heartbeat acknowledged, latency of 88ms
CyclingPingTimer 0: server silent for too long, let's send a PING
15 Jul 16:50:02 - SEND: PING 68
CyclingPingTimer 0: ping timeout!
15 Jul 16:50:09 - Connection got "close" event
15 Jul 16:50:09 - Non-latest connection is being discarded, not reconnected
debug: Received debug event from Discord [ws] [connection] Sending a heartbeat
debug: Received debug event from Discord [ws] [connection] Heartbeat acknowledged, latency of 40ms

So everything was fine, but then a single ping timed out, and the connection was closed. Then, we see the same error as listed above, and the bot doesn't try and reconnect. Its connection with Discord, however, was fine and it continued to send heartbeats.

Any suggestions as to what could be going on here or how to potentially fix? It happens consistently, sometimes within a few minutes after launching discord-irc, and sometimes up to an hour. I have the config setup to autoreconnect, but after shooting the "not reconnected" error, it seems to not even try. Seems like it shouldn't be disconnecting from the IRC server that often anyway.

[Throne3d]

So, the "not reconnected" notification should only appear when it's not reconnecting the old connection – it should only ever pop this up when there's a newer connection, which is trying to connect, and the old one is then getting discarded.

That looks like it's for some reason not connecting a second time, despite the old connection being marked as old, which really… shouldn't occur? I'm not sure what's up with that.

Possibly relatedly: before the recent changes, did you ever encounter times where the bot reconnected and then failed to mirror messages between Discord and IRC properly? (One-sided – it would transmit to Discord properly, but not transmit to IRC properly.) If so, I have a feeling this is related to that.

Edit: So I just realized I might be able to reproduce this myself by disabling my internet connection while the bot is running. Uh. I'll go do that and see if I can fix it. Oops.

[microburst]

Yes, I have had that happen before a few times, I believe before updating to the newest release?

[Throne3d]

… Whoops. I did not realize the issue would get closed if I did a commit in another repository. (Reopening until this version is actually published and used.)