Stopped relaying from irc->discord

[aleksandervines]

So, some time last night the relay suddenly stopped working in the direction from irc->discord.

I've only been running this bot since yesterday, so I don't know if this is going to happen again, but thought I should report it.

I'm running the bot with only one channelmapping. Neither channel is very active.

The bot gave no error or info messages. Is there perhaps a debug mode I can run it in to see what happens if it should happen again?

[Throne3d]

Huh. This looks… almost(?) like a dupe of #326, except in that case the bot only works IRC → Discord and not vice versa. That issue isn't solved yet but I had an idea for how it might be done which I haven't got around to implementing yet.

There is in fact a debug mode! It comes in two parts – you can add "debug": true to the ircOptions part of the config, which has the IRC side of things output more, and you can run it with the NODE_ENV=development environment variable, if you know how to do that, which will have the rest of the bot output more details; in Bash (on, say, Ubuntu) this is done with NODE_ENV=development npm start ….

I've been using the bot for a while, and used to encounter the issue from #326 quite often, but it seems to occur much less often in recent updates. It seems to happen more on a poor network connection.

[aleksandervines]

It happened again! And I've started it in debug mode now.

I've had the similar happen with a telegram-discord bot, but in the direction discord->telegram.

Btw, info on the setup: Linode vm CentOS 7 discord-irc git tag 2.3.0 npm 3.10.10 discord.js@11.0.0

[Throne3d]

There have been several updates since that version – we're now on v2.4.2 – so you might want to update.

Are you sure it was failing to mirror from IRC to Discord, and not the other way around? If the telegram-discord bot failed Discord → Telegram, I'd expect this one to fail Discord → IRC, not IRC → Discord (and that would make your issue a duplicate of #326).

[aleksandervines]

Haha. I was sure I had checked out the latest release. Will update to latest when I get home.

And yes, I am sure of the direction. I did not say there was any correlation to the other case, just gave it as a 'fun fact'.

[aleksandervines]

For the record, it just happened again, but I managed to screw up the output when I joined the session. So now I started it with logging to a file :)

[aleksandervines]

Went down twice, last time it was only up an hour or so :/ this is too unreliable for us to use atm :'(

The debug logs seems to show nothing special for me.

In this case the last message relayed from irc->discord was the **<Monroe|afk>** as requested #8.1 -> #8_1

I will see if I can add some more debug output after the "Sending message to Discord" part. For me it appears to not send much debug messages from the discord part?

discord->irc works nicely

I'm running it like this atm DATE=date +%Y-%m-%dT%H%M%S; NODE_ENV=development ; npm start -- --config ../config/8_1.json &> ../logs/${DATE}.log &

debug: Received debug event from Discord Sending heartbeat
debug: Received debug event from Discord Heartbeat acknowledged
debug: Channel Mapping #8_1
debug: Sending message to IRC #8.1 <03Aleks - 812E> which eta is that monroe
24 Oct 04:06:23 - SEND: PRIVMSG #8.1 :<03Aleks - 812E> which eta is that monroe
CyclingPingTimer 0: server silent for too long, let's send a PING
24 Oct 04:06:33 - SEND: PING 248
debug: Sending message to Discord **<Monroe|afk>** 5 #8.1 -> #8_1
debug: Sending message to Discord **<Monroe|afk>** as requested #8.1 -> #8_1
CyclingPingTimer 0: server silent for too long, let's send a PING
24 Oct 04:06:57 - SEND: PING 249
debug: Channel Mapping #8_1
debug: Sending message to IRC #8.1 <03Aleks - 812E> I meant the co you need
24 Oct 04:06:58 - SEND: PRIVMSG #8.1 :<03Aleks - 812E> I meant the co you need
debug: Received debug event from Discord Sending heartbeat
debug: Received debug event from Discord Heartbeat acknowledged
debug: Sending message to Discord **<Monroe|afk>** eta 6 atm #8.1 -> #8_1
debug: Sending message to Discord **<Monroe|afk>** anti CO :) #8.1 -> #8_1
CyclingPingTimer 0: server silent for too long, let's send a PING
24 Oct 04:07:26 - SEND: PING 250
CyclingPingTimer 0: server silent for too long, let's send a PING
24 Oct 04:07:42 - SEND: PING 251
debug: Received debug event from Discord Sending heartbeat
debug: Received debug event from Discord Heartbeat acknowledged

My config is quite simple:

[
  {
    "nickname": "DiscordRel",
    "server": "irc.netgamers.org",
    "discordToken": "token",
    "channelMapping": {
        "channel ID": "#8.1 <key>"
    },
    "ircOptions": {
      "debug": true
    }
  }
]

[Throne3d]

Do you have an example of it working? The IRC part of things should output when it receives a line from the server, as in the example below (lines starting 24 Oct HH:mm:ss - Received:), but it looks like your output isn't showing that.

24 Oct 15:17:51 - Received: :Throne3d_!~throne3d@example.com JOIN #testbed
debug: Received join: #testbed Throne3d_
24 Oct 15:17:51 - Received: :stormlight.esper.net PONG stormlight.esper.net :1
24 Oct 15:18:01 - Received: :Throne3d_!~throne3d@example.com PRIVMSG #testbed :example sent to IRC and then bridged to Discord.
debug: Sending message to Discord **<Throne3d_>** example sent to IRC and then bridged to Discord. #testbed -> #general
debug: Channel Mapping #general #testbed
debug: Sending message to IRC #testbed <07Throne3d> example sent to Discord and then bridged to IRC.
24 Oct 15:18:08 - SEND: PRIVMSG #testbed :<07Throne3d> example sent to Discord and then bridged to IRC.

Edit: Maybe you need to re-run npm install after having checked out the new version of discord-irc?

[aleksandervines]

as I wrote, it did work in the first 9 lines of the log I pasted, it seemingly works as supposed to, this is the first line that I know does not work: debug: Sending message to Discord **<Monroe|afk>** eta 6 atm #8.1 -> #8_1

Not a single line containing "Received:" in the entire output.

all the output is pretty much the same, with a lot of heartbeat and pings and some messages on this form. I guess including the "startup" lines might tell you something extra:

> discord-irc@2.4.2 start /opt/discord-irc/discord-irc
> node dist/index.js "--config" "../config/8_1.json"

debug: Connecting to IRC and Discord
debug: Received debug event from Discord Using gateway wss://gateway.discord.gg/?v=6
debug: Received debug event from Discord Connecting to gateway wss://gateway.discord.gg/?v=6&encoding=json
debug: Received debug event from Discord Connection to gateway opened
debug: Received debug event from Discord Identifying as new session
debug: Received debug event from Discord Sending heartbeat
info: Connected to Discord
debug: Received debug event from Discord Heartbeat acknowledged
24 Oct 03:00:22 - Sending irc NICK/USER
24 Oct 03:00:22 - SEND: NICK DiscordRel
24 Oct 03:00:23 - SEND: USER DiscordRel 8 * DiscordRel
24 Oct 03:00:23 - SEND: PONG 513476975
info: Connected to IRC
debug: Registered event:  prefix=underworld.no.eu.netgamers.org, server=underworld.no.eu.netgamers.org, command=rpl_w
24 Oct 03:00:23 - GOT NOTICE from the server: "Highest connection count: 298 (297 clients)"
24 Oct 03:00:23 - GOT NOTICE from the server: "on 1 ca 1(4) ft 10(10)"
24 Oct 03:00:23 - MODE: DiscordRel sets mode: +i
24 Oct 03:00:24 - SEND: WHOIS DiscordRel
24 Oct 03:00:24 - SEND: JOIN #8.1 Discord
24 Oct 03:00:25 - SEND: MODE #8.1
CyclingPingTimer 0: server silent for too long, let's send a PING
24 Oct 03:00:40 - SEND: PING 1

Of course I forgot to install again after checking out the new version. I'll do it right away!

[aleksandervines]

I had some unmet peer dependencies on installation. could this possibly cause it?

npm install

> node-icu-charset-detector@0.2.0 install /opt/discord-irc/discord-irc/node_modules/node-icu-charset-detector
> node-gyp rebuild

make: Entering directory `/opt/discord-irc/discord-irc/node_modules/node-icu-charset-detector/build'
  CXX(target) Release/obj.target/node-icu-charset-detector/node-icu-charset-detector.o
  SOLINK_MODULE(target) Release/obj.target/node-icu-charset-detector.node
  COPY Release/node-icu-charset-detector.node
make: Leaving directory `/opt/discord-irc/discord-irc/node_modules/node-icu-charset-detector/build'

> discord-irc@2.4.2 prepublish /opt/discord-irc/discord-irc
> npm run build

> discord-irc@2.4.2 build /opt/discord-irc/discord-irc
> babel lib --out-dir dist

lib/bot.js -> dist/bot.js
lib/cli.js -> dist/cli.js
lib/errors.js -> dist/errors.js
lib/formatting.js -> dist/formatting.js
lib/helpers.js -> dist/helpers.js
lib/index.js -> dist/index.js
lib/validators.js -> dist/validators.js
discord-irc@2.4.2 /opt/discord-irc/discord-irc
├── UNMET PEER DEPENDENCY bufferutil@^3.0.0
├── UNMET PEER DEPENDENCY erlpack@hammerandchisel/erlpack
├─┬ irc-upd@0.7.0
│ └── node-icu-charset-detector@0.2.0
├── UNMET PEER DEPENDENCY libsodium-wrappers@^0.5.1
├── UNMET PEER DEPENDENCY node-opus@^0.2.5
├── UNMET PEER DEPENDENCY opusscript@^0.0.3
├── UNMET PEER DEPENDENCY sodium@^2.0.1
└── UNMET PEER DEPENDENCY uws@^0.14.1

npm WARN optional SKIPPING OPTIONAL DEPENDENCY: fsevents@^1.0.0 (node_modules/chokidar/node_modules/fsevents):
npm WARN notsup SKIPPING OPTIONAL DEPENDENCY: Unsupported platform for fsevents@1.1.2: wanted {"os":"darwin","arch":"any"} (current: {"os":"linux","arch":"x64"})
npm WARN discord.js@11.1.0 requires a peer of bufferutil@^3.0.0 but none was installed.
npm WARN discord.js@11.1.0 requires a peer of erlpack@hammerandchisel/erlpack but none was installed.
npm WARN discord.js@11.1.0 requires a peer of node-opus@^0.2.5 but none was installed.
npm WARN discord.js@11.1.0 requires a peer of opusscript@^0.0.3 but none was installed.
npm WARN discord.js@11.1.0 requires a peer of sodium@^2.0.1 but none was installed.
npm WARN discord.js@11.1.0 requires a peer of libsodium-wrappers@^0.5.1 but none was installed.
npm WARN discord.js@11.1.0 requires a peer of uws@^0.14.1 but none was installed.

[Throne3d]

No, they shouldn't cause it; discord.js has a lot of unmet peer dependencies that you should be able to safely ignore.

[aleksandervines]

well, npm install didn't help :(

edit: From the log, there seem to be absolutely nothing special happening at the time it breaks. On one line it works, the next not.

25 Oct 02:03:13 - Received: :underworld.no.eu.netgamers.org PONG underworld.no.eu.netgamers.org :2589
25 Oct 02:03:28 - CyclingPingTimer 0: server silent for too long, let's send a PING
25 Oct 02:03:28 - SEND: PING 2590
25 Oct 02:03:28 - Received: :underworld.no.eu.netgamers.org PONG underworld.no.eu.netgamers.org :2590
25 Oct 02:03:31 - Received: :Monroe|afk!~Monroe@PFC-Monroe.users.netgamers.org PRIVMSG #8.1 :incoming
------------ HERE IT BREAKS ------------
25 Oct 02:03:34 - Received: :Monroe|afk!~Monroe@PFC-Monroe.users.netgamers.org PRIVMSG #8.1 :I have wyverns
25 Oct 02:03:49 - CyclingPingTimer 0: server silent for too long, let's send a PING
25 Oct 02:03:49 - SEND: PING 2591
25 Oct 02:03:49 - Received: :underworld.no.eu.netgamers.org PONG underworld.no.eu.netgamers.org :2591
25 Oct 02:03:54 - Received: :Monroe|afk!~Monroe@PFC-Monroe.users.netgamers.org PRIVMSG #8.1 :3500 if needed
25 Oct 02:04:09 - CyclingPingTimer 0: server silent for too long, let's send a PING
25 Oct 02:04:09 - SEND: PING 2592

edit2: the npm install seems to have changed the log output slightly?

[Throne3d]

Did you run it with NODE_ENV=development this time? (It looks like you didn't, whereas you did last time, although it looks like you have installed an updated version and it looks like the IRC side of things is still in debug mode. NODE_ENV=development puts the actual bot part of things into debug mode.)

It seems like the IRC library is receiving the messages from IRC (that's why it was useful to update, it shows the Received: lines), but since the bot isn't sending messages, it would be useful to see if the bot itself is still itself responding to the messages being sent, and how.

[aleksandervines]

Well, after checking some bash manuals and googling some, I believe I didn't pass the environment variables properly. I now rather just export NODE_ENV to ensure its set, and it seems to produce more debug lines.

Now I'll just wait to see what it says when it happens again.

[mmjee]

This happened to me too today, the discord servers got nuked for a second and the next moment the bridge wasn't relaying IRC -> discord.

[aleksandervines]

For the record. It hasn't happened since my last post in here, the bot was running nicely for 24 days straight, until it, a couple of days ago, stopped, but I haven't hat time to look at the logs yet.

[acerspyro]

I do not know if this is the same bug, but our bot stopped relaying data from IRC to Discord with a different error:

(node:2263) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 2): TypeError: Cannot read property 'options' of undefined

I am running discord-irc installed from the NPM repositories.

[redfellow]

Any updates on this? Happens to my bot at least once a week, but even with debug enabled there is no indication in the messages when this happens, so I cannot help with more info.

[redfellow]

Could we maybe get some mechanism that would kill the bot when this happens, so when running with forever we'd at least automatically restart once the bot is in a limbo?

I ask because when I tested with forever restartall the result was that a 2nd bot joined IRC and while IRC to Discord was still only one message, Discord to IRC was being relayed by both. (My first idea was to schedule chronjob for a daily forever restartall)

[Throne3d]

I think that if we had a mechanism to kill the bot when this happens, we could instead reconnect at that time. It's not complicated to stop and start both sides of the bot, but I'm not sure how we notice when this is happening from the bot's side.

The IRC side of things still seems to notice when a message is sent, but it's failing to then send it on to Discord. Iirc, when I checked this out, the Discord side of things was disconnecting somehow and failing to reconnect, but it also didn't emit any event to say (i.e. let us know when) it had disconnected. (I'm a bit busy right now, so won't be able to get to it myself for a few weeks, but might find something then? I'm not sure.)

[redfellow]

One way to verify this would be to read back what was sent to Discord/IRC side by the bot. If the line doesn't come back after sending it, it could be detected as an error. Enough errors and the bot would reconnect.

And no hurries, the bot works great already, this is at worst a minor inconvenience. I think I got the chronjob working too so I'm personally covered (needed -t switch for starting the script).

[Throne3d]

I think reading back the IRC side is not possible – as far as I know, the server doesn't send a confirmation when it receives a message you send. (I could well be wrong.) For the Discord side, that seems like it might work – Discord provides message history, so we should be able to poll that – but it's a bit of an ugly way to do it (when really the discord.js library should figure it out itself and reconnect us / tell us that we've been disconnected). If I don't find a better way to do it, I'll see if I can implement that and hopefully it'll be accepted as a temporary measure, while I (hopefully) open a bug report with discord.js itself.

I'm not completely sure, but it seems like this might fix both this issue and #326, since (iirc) they're both about the Discord side of things disconnecting and failing to do anything about it.

[acerspyro]

Here is a script I wrote to automatically restart discord-irc whenever it starts shitting itself.

command="discord-irc -c config.json"
log="prog.log"
match="TypeError: Cannot read property 'options' of undefined"
$command > "$log" 2>&1 &
pid=$!

while sleep 60; do
    if fgrep --quiet "$match" "$log"; then
        kill $pid
        ./autorestart.sh &
        exit 0
    fi
done

Basically, it spawns the program and listens to its output and looks for $match If it finds it, it then kills the program and starts it again. This doesn't seem to cause a disconnection on IRC, and the bot just keeps running. Been using the bot like this for almost two months with no issues.

[Throne3d]

@acerspyro

Your problem looks more like #351 (and #342) than this one, and we think those have both been fixed as of v2.5.1. Are you sure it's still a problem? The debug logs given in this issue don't, except for yours, complain about a TypeError, and instead have the issue that the logs don't show anything going obviously wrong.

Since we are being mostly ignored, here is a script I wrote to automatically restart discord-irc whenever it starts shitting itself.

This seems, to put it nicely, less than maximally charitable as a description. I'm not intending to ignore you, and I'm sorry that you feel that way. If your issue is still a problem, I don't have a great way to fix it, as I cannot reproduce it locally and it doesn't seem to offer enough useful debug information. You may get something out of looking at https://www.bennadel.com/blog/3238-logging-and-debugging-unhandled-promise-rejections-in-node-js-v1-4-1-and-later.htm to set it up to debug more useful information.

[Mikaela]

I think reading back the IRC side is not possible – as far as I know, the server doesn't send a confirmation when it receives a message you send. (I could well be wrong.)

This depends on the IRC server.

• https://ircv3.net/irc/#echo-message
• https://ircv3.net/software/servers.html

[Throne3d]

Huh! Okay, I might be able to implement that in the upstream IRC library to better detect if something's gone wrong. (It still seems like a thing that should be done upstream, like a ping timer, but I'm not sure if I'll be able to get anywhere with discord.js for their side – I haven't tried yet – whereas I do have the ability to do that for irc-upd.) It still leaves the problem for IRC servers that don't implement that protocol, but it's an improvement.

[Mikaela]

So is there a better solution or workaround to this issue than the following?

% cat /etc/systemd/system/discordpirateirc.service 
[Unit]
Description=discordpirateirc
#After=network-online.target

[Service]
ExecStart=/home/discordirc/discordpirateirc.start
Restart=always
User=discordirc

[Install]
WantedBy=default.target

and

0 1 * * * perl -le 'sleep rand 3600' && systemctl restart discordpirateirc --quiet                                                                             
0 8 * * * perl -le 'sleep rand 3600' && systemctl restart discordpirateirc --quiet                                                                             
0 13 * * * perl -le 'sleep rand 3600' && systemctl restart discordpirateirc --quiet                                                                            
0 20 * * * perl -le 'sleep rand 3600' && systemctl restart discordpirateirc --quiet

[Throne3d]

We still haven't found the root cause of this issue, and the proposed (partial) workarounds haven't been implemented yet.

If someone could run this with both debug flags on (NODE_ENV=development as an environment variable and "debug": true in the ircOptions part of the config), and paste me the relevant section where the bot stops relaying, that may help a lot!

[Throne3d]

I'll close this for now as potentially fixed, as I haven't heard anything back in a long while here (and I haven't got enough information to be able to debug it further =/). If you have any recent connectivity issues, please get back in touch!