Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bot still silently disconnecting #1233

Closed
ericnelson0 opened this issue Feb 27, 2017 · 62 comments
Closed

Bot still silently disconnecting #1233

ericnelson0 opened this issue Feb 27, 2017 · 62 comments

Comments

@ericnelson0
Copy link

ericnelson0 commented Feb 27, 2017

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

@devsnek
Copy link
Member

devsnek commented Feb 27, 2017

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.

@ericnelson0
Copy link
Author

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.

@Georgia10
Copy link

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

@amishshah
Copy link
Member

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

@Olian04
Copy link

Olian04 commented Feb 27, 2017

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

@iCrawl
Copy link
Member

iCrawl commented Feb 27, 2017

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.

@Georgia10
Copy link

Georgia10 commented Feb 27, 2017

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.

@CyberiumShadow
Copy link
Contributor

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

but its kinda hacky in its implementation

@devsnek
Copy link
Member

devsnek commented Feb 27, 2017

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))

@btw6391
Copy link

btw6391 commented Mar 2, 2017

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

@devsnek
Copy link
Member

devsnek commented Mar 2, 2017

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

@tomforster
Copy link

tomforster commented Mar 2, 2017

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.

@devsnek
Copy link
Member

devsnek commented Mar 2, 2017

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

@tomforster
Copy link

loc=GB
colo=LHR

@devsnek
Copy link
Member

devsnek commented Mar 2, 2017

thx

@robflop
Copy link

robflop commented Mar 3, 2017

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.

@eaaliprantis
Copy link

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.

@robflop
Copy link

robflop commented Mar 3, 2017

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

@eaaliprantis
Copy link

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

@robflop
Copy link

robflop commented Mar 3, 2017

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

@robflop
Copy link

robflop commented Mar 3, 2017

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
}

@devsnek
Copy link
Member

devsnek commented Mar 3, 2017

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

@robflop
Copy link

robflop commented Mar 3, 2017

loc=LT & colo=FRA on my vps.

@tripl3dogdare
Copy link

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.

@bdistin
Copy link
Contributor

bdistin commented Mar 6, 2017

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

@devsnek
Copy link
Member

devsnek commented Mar 6, 2017

@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
Copy link
Contributor

bdistin commented Mar 16, 2017

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.

@tomforster
Copy link

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.

@JMTK
Copy link
Contributor

JMTK commented Mar 21, 2017

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?

@robflop
Copy link

robflop commented Mar 21, 2017

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

@robflop
Copy link

robflop commented Mar 21, 2017

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

@meldsza
Copy link

meldsza commented Apr 3, 2017

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

@devsnek
Copy link
Member

devsnek commented Apr 3, 2017

@meldsza that has nothing to do with this issue ☹️

@killedWithFire9001
Copy link

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

@idivait
Copy link

idivait commented Apr 12, 2017

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
Copy link

@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
Copy link

idivait commented Apr 13, 2017

@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
Copy link

GeekyDeaks commented Apr 14, 2017

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
Copy link

elithrar commented Apr 16, 2017

@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
Copy link
Member

amishshah commented Apr 25, 2017

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
Copy link

robflop commented Apr 25, 2017

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
Copy link
Member

Discord.js's support for uWs has been improved in edf1a3e - 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
Copy link
Contributor

JMTK commented May 7, 2017

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
Copy link

robflop commented May 7, 2017

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

@ericnelson0
Copy link
Author

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

Thanks for the help guys.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests