Bot still silently disconnecting

[ericnelson0]

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

[killedWithFire9001]

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

[idivait]

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

[elithrar]

@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.

[idivait]

@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.

[GeekyDeaks]

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.

[elithrar]

@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.

[amishshah]

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

[robflop]

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.

[amishshah]

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!

[JMTK]

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 😄

[robflop]

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

[ericnelson0]

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

Thanks for the help guys.