Discord.js: Bot still silently disconnecting

Created on 27 Feb 2017  ยท  62Comments  ยท  Source: discordjs/discord.js

My issue seems related to issue #225.

The bot will run and show as logged in for a channel for some time and then it will suddenly drop offline. However, it will still post messages that are scheduled to a text channel.

autoReconnect is set to true as well.

For a look at my bot see: https://github.com/ericnelson0/GoHBot/blob/master/index.js

Discord bug gateway bug discussion

Most helpful comment

client.destroy().then(client.login()) this wouldn't work ๐Ÿ˜ i think you mean client.destroy().then(() => client.login()) or client.destroy().then(client.login.bind(client))

All 62 comments

autoreconnect isn't a thing anymore, it is always true, no matter what you do.

can you log disconnect events? i suspect you are getting close code 1000.

it is also worth mentioning that being online/offline happens on the websocket gateway and sending messages happens via the http api.

it is also worth mentioning that being online/offline happens on the websocket gateway and sending messages happens via the http api.

That makes sense, thanks.

autoreconnect isn't a thing anymore, it is always true, no matter what you do.

can you log disconnect events? i suspect you are getting close code 1000.

Ok, didn't realize that. I'll log the disconnects and report back.

Also, for what it's worth the bot is hosted on AWS. I'm not sure if that's relevant to the issue.

Happens to me too a lot, out of nowhere for no reason.

Hi, which version of discord.js are you guys running?

I'm having the same issue, I'm running discord.js version 11.0.0

You guys need to give us some logs.
Not everyone has the same issue, obviously we cannot just say "doesn't happen for us, bad luck."

But a detailed report would be kinda nice, does it come back online? What are the close codes? etc.

In my case after being idle for a while it just says that it was disconnected, (I use the disconnect event to catch it). In that event I have a rejoin command but it when I try to play again, nothing plays(shows that it plays but no sound), and I have to reboot it for it to work normally.

@Georgia10
You could do a client.destroy().then(client.login())

but its kinda hacky in its implementation

client.destroy().then(client.login()) this wouldn't work ๐Ÿ˜ i think you mean client.destroy().then(() => client.login()) or client.destroy().then(client.login.bind(client))

I believe I'm experiencing the same issue. The only thing printed to my "err.log" file is-

Unhandled rejection RequestError: Error: read ECONNRESET at new RequestError (/home/ec2-user/node/npm/node_modules/snoowrap/node_modules/request-promise/lib/errors.js:14:15) at Request.RP$callback [as _callback] (/home/ec2-user/node/npm/node_modules/snoowrap/node_modules/request-promise/lib/rp.js:60:25) at self.callback (/home/ec2-user/node/npm/node_modules/request/request.js:200:22) at emitOne (events.js:96:13) at Request.emit (events.js:188:7) at Request.onRequestError (/home/ec2-user/node/npm/node_modules/request/request.js:831:8) at emitOne (events.js:96:13) at ClientRequest.emit (events.js:188:7) at TLSSocket.socketErrorListener (_http_client.js:308:9) at emitOne (events.js:96:13) at TLSSocket.emit (events.js:188:7) at emitErrorNT (net.js:1272:8) at _combinedTickCallback (internal/process/next_tick.js:74:11) at process._tickCallback (internal/process/next_tick.js:98:9)

but not sure if this is related to the issue

that error is from snoowrap, which has nothing to do with discord.js

Same thing is happening to me every few days, close code 1000, no reason specified, then the bot never tries to reconnect. This seems to be intentional behavior; WebSocketManager has the line

if (!this.reconnecting && event.code !== 1000) this.tryReconnect();

I imagine this is related to https://discordapp.com/developers/docs/topics/gateway#connecting, though I don't know what 1000 means in this case and why that would prevent the bot from trying to reconnect. Here is my event log for the disconnection event. Happy to add more logging if required.
โ†’ { target: โ†’ WebSocket { โ†’ domain: null, โ†’ _events: โ†’ { open: [Object], โ†’ message: [Object], โ†’ close: [Object], โ†’ error: [Object] }, โ†’ _eventsCount: 4, โ†’ _maxListeners: undefined, โ†’ readyState: 3, โ†’ bytesReceived: 147714, โ†’ extensions: {}, โ†’ protocol: '', โ†’ _finalize: [Function: bound finalize], โ†’ _binaryType: 'nodebuffer', โ†’ _finalizeCalled: true, โ†’ _closeMessage: '', โ†’ _closeTimer: null, โ†’ _closeCode: 1000, โ†’ _receiver: โ†’ Receiver { โ†’ extensions: null, โ†’ maxPayload: 0, โ†’ bufferedBytes: 0, โ†’ buffers: null, โ†’ compressed: false, โ†’ payloadLength: 2, โ†’ fragmented: 0, โ†’ masked: false, โ†’ fin: true, โ†’ mask: null, โ†’ opcode: 8, โ†’ totalPayloadLength: 0, โ†’ messageLength: 0, โ†’ fragments: null, โ†’ cleanupCallback: null, โ†’ hadError: false, โ†’ dead: true, โ†’ loop: false, โ†’ onmessage: null, โ†’ onclose: null, โ†’ onerror: null, โ†’ onping: null, โ†’ onpong: null, โ†’ state: 4 }, โ†’ _sender: null, โ†’ _socket: null, โ†’ _ultron: null, โ†’ protocolVersion: 13, โ†’ _isServer: false, โ†’ url: 'wss://gateway.discord.gg/?v=6&encoding=etf', โ†’ _req: null }, โ†’ type: 'close', โ†’ wasClean: true, โ†’ reason: '', โ†’ code: 1000 }
No errors/unresolved promises in the logs.

this is a thing multiple libs and users have been seeing. can you do me a favor and on the computer that hosts your code get https://discordapp.com/cdn-cgi/trace and post your loc and colo

loc=GB
colo=LHR

thx

I have been receiving the same over the past few days.

I'll keep a look out for if it happens more often (and if the code is the same each time) and then report back the error it outputs.

loc=DE
colo=FRA

Edit: Oops, these are off of my local machine. My bad, see post below.

I'm pretty sure it's an actual coding issue instead because it has happened to a friend of mine and we have fixed his issues.

@eaaliprantis Would you mind describing (or preferably showing) how you did that?

@robflop Pretty much, my friend had an issue with a logging feature that he build. Whenever the bot joined a new guild, it caused an error stating that "a logger was undefined" but it wasn't a D.js issue but his code. When we resolved that issue, he has not had any 1006/1007 issues anymore.

@eaaliprantis Hmm I see. Thanks for the input, i'll keep it in mind.

Alright, I've been watching for a while and I always get this error:

```{
"target": {
"domain": null,
"_events": {},
"_eventsCount": 4,
"readyState": 3,
"bytesReceived": 4752794,
"extensions": {},
"protocol": "",
"_binaryType": "nodebuffer",
"_finalizeCalled": true,
"_closeMessage": null,
"_closeTimer": null,
"_closeCode": 1006,
"_receiver": {
"extensions": null,
"maxPayload": 0,
"bufferedBytes": 0,
"buffers": null,
"compressed": false,
"payloadLength": 167,
"fragmented": 0,
"masked": false,
"fin": true,
"mask": null,
"opcode": 1,
"totalPayloadLength": 0,
"messageLength": 0,
"fragments": null,
"cleanupCallback": null,
"hadError": false,
"dead": true,
"loop": false,
"onmessage": null,
"onclose": null,
"onerror": null,
"onping": null,
"onpong": null,
"state": 0
},
"_sender": null,
"_socket": null,
"_ultron": null,
"protocolVersion": 13,
"_isServer": false,
"url": "wss://gateway.discord.gg/?v=6&encoding=json",
"_req": null
},
"type": "close",
"wasClean": false,
"reason": "",
"code": 1006
}

@robflop thx for reporting, can you perform a GET to https://discordapp.com/cdn-cgi/trace on the machine you host your bot on and tell me the loc and colo it gives you?

loc=LT & colo=FRA on my vps.

I've been getting a similar if slightly different issue for as long as I can remember - occasionally when my bot disconnects, it simply stops trying to reconnect. Not sure if this is caused by the same problem or not, but as this is causing issues with some very mission-critical elements of one of my servers, I'd really like to figure out what's going on. All the pull requests on it have been closed as fixed, but it still happens.

@tripl3dogdare you using uws? It sounds like you are, uws has that issue...

@tripl3dogdare can you log disconnect codes, and if it is 1006 or 1000 can you get that url i posted above and post your colo and loc

@bdistin I noticed the issue with uws noted in the docs and specifically choose bufferutil for that exact reason.

@GusCaplan The issue isn't consistent enough to log effectively, it only happens maybe once in ten times. I could theoretically get them, but it could take as much as a week or more.

well uh, thanks for telling us you get disconnects, if you feel like posting something useful, we will be here. ๐Ÿ‘‹

There's no need to be rude about it. I simply mentioned the issue I was having in the hopes of increasing the urgency of the fix somewhat. If you have something to contribute to my problem I'm all ears, but at this point I'm thinking it may be better to just do things the hard way instead of asking for help that obviously won't be given, if your response to "I'm sorry, I have no good way of getting that information" is any indication. Good day.

it isn't something we can fix anyway, it is an issue on discord/cloudflare's end, which is why i would like the close code and the response from a cdn-cgi trace, to report to discord (โ•ฏยฐโ–กยฐ๏ผ‰โ•ฏ๏ธต โ”ปโ”โ”ป

Why does it matter if it's their fault or yours, auto-reconnect should reconnect if the connection is closed - whether through an error on their side, or weird behavior on cloudflares side - doesn't matter...

that is actually wrong. different close codes mean different things, and so for instance, if we were to accidentally get a 1000, it would be assumed we shouldn't reconnect. here is a list of close codes

If it is wrong, then you should be able to fix and solve this issue of why the bot silently disconnecting.

The reason why i believe what I stated is correct is because a friend of mine had errors in his bot that caused him to get 1006 and 1007 errors. Those errors were caused by a line of code that shouldn't had been there that produced those errors. And since he has 5-6 shards, every time that error occurred (error 1006 and 1007), it would disconnect and re-connect his shards. After a while of getting that error, it would return a error 1000, and drop the connection, thereby taking down a shard. According to Discord, if you have a lot of disconnects and re-connects in a given time frame, your token is reset automatically.

I understand that you may think I'm wrong or don't know things but I'm pretty sure I'm right because my friend had the issue, asked me to figure out why, and the issue was a bad line of code in the function/method that was executing it.

Sent from my iPhone

On Mar 11, 2017, at 7:58 AM, Gus Caplan notifications@github.com wrote:

that is actually wrong. different close codes mean different things, and so for instance, if we were to accidentally get a 1000, it would be assumed we shouldn't reconnect. here is a list of close codes

โ€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

Error close codes of 1006 are not caused by bad code.

(they are caused by cloudflare bad code ๐Ÿ˜† )

OK. I've let my bot run for a couple of days untill I could reproduce this.

This is my log:

debug: [14/03/2017 09:04:39] [DEBUG] Authenticated using token ***************************************
debug: [14/03/2017 09:04:39] [DEBUG] Using gateway wss://gateway.discord.gg/?v=6
debug: [14/03/2017 09:04:39] [DEBUG] Connecting to gateway wss://gateway.discord.gg/?v=6&encoding=json
debug: [14/03/2017 09:04:40] [DEBUG] Connection to gateway opened
debug: [14/03/2017 09:04:40] [DEBUG] Identifying as new session
debug: [14/03/2017 09:04:40] [DEBUG] Sending heartbeat
debug: [14/03/2017 09:05:21] [DEBUG] Heartbeat acknowledged
debug: [14/03/2017 09:06:02] [DEBUG] Sending heartbeat
debug: [14/03/2017 09:06:02] [DEBUG] Heartbeat acknowledged
(...2 days after)
debug: [16/03/2017 06:06:37] [DEBUG] Heartbeat acknowledged
debug: [16/03/2017 06:07:18] [DEBUG] Sending heartbeat
info: [16/03/2017 06:07:33] Connection lost [1000]

My trace returned colo=EWR and loc=US

By the way, can anyone confirm if this client.destroy().then(() => client.login()) works as a workaround for this issue?

I can't see anything in the list of close codes above (https://developer.mozilla.org/en-US/docs/Web/API/CloseEvent) that would imply that a code 1000 should make the client back off and not auto-reconnect. Is there some further documentation that explains this behaviour?

if (!this.reconnecting && event.code !== 1000) this.tryReconnect();

Normal closure; the connection successfully completed whatever purpose for which it was created.

This implies the connection has no purpose anymore, so why would it reconnect?

Well, the connection has a purpose, to listen for messages, despite what the server might think. Clearly the client still needs an active connection in order to do that, so should create a new connection.

1000 implies that this purpose has been fulfilled or completed is what I am saying.

Well, as these code 1000 closures happen seemingly randomly every few days, it seems as though the server cannot be trusted to determine that the sockets purpose has been fulfilled, so the client trusting that and not attempting to reconnect seems a flawed approach.

No, I don't think this is how this all works.
Neither do I think this is the right way to approach this situation.

I've "resorted" to simply adding a check in the disconnected event which destroys and re-logins the client if the disconnect code is 1000. Seems to work fine.

Hi, I have been looking into this issue:

This is potentially caused by you blocking the event loop, and preventing d.js from acking received heartbeats. This has been a known method to cause a known cloudflare bug to incorrectly respond close code 1000. (although this isn't the only way the bug can be triggered, this is one way that can be replicated in any library that can have it's event loop blocked.)

Although yes, it is a bugged reason to receive the 1000. It is something we still must honor, regardless of the reason. Your solution of client.destroy()/client.login() in combination with reducing the amount of time the event loop is blocked (async methods are your friend) will be the best course until cloudflare fixes their bug.

I've also used that fix, and its fine, but it's a little worrying as it will conflict if any changes are made based on this issue.

I acknowledge its really a bug somewhere between cloudflare and discord itself, causing these extra code 1000/1006 with no reasons, but it would be nice if discord.js could mitigate it somehow, considering the issue seems to have been around for at least 10 months now, maybe longer, presumably ever since the bot api was created. Fair enough if you consider it out of scope though.

@bdistin I have looked into that myself and it seems as though in my case the heartbeats are being sent on time unfortunately.

Out of curiousity, when this happens are any of you able to check the .status property of your bot's client? Does it return 5 or 0?

I'll implement a check and see when it next happens.

@JMTK Alright, so I just peeked into my logs and it returns a 5 on disconnect.

I get this too

Log - revivebot-2 (err): Error: A bad message was received from the websocket; either bad compression, or not JSON.
revivebot-2 (err):     at WebSocketManager.eventMessage (/opt/revive-bot/apps/revivebot/node_modules/discord.js/src/client/websocket/WebSocketManager.js:264:23)
revivebot-2 (err):     at WebSocket.onMessage (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/EventTarget.js:103:16)
revivebot-2 (err):     at emitTwo (events.js:106:13)
revivebot-2 (err):     at WebSocket.emit (events.js:194:7)
revivebot-2 (err):     at Receiver._receiver.onmessage (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/WebSocket.js:145:54)
revivebot-2 (err):     at Receiver.dataMessage (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:385:14)
revivebot-2 (err):     at Receiver.getData (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:326:12)
revivebot-2 (err):     at Receiver.startLoop (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:161:16)
revivebot-2 (err):     at Receiver.add (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:135:10)
revivebot-2 (err):     at TLSSocket._ultron.on (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/WebSocket.js:141:22)
revivebot-2 (err):     at emitOne (events.js:96:13)
revivebot-2 (err):     at TLSSocket.emit (events.js:191:7)
revivebot-2 (err):     at readableAddChunk (_stream_readable.js:178:18)
revivebot-2 (err):     at TLSSocket.Readable.push (_stream_readable.js:136:10)
revivebot-2 (err):     at TLSWrap.onread (net.js:559:20)
revivebot-2 (out):     at Receiver.dataMessage (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:385:14)
revivebot-2 (out):     at Receiver.getData (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:326:12)
revivebot-2 (out):     at Receiver.startLoop (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:161:16)
revivebot-2 (out):     at Receiver.add (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:135:10)
revivebot-2 (out):     at TLSSocket._ultron.on (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/WebSocket.js:141:22)
revivebot-2 (out):     at emitOne (events.js:96:13)
revivebot-2 (out):     at TLSSocket.emit (events.js:191:7)
revivebot-2 (err):     at Receiver.dataMessage (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:385:14)
revivebot-2 (err):     at Receiver.getData (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:326:12)
revivebot-2 (err):     at Receiver.startLoop (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:161:16)
revivebot-2 (err):     at Receiver.add (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:135:10)
revivebot-2 (err):     at TLSSocket._ultron.on (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/WebSocket.js:141:22)
revivebot-2 (err):     at emitOne (events.js:96:13)
revivebot-2 (err):     at TLSSocket.emit (events.js:191:7
Log - revivebot-2 (err): { Error: RSV1 must be clear
revivebot-2 (err):     at Receiver.getInfo (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:187:18)
revivebot-2 (err):     at Receiver.startLoop (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:149:16)
revivebot-2 (err):     at Receiver.add (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/Receiver.js:135:10)
revivebot-2 (err):     at TLSSocket._ultron.on (/opt/revive-bot/apps/revivebot/node_modules/ws/lib/WebSocket.js:141:22)
revivebot-2 (err):     at emitOne (events.js:96:13)
revivebot-2 (err):     at TLSSocket.emit (events.js:191:7)
revivebot-2 (err):     at readableAddChunk (_stream_readable.js:178:18)
revivebot-2 (err):     at TLSSocket.Readable.push (_stream_readable.js:136:10)
revivebot-2 (err):     at TLSWrap.onread (net.js:559:20)
revivebot-2 (err):   type: 'error',
revivebot-2 (err):   target: 
revivebot-2 (err):    WebSocket {
revivebot-2 (err):      domain: null,
revivebot-2 (err):      _events: 
revivebot-2 (err):       { open: [Object],
revivebot-2 (err):         message: [Object],
revivebot-2 (err):         close: [Object],
revivebot-2 (err):         error: [Object] },
revivebot-2 (err):      _eventsCount: 4,
revivebot-2 (err):      _maxListeners: undefined,
revivebot-2 (err):      readyState: 2,
revivebot-2 (err):      bytesReceived: 13958546,
revivebot-2 (err):      extensions: {},
revivebot-2 (err):      protocol: '',
revivebot-2 (err):      _binaryType: 'nodebuffer',
revivebot-2 (err):      _finalize: { [Function: bound finalize] __ultron: 0 },
revivebot-2 (err):      _finalizeCalled: false,
revivebot-2 (err):      _closeMessage: null,
revivebot-2 (err):      _closeTimer: null,
revivebot-2 (err):      _closeCode: null,
revivebot-2 (err):      _receiver: 
revivebot-2 (err):       Receiver {
revivebot-2 (err):         binaryType: 'nodebuffer',
revivebot-2 (err):         extensions: {},
revivebot-2 (err):         maxPayload: 0,
revivebot-2 (err):         bufferedBytes: 2745,
revivebot-2 (err):         buffers: [Object],
revivebot-2 (err):         compressed: false,
revivebot-2 (err):         payloadLength: 445,
revivebot-2 (err):         fragmented: 0,
revivebot-2 (err):         masked: false,
revivebot-2 (err):         fin: true,
revivebot-2 (err):         mask: null,
revivebot-2 (err):         opcode: 1,
revivebot-2 (err):         totalPayloadLength: 0,
revivebot-2 (err):         messageLength: 0,
revivebot-2 (err):         fragments: [],
revivebot-2 (err):         cleanupCallback: null,
revivebot-2 (err):         hadError: false,
revivebot-2 (err):         dead: false,
revivebot-2 (err):         loop: true,
revivebot-2 (err):         onmessage: [Function],
revivebot-2 (err):         onclose: [Function],
revivebot-2 (err):         onerror: [Function],
revivebot-2 (err):         onping: [Function],
revivebot-2 (err):         onpong: [Function],
revivebot-2 (err):         state: 0 },
revivebot-2 (err):      _sender: 
revivebot-2 (err):       Sender {
revivebot-2 (err):         perMessageDeflate: undefined,
revivebot-2 (err):         _socket: [Object],
revivebot-2 (err):         firstFragment: true,
revivebot-2 (err):         compress: false,
revivebot-2 (err):         bufferedBytes: 0,
revivebot-2 (err):         deflating: false,
revivebot-2 (err):         queue: [],
revivebot-2 (err):         onerror: [Function] },
revivebot-2 (err):      _socket: 
revivebot-2 (err):       TLSSocket {
revivebot-2 (err):         _tlsOptions: [Object],
revivebot-2 (err):         _secureEstablished: true,
revivebot-2 (err):         _securePending: false,
revivebot-2 (err):         _newSessionPending: false,
revivebot-2 (err):         _controlReleased: true,
revivebot-2 (err):         _SNICallback: null,
revivebot-2 (err):         servername: null,
revivebot-2 (err):         npnProtocol: false,
Log - revivebot-2 (out): logs ready
Bot Ready (pid: 5854)
revivebot-2 (err):         alpnProtocol: false,
revivebot-2 (err):         authorized: true,
revivebot-2 (err):         authorizationError: null,
revivebot-2 (err):         encrypted: true,
revivebot-2 (err):         _events: [Object],
revivebot-2 (err):         _eventsCount: 8,
revivebot-2 (err):         connecting: false,
revivebot-2 (err):         _hadError: false,
revivebot-2 (err):         _handle: [Object],
revivebot-2 (err):         _parent: null,
revivebot-2 (err):         _host: 'gateway.discord.gg',
revivebot-2 (err):         _readableState: [Object],
revivebot-2 (err):         readable: true,
revivebot-2 (err):         domain: null,
revivebot-2 (err):         _maxListeners: undefined,
revivebot-2 (err):         _writableState: [Object],
revivebot-2 (err):         writable: true,
revivebot-2 (err):         allowHalfOpen: false,
revivebot-2 (err):         destroyed: false,
revivebot-2 (err):         _bytesDispatched: 6868,
revivebot-2 (err):         _sockname: null,
revivebot-2 (err):         _pendingData: null,
revivebot-2 (err):         _pendingEncoding: '',
revivebot-2 (err):         server: undefined,
revivebot-2 (err):         _server: null,
revivebot-2 (err):         ssl: [Object],
revivebot-2 (err):         _requestCert: true,
revivebot-2 (err):         _rejectUnauthorized: true,
revivebot-2 (err):         parser: null,
revivebot-2 (err):         _httpMessage: [Object],
revivebot-2 (err):         read: [Function],
revivebot-2 (err):         _consuming: true,
revivebot-2 (err):         _idleNext: null,
revivebot-2 (err):         _idlePrev: null,
revivebot-2 (err):         _idleTimeout: -1 },
revivebot-2 (err):      _ultron: Ultron { id: 0, ee: [Object] },
revivebot-2 (err):      protocolVersion: 13,
revivebot-2 (err):      _isServer: false,
revivebot-2 (err):      url: 'wss://gateway.discord.gg/?v=6&encoding=json',
revivebot-2 (err):      _req: null } }

here is https://discordapp.com/cdn-cgi/trace

fl=11f17
h=discordapp.com
ip=REMOVED
ts=1491189400.326
visit_scheme=https
uag=
colo=EWR
spdy=off
http=http/1.1
loc=US

@meldsza that has nothing to do with this issue โ˜น๏ธ

@meldsza u prob have an unhandledRejection / uncaughtException going through a sendMessage event, thats where i see that alot

Having a similar issue with my bot - It's been disconnected every 2-3 days.

2017-04-11T12:19:52.235681781Z app[web.1]: CloseEvent {
2017-04-11T12:19:52.235741704Z app[web.1]:   type: 'close',
2017-04-11T12:19:52.235749486Z app[web.1]:   wasClean: false,
2017-04-11T12:19:52.235754381Z app[web.1]:   code: 1001,
2017-04-11T12:19:52.235758915Z app[web.1]:   reason: '',
2017-04-11T12:19:52.235763364Z app[web.1]:   target: 
2017-04-11T12:19:52.235767671Z app[web.1]:    WebSocket {
2017-04-11T12:19:52.235772083Z app[web.1]:      domain: null,
2017-04-11T12:19:52.235776642Z app[web.1]:      _events: 
2017-04-11T12:19:52.235780982Z app[web.1]:       { open: [Object],
2017-04-11T12:19:52.235785414Z app[web.1]:         message: [Object],
2017-04-11T12:19:52.235789646Z app[web.1]:         close: [Object],
2017-04-11T12:19:52.235793837Z app[web.1]:         error: [Object] },
2017-04-11T12:19:52.235798149Z app[web.1]:      _eventsCount: 4,
2017-04-11T12:19:52.235802329Z app[web.1]:      _maxListeners: 100,
2017-04-11T12:19:52.235806514Z app[web.1]:      _socket: 
2017-04-11T12:19:52.235810683Z app[web.1]:       TLSSocket {
2017-04-11T12:19:52.235838064Z app[web.1]:         _tlsOptions: [Object],
2017-04-11T12:19:52.235843446Z app[web.1]:         _secureEstablished: true,
2017-04-11T12:19:52.235847493Z app[web.1]:         _securePending: false,
2017-04-11T12:19:52.235851526Z app[web.1]:         _newSessionPending: false,
2017-04-11T12:19:52.235855535Z app[web.1]:         _controlReleased: true,
2017-04-11T12:19:52.235859473Z app[web.1]:         _SNICallback: null,
2017-04-11T12:19:52.235863335Z app[web.1]:         servername: null,
2017-04-11T12:19:52.235867218Z app[web.1]:         npnProtocol: false,
2017-04-11T12:19:52.235871087Z app[web.1]:         alpnProtocol: false,
2017-04-11T12:19:52.235875013Z app[web.1]:         authorized: true,
2017-04-11T12:19:52.235878938Z app[web.1]:         authorizationError: null,
2017-04-11T12:19:52.235882927Z app[web.1]:         encrypted: true,
2017-04-11T12:19:52.235886938Z app[web.1]:         _events: [Object],
2017-04-11T12:19:52.235890818Z app[web.1]:         _eventsCount: 8,
2017-04-11T12:19:52.235894690Z app[web.1]:         connecting: false,
2017-04-11T12:19:52.235898841Z app[web.1]:         _hadError: false,
2017-04-11T12:19:52.235902774Z app[web.1]:         _handle: null,
2017-04-11T12:19:52.235906623Z app[web.1]:         _parent: null,
2017-04-11T12:19:52.235910530Z app[web.1]:         _host: 'gateway.discord.gg',
2017-04-11T12:19:52.235918508Z app[web.1]:         _readableState: [Object],
2017-04-11T12:19:52.235922655Z app[web.1]:         readable: false,
2017-04-11T12:19:52.235926635Z app[web.1]:         domain: null,
2017-04-11T12:19:52.235930600Z app[web.1]:         _maxListeners: 100,
2017-04-11T12:19:52.235934756Z app[web.1]:         _writableState: [Object],
2017-04-11T12:19:52.235938769Z app[web.1]:         writable: false,
2017-04-11T12:19:52.235942738Z app[web.1]:         allowHalfOpen: false,
2017-04-11T12:19:52.235946774Z app[web.1]:         destroyed: true,
2017-04-11T12:19:52.235950734Z app[web.1]:         _bytesDispatched: 30617,
2017-04-11T12:19:52.235954779Z app[web.1]:         _sockname: null,
2017-04-11T12:19:52.235958615Z app[web.1]:         _pendingData: null,
2017-04-11T12:19:52.235962604Z app[web.1]:         _pendingEncoding: '',
2017-04-11T12:19:52.235966513Z app[web.1]:         server: undefined,
2017-04-11T12:19:52.235970413Z app[web.1]:         _server: null,
2017-04-11T12:19:52.235974351Z app[web.1]:         ssl: null,
2017-04-11T12:19:52.235981999Z app[web.1]:         _requestCert: true,
2017-04-11T12:19:52.235986480Z app[web.1]:         _rejectUnauthorized: true,
2017-04-11T12:19:52.235990687Z app[web.1]:         parser: null,
2017-04-11T12:19:52.235994634Z app[web.1]:         _httpMessage: [Object],
2017-04-11T12:19:52.235998574Z app[web.1]:         read: [Function],
2017-04-11T12:19:52.236002485Z app[web.1]:         _consuming: true,
2017-04-11T12:19:52.236006374Z app[web.1]:         _idleNext: null,
2017-04-11T12:19:52.236018847Z app[web.1]:         _idlePrev: null,
2017-04-11T12:19:52.236023441Z app[web.1]:         _idleTimeout: -1,
2017-04-11T12:19:52.236027432Z app[web.1]:         write: [Function: writeAfterFIN] },
2017-04-11T12:19:52.236031581Z app[web.1]:      _ultron: Ultron { id: 0, ee: [Object] },
2017-04-11T12:19:52.236035811Z app[web.1]:      _closeReceived: true,
2017-04-11T12:19:52.236039786Z app[web.1]:      bytesReceived: 391583,
2017-04-11T12:19:52.236043813Z app[web.1]:      readyState: 3,
2017-04-11T12:19:52.236047762Z app[web.1]:      supports: { binary: true },
2017-04-11T12:19:52.236051934Z app[web.1]:      extensions: {},
2017-04-11T12:19:52.236055896Z app[web.1]:      _binaryType: 'nodebuffer',
2017-04-11T12:19:52.236059861Z app[web.1]:      _isServer: false,
2017-04-11T12:19:52.236075792Z app[web.1]:      url: 'wss://gateway.discord.gg/?v=6&encoding=json',
2017-04-11T12:19:52.237484427Z app[web.1]:      protocolVersion: 13,
2017-04-11T12:19:52.237493291Z app[web.1]:      _receiver: 
2017-04-11T12:19:52.237497515Z app[web.1]:       Receiver {
2017-04-11T12:19:52.237501622Z app[web.1]:         fragmentedBufferPool: [Object],
2017-04-11T12:19:52.237505721Z app[web.1]:         unfragmentedBufferPool: [Object],
2017-04-11T12:19:52.237509710Z app[web.1]:         extensions: {},
2017-04-11T12:19:52.237513868Z app[web.1]:         maxPayload: 0,
2017-04-11T12:19:52.237551396Z app[web.1]:         currentPayloadLength: 0,
2017-04-11T12:19:52.237555572Z app[web.1]:         state: [Object],
2017-04-11T12:19:52.237559565Z app[web.1]:         overflow: [],
2017-04-11T12:19:52.237563685Z app[web.1]:         headerBuffer: <Buffer 88 02 a9 02 00 00 00 00 08 00>,
2017-04-11T12:19:52.237568275Z app[web.1]:         expectOffset: 0,
2017-04-11T12:19:52.237572335Z app[web.1]:         expectBuffer: null,
2017-04-11T12:19:52.237588461Z app[web.1]:         expectHandler: null,
2017-04-11T12:19:52.237592757Z app[web.1]:         currentMessage: [],
2017-04-11T12:19:52.237596746Z app[web.1]:         currentMessageLength: 0,
2017-04-11T12:19:52.237600788Z app[web.1]:         messageHandlers: [],
2017-04-11T12:19:52.237604791Z app[web.1]:         dead: false,
2017-04-11T12:19:52.237623808Z app[web.1]:         processing: true,
2017-04-11T12:19:52.237627808Z app[web.1]:         onerror: [Function: onerror],
2017-04-11T12:19:52.237631929Z app[web.1]:         ontext: [Function: ontext],
2017-04-11T12:19:52.237635985Z app[web.1]:         onbinary: [Function: onbinary],
2017-04-11T12:19:52.237639985Z app[web.1]:         onclose: [Function: onclose],
2017-04-11T12:19:52.237643981Z app[web.1]:         onping: [Function: onping],
2017-04-11T12:19:52.237648125Z app[web.1]:         onpong: [Function: onpong] },
2017-04-11T12:19:52.237652780Z app[web.1]:      _sender: 
2017-04-11T12:19:52.237656766Z app[web.1]:       Sender {
2017-04-11T12:19:52.237660658Z app[web.1]:         domain: null,
2017-04-11T12:19:52.237664713Z app[web.1]:         _events: [Object],
2017-04-11T12:19:52.237684151Z app[web.1]:         _eventsCount: 1,
2017-04-11T12:19:52.237704789Z app[web.1]:         _maxListeners: 100,
2017-04-11T12:19:52.237708974Z app[web.1]:         _socket: [Object],
2017-04-11T12:19:52.237713234Z app[web.1]:         extensions: {},
2017-04-11T12:19:52.237717276Z app[web.1]:         firstFragment: true,
2017-04-11T12:19:52.237721348Z app[web.1]:         compress: false,
2017-04-11T12:19:52.237725321Z app[web.1]:         messageHandlers: [],
2017-04-11T12:19:52.237730839Z app[web.1]:         processing: false },
2017-04-11T12:19:52.237737515Z app[web.1]:      _closeCode: 1001,
2017-04-11T12:19:52.240670492Z app[web.1]:      _closeMessage: '',
2017-04-11T12:19:52.240681829Z app[web.1]:      _closeTimer: null } }

From the trace:

colo=DFW
loc=US

@idivait Do you have the full trace, including the ts and fl fields? I don't see any noticeable error spikes from the DFW datacenter at that time (I work at Cloudflare).

As suggested above, it's either an unhandled Promise rejection (common) or a connectivity issue with your bot.

@elithrar I screwed up and put the wrong trace anyhow (I've been using dokku to deploy and mistakenly did the trace on my VM rather than my server):

fl=11f81
h=discordapp.com
ip=138.197.78.214
ts=1492099624.397
visit_scheme=https
uag=curl/7.35.0
colo=EWR
spdy=off
http=http/1.1
loc=US

I also went through my code and made certain I was properly rejecting all Promises... If that ends up resolving (no pun intended) the issue, I'll post here. May take a few days, as it's generally a day or two before the disconnect happens.

I have reviewed the RFC relating to websockets and there is one point that seems relevant to this issue:

https://tools.ietf.org/html/rfc6455#section-7.3

Basically it's saying that whilst the client should not arbitrarily close the websocket, the server may. Also, section 7.4 states that the codes are optional and the interpretation of the reason is left undefined. This implies that receiving an unexpected 1000 close from the server is within spec of the RFC and that it's up the client to determine the course of action to take.

@idivait late reply, but: no issues at that colo or with that metal (11f81) during that window.

Note that @GeekyDeaks summary of the WebSocket RFC's details on server-client interactions is correct.

I should also mention that WS clients will see a 1001 "Going away" from Cloudflare when we restart our machines during a rolling deploy of new releases. The Discord.js client appears to handle those correctly.

Within limits, posting the details of /cdn-cgi/trace can be useful, but thus far the disconnects experienced in this thread seem to be unrelated to any broader network events.

Hi, I _think_ this issue might be resolved with the WebSocket rewrite I am doing; in the master branch, it's possible that the client may not resume properly and silently disconnect or remain online but not react to any events.

You can try out the rewrite branch by installing discord.js from the wsrewrite branch; npm install hydrabolt/discord.js#wsrewrite. master branch

If you experience any WebSocket-related issues after trying this out, please make a comment here

I've recently experienced the described "remains online but does not react to any events" on the master branch, so i'll be sure to try the branch out and have a watch on the console.

Discord.js's support for uWs has been improved in edf1a3e7b44231fee3cf5ab2df0c78e35e9f48e6 - it should behave nicely now! In case any of you were using uWs and experience this issue, try out the master branch and see if that fixes your problem.

For normal ws users, the master branch has a few more fixes since I last commented; could you see if these fix your problems?

Thanks!

I think you can close this. I haven't personally had any issues since the WS rewrite. I also stopped using UWS but I was having disconnecting issues without it.

Thanks for all your hard work ๐Ÿ˜„

Same here. I haven't experienced any of em lately.

I haven't had any issues since the rewrite either.

Thanks for the help guys.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

Dmitry221060 picture Dmitry221060  ยท  3Comments

xCuzImPro picture xCuzImPro  ยท  3Comments

shukriadams picture shukriadams  ยท  3Comments

tom-barnes picture tom-barnes  ยท  3Comments

ghost picture ghost  ยท  3Comments