discord.js icon indicating copy to clipboard operation
discord.js copied to clipboard

Spam reconnection

Open JusteLoneWolf opened this issue 4 years ago • 56 comments

Please describe the problem you are having in as much detail as possible:

Since several weeks (about 3 weeks) my spam bot reconnection to Discord, it happens a few hours or a few minutes after the launch of the shards (Less shards the more it will take time to spam reconnection) I have not made any modification for 4 weeks on my bot so I wonder if it comes from discord directly or from my code.

I have already run it locally and same problem and several of my friends have the same problem on a different library of discord (eris) but also on discord.js

Namely I use Discord.js 11.6.4

I currently have 25 servers so I launched my bot plus 25 shards I had no problem for 2-3 minutes then the shards were restarted one after the other.

Namely that I'm not testing another bot on the same VPS or PC

https://imgur.com/c2Xbf0l.png

Further details:

  • discord.js version: 11.6.5
  • Node.js version: 12.16.1
  • Operating system: Linux Debian (VPS) Windows 10 (Local)
  • Priority this issue should have - please be realistic and elaborate if possible: On a scale of 1 to 10 I would say 6/10

Translated with www.DeepL.com/Translator (free version)

JusteLoneWolf avatar Apr 18 '20 08:04 JusteLoneWolf

https://imgur.com/tManVca.png another image to illustrate (5 to 10 messages per minute)

JusteLoneWolf avatar Apr 18 '20 08:04 JusteLoneWolf

that is expected behaviour. Discord pushed a gateway change that will regularly reconnect you.

castdrian avatar Apr 18 '20 08:04 castdrian

As far as I'm concerned, it's a reconnection every 1 or 2 minutes, I don't think that's really normal.

JusteLoneWolf avatar Apr 18 '20 08:04 JusteLoneWolf

You can read more about it from the announcement in the Discord API Server

monbrey avatar Apr 18 '20 08:04 monbrey

Firstly: if you have 25 guilds, you do NOT need 25 shards.. you need 1. You can start sharding when you get to 2.5k servers

Secondly; Discord has now made a change in the gateway API where they will ask connections to reconnect at random times. We implement that accordingly in both v11 and v12 of discord.js, the latter logging when it happens.

Besides, this isn't really a problem as the bot RESUMED, which doesn't drain the Identify Limit.

TL;DR: for 25 guilds you don't need to shard to 25 shards, what you've presented is normal, no need to worry about it!

vladfrangu avatar Apr 18 '20 09:04 vladfrangu

I know a shards is 2500 guild if I just wanted to see if it was a waiter or something else that was a problem.

Plus if I want to make shard I do it that way so I don't have to modify all my files once I shard.

The "it's not really a problem because the bot RESUMED" is sure but during this moment or it is connecting it can take between 3-5 seconds before answering or even not answering.

But when I'm on a shard it happens after 5 hours of uptime and then it reconnects every 1 minute, so if it was I think it would do it as soon as it was launched.

JusteLoneWolf avatar Apr 18 '20 09:04 JusteLoneWolf

image

Are you really sure that's normal?

JusteLoneWolf avatar Apr 18 '20 18:04 JusteLoneWolf

Jake said bots are now disconnected randomly every 15 minutes to 4 hours, and should automatically resume. The bot shouldn't actually restart, it should just reconnect to the gateway, and as Vlad said, it shouldn't contribute to the connection limit, are you sure there isn't something in your code causing the whole bot to restart?

advaith1 avatar Apr 18 '20 20:04 advaith1

Currently I haven't changed the code for about 4 weeks and before that everything was working fine and the bot was reconnecting every 15-20 minutes or so but now it's every minute to 2 and so from one day to the next another person has exactly the same problem as me and he's waiting for a rewrite of the Eris library but he's not sure if it solves the problem.

JusteLoneWolf avatar Apr 18 '20 21:04 JusteLoneWolf

Just the number of shards I changed to see if that was the problem but then I went back to 1 shard.

JusteLoneWolf avatar Apr 18 '20 21:04 JusteLoneWolf

still, you don't need 25 shards for 25 servers

crispyaus avatar Apr 19 '20 07:04 crispyaus

zechaos031 commented 13 hours ago Just the number of shards I changed to see if that was the problem but then I went back to 1 shard.

JusteLoneWolf avatar Apr 19 '20 10:04 JusteLoneWolf

To make it simpler, can you please:

  1. Get some debug logs (listen to the client debug event, more info in #3201)
  2. Check if the same issue can be seen with v12 of discord.js, with debug logs attached as well as #3201 shows

vladfrangu avatar Apr 19 '20 12:04 vladfrangu

I already listen debug event and i ave just this image

This image has already been posted above.

JusteLoneWolf avatar Apr 19 '20 14:04 JusteLoneWolf

I am commenting this because it seems like a relevant issue to the conversation, but I've noticed this re-connecting thing happening for me randomly too for a few weeks now. My bot only has 1 shard. Most of the time it starts happening as soon as my bot connects to the gateway. image

And while I'm on this topic, I'm not sure if this is caused from the same issue but I have also noticed that as soon as my bot connects to the gateway a lot of times servers will be reported as unavailable and the guild object name property will just be undefined. It's not like just one server being reported as unavailable. It spams the same servers repeatedly until the bot fully connects to the gateway. image

Just as a note, the same issue occurs on all 4 of my bots.

BannerBomb avatar Apr 20 '20 04:04 BannerBomb

Running into the same issue. The bot runs fine for around an hour or two then begins to disconnect & reconnect continually.

Only in 1 server and does not use sharding.

DJS Version 11.6.4 Node Version 10.18.1

It doesn't appear to impact the bot responding to messages but can't confirm.

Seems to have started since that Discord API update referenced before

You can read more about it from the announcement in the Discord API Server

image

AdamMcD94 avatar Apr 23 '20 16:04 AdamMcD94

I don't know if only v11 has this issue or v12 too, can you try it and let me know if it also breaks?

vladfrangu avatar Apr 23 '20 16:04 vladfrangu

according to the message above he has the same problem (BannerBomb) because SHARD RECONNECTING, and SHARD RESUME is only on discordjs v12 but I'm gonna try

JusteLoneWolf avatar Apr 24 '20 11:04 JusteLoneWolf

miss click sorry

JusteLoneWolf avatar Apr 24 '20 11:04 JusteLoneWolf

Hey,

My bot is now offline after 6 days of uptime and I having this error un debug event image

JusteLoneWolf avatar Apr 26 '20 22:04 JusteLoneWolf

and I having the last error on my console

  target: WebSocket {
    _events: [Object: null prototype] {
      message: [Function],
      open: [Function],
      error: [Function],
      close: [Function]
    },
    _eventsCount: 4,
    _maxListeners: undefined,
    readyState: 2,
    protocol: '',
    _binaryType: 'nodebuffer',
    _closeFrameReceived: false,
    _closeFrameSent: false,
    _closeMessage: '',
    _closeTimer: null,
    _closeCode: 1006,
    _extensions: {},
    _receiver: null,
    _sender: null,
    _socket: null,
    _isServer: false,
    _redirects: 0,
    url: 'wss://gateway.discord.gg/?v=6&encoding=json',
    _req: null,
    [Symbol(kCapture)]: false
  },
  type: 'error',
  message: 'socket hang up',
  error: Error: socket hang up
      at connResetException (internal/errors.js:604:14)
      at TLSSocket.socketOnEnd (_http_client.js:460:23)
      at TLSSocket.emit (events.js:323:22)
      at endReadableNT (_stream_readable.js:1204:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
}
ErrorEvent {
  target: WebSocket {
    _events: [Object: null prototype] {
      message: [Function],
      open: [Function],
      error: [Function],
      close: [Function]
    },
    _eventsCount: 4,
    _maxListeners: undefined,
    readyState: 2,
    protocol: '',
    _binaryType: 'nodebuffer',
    _closeFrameReceived: false,
    _closeFrameSent: false,
    _closeMessage: '',
    _closeTimer: null,
    _closeCode: 1006,
    _extensions: {},
    _receiver: null,
    _sender: null,
    _socket: null,
    _isServer: false,
    _redirects: 0,
    url: 'wss://gateway.discord.gg/?v=6&encoding=json',
    _req: null,
    [Symbol(kCapture)]: false
  },
  type: 'error',
  message: 'socket hang up',
  error: Error: socket hang up
      at connResetException (internal/errors.js:604:14)
      at TLSSocket.socketOnEnd (_http_client.js:460:23)
      at TLSSocket.emit (events.js:323:22)
      at endReadableNT (_stream_readable.js:1204:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21) {
    code: 'ECONNRESET'
  }
}

a presicer that I'm using pm2 and that pm2 doesn't detect an error (process id is 0)

image

JusteLoneWolf avatar Apr 26 '20 22:04 JusteLoneWolf

Other than BannerBomb who's already on v12, can any/all of you try v12 and report if this is still an issue? Thanks <3

vladfrangu avatar Apr 26 '20 22:04 vladfrangu

I'll try that right now. I'll text you back if anything happens.

JusteLoneWolf avatar Apr 26 '20 22:04 JusteLoneWolf

Re after feew minutes I have this in logs image

in discord.js v12.2.0

JusteLoneWolf avatar Apr 27 '20 00:04 JusteLoneWolf

No issue on our side, it's Discord asking for reconnects and we resume accordingly 🤷‍♂️

vladfrangu avatar Apr 27 '20 00:04 vladfrangu

Very strange 😕

JusteLoneWolf avatar Apr 27 '20 00:04 JusteLoneWolf

It should make you reconnect randomly every 15 mins to 4 hrs

advaith1 avatar Apr 27 '20 00:04 advaith1

The issue is it seems to be doing this every minute as opposed to every 15. The bot is also responsive during this time.

As an example, here's the log after the bot has been doing this for 48 hours. The heartbeats are also apparently repeating? It seems more like there's a strange looping issue within the reconnection debug? The 4 duplicated "sending a heartbeat" messages appear in the log at the same time so it's not a case of one failing and it attempting to send another. The fact the bot remains responsive I'm not sure it's even disconnecting/reconnecting when it displays this message.

image

AdamMcD94 avatar Apr 27 '20 00:04 AdamMcD94

Alright, so:

  1. If you're using v11 and encountering WS issues, upgrade to v12 and report back (after doing the instructions noted in #3201) if the issues persist
  2. Discord now sends a RECONNECT Op Code (see https://discordapp.com/developers/docs/topics/gateway#reconnect) at random times. d.js handles this appropriately and attempts a RESUME (see https://discordapp.com/developers/docs/topics/gateway#resuming). Resumes DO NOT count towards your identify limit (for 99% of you, said limit is 1000/24 hour), so you're fine. Generally, WS shard closing and resuming is FINE, to be expected and most of the time nothing to worry about! HOWEVER if your shards are sucking up your identify limit like nobody's business, then DEFINITELY report it with attached debug logs

vladfrangu avatar Apr 27 '20 00:04 vladfrangu

In the process of rewriting to support v12. Once that's all set I'll let you know if it fixes the issue.

Some additional information;

v11 is handling the OpCode 7 (WebSocket close 1001) Reconnect request as expected, however, it begins the odd reconnect debug loop.

Here is the debug log with some additional logging on the event.

[ws] [connection] Heartbeat acknowledged, latency of 110ms
{ t: null, s: null, op: 7, d: null }
[ws] [connection] Attemping to reconnect in 5500ms...
[ws] [connection] Connecting to wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Connected to gateway wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Attempting to resume session a1439a15ac571117aa42bf1c7b5ba3af
[ws] [connection] Setting a heartbeat interval for 41250ms
[ws] [connection] RESUMED | replayed 93 events.
[ws] [connection] Sending a heartbeat
[ws] [connection] Heartbeat acknowledged, latency of 114ms
CloseEvent {
  target:
   WebSocket {
     _events:
      [Object: null prototype] {
        message: [Function],
        open: [Function],
        error: [Function],
        close: [Function] },
     _eventsCount: 4,
     _maxListeners: undefined,
     readyState: 3,
     protocol: '',
     _binaryType: 'nodebuffer',
     _closeFrameReceived: true,
     _closeFrameSent: true,
     _closeMessage: 'Discord WebSocket requesting client reconnect.',
     _closeTimer:
      Timeout {
        _called: false,
        _idleTimeout: -1,
        _idlePrev: null,
        _idleNext: null,
        _idleStart: 4898939,
        _onTimeout: null,
        _timerArgs: undefined,
        _repeat: null,
        _destroyed: false,
        [Symbol(unrefed)]: false,
        [Symbol(asyncId)]: 1014,
        [Symbol(triggerId)]: 49 },
     _closeCode: 1001,
     _extensions: {},
     _receiver:
      Receiver {
        _writableState: [WritableState],
        writable: false,
        _events: [Object: null prototype] {},
        _eventsCount: 0,
        _maxListeners: undefined,
        _binaryType: 'nodebuffer',
        _extensions: {},
        _maxPayload: 104857600,
        _bufferedBytes: 0,
        _buffers: [],
        _compressed: false,
        _payloadLength: 48,
        _mask: undefined,
        _fragmented: 0,
        _masked: false,
        _fin: true,
        _opcode: 8,
        _totalPayloadLength: 0,
        _messageLength: 0,
        _fragments: [],
        _state: 0,
        _loop: false,
        [Symbol(websocket)]: [Circular] },
     _sender:
      Sender {
        _extensions: {},
        _socket: [TLSSocket],
        _firstFragment: true,
        _compress: false,
        _bufferedBytes: 0,
        _deflating: false,
        _queue: [] },
     _socket:
      TLSSocket {
        _tlsOptions: [Object],
        _secureEstablished: true,
        _securePending: false,
        _newSessionPending: false,
        _controlReleased: true,
        _SNICallback: null,
        servername: 'gateway.discord.gg',
        alpnProtocol: false,
        authorized: true,
        authorizationError: null,
        encrypted: true,
        _events: [Object],
        _eventsCount: 4,
        connecting: false,
        _hadError: false,
        _handle: null,
        _parent: null,
        _host: 'gateway.discord.gg',
        _readableState: [ReadableState],
        readable: false,
        _maxListeners: undefined,
        _writableState: [WritableState],
        writable: false,
        allowHalfOpen: false,
        _sockname: null,
        _pendingData: null,
        _pendingEncoding: '',
        server: undefined,
        _server: null,
        ssl: null,
        _requestCert: true,
        _rejectUnauthorized: true,
        parser: null,
        _httpMessage: null,
        timeout: 0,
        write: [Function: writeAfterFIN],
        [Symbol(res)]: null,
        [Symbol(asyncId)]: 49,
        [Symbol(lastWriteQueueSize)]: 0,
        [Symbol(timeout)]: null,
        [Symbol(kBytesRead)]: 71917,
        [Symbol(kBytesWritten)]: 3134,
        [Symbol(connect-options)]: [Object],
        [Symbol(websocket)]: undefined },
     _isServer: false,
     _redirects: 0,
     url: 'wss://gateway.discord.gg/?v=6&encoding=json',
     _req: null },
  type: 'close',
  wasClean: true,
  reason: 'Discord WebSocket requesting client reconnect.',
  code: 1001 }
[ws] [connection] Server closed the WebSocket connection: 1001
[ws] [connection] Clearing heartbeat interval
[ws] [connection] Attemping to reconnect in 5500ms...
[ws] [connection] Connecting to wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Connected to gateway wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Attempting to resume session a1439a15ac571117aa42bf1c7b5ba3af
[ws] [connection] Setting a heartbeat interval for 41250ms
[ws] [connection] RESUMED | replayed 1 events.
[ws] [connection] Sending a heartbeat
[ws] [connection] Heartbeat acknowledged, latency of 110ms
[ws] [connection] Sending a heartbeat
[ws] [connection] Heartbeat acknowledged, latency of 112ms
[ws] [connection] Sending a heartbeat
[ws] [connection] Heartbeat acknowledged, latency of 111ms
CloseEvent {
  target:
   WebSocket {
     _events:
      [Object: null prototype] {
        message: [Function],
        open: [Function],
        error: [Function],
        close: [Function] },
     _eventsCount: 4,
     _maxListeners: undefined,
     readyState: 3,
     protocol: '',
     _binaryType: 'nodebuffer',
     _closeFrameReceived: true,
     _closeFrameSent: true,
     _closeMessage: '',
     _closeTimer:
      Timeout {
        _called: false,
        _idleTimeout: -1,
        _idlePrev: null,
        _idleNext: null,
        _idleStart: 4950242,
        _onTimeout: null,
        _timerArgs: undefined,
        _repeat: null,
        _destroyed: false,
        [Symbol(unrefed)]: false,
        [Symbol(asyncId)]: 1071,
        [Symbol(triggerId)]: 987 },
     _closeCode: 1000,
     _extensions: {},
     _receiver:
      Receiver {
        _writableState: [WritableState],
        writable: false,
        _events: [Object: null prototype] {},
        _eventsCount: 0,
        _maxListeners: undefined,
        _binaryType: 'nodebuffer',
        _extensions: {},
        _maxPayload: 104857600,
        _bufferedBytes: 0,
        _buffers: [],
        _compressed: false,
        _payloadLength: 2,
        _mask: undefined,
        _fragmented: 0,
        _masked: false,
        _fin: true,
        _opcode: 8,
        _totalPayloadLength: 0,
        _messageLength: 0,
        _fragments: [],
        _state: 0,
        _loop: false,
        [Symbol(websocket)]: [Circular] },
     _sender:
      Sender {
        _extensions: {},
        _socket: [TLSSocket],
        _firstFragment: true,
        _compress: false,
        _bufferedBytes: 0,
        _deflating: false,
        _queue: [] },
     _socket:
      TLSSocket {
        _tlsOptions: [Object],
        _secureEstablished: true,
        _securePending: false,
        _newSessionPending: false,
        _controlReleased: true,
        _SNICallback: null,
        servername: 'gateway.discord.gg',
        alpnProtocol: false,
        authorized: true,
        authorizationError: null,
        encrypted: true,
        _events: [Object],
        _eventsCount: 4,
        connecting: false,
        _hadError: false,
        _handle: null,
        _parent: null,
        _host: 'gateway.discord.gg',
        _readableState: [ReadableState],
        readable: false,
        _maxListeners: undefined,
        _writableState: [WritableState],
        writable: false,
        allowHalfOpen: false,
        _sockname: null,
        _pendingData: null,
        _pendingEncoding: '',
        server: undefined,
        _server: null,
        ssl: null,
        _requestCert: true,
        _rejectUnauthorized: true,
        parser: null,
        _httpMessage: null,
        timeout: 0,
        write: [Function: writeAfterFIN],
        [Symbol(res)]: null,
        [Symbol(asyncId)]: 987,
        [Symbol(lastWriteQueueSize)]: 0,
        [Symbol(timeout)]: null,
        [Symbol(kBytesRead)]: 976,
        [Symbol(kBytesWritten)]: 423,
        [Symbol(connect-options)]: [Object],
        [Symbol(websocket)]: undefined },
     _isServer: false,
     _redirects: 0,
     url: 'wss://gateway.discord.gg/?v=6&encoding=json',
     _req: null },
  type: 'close',
  wasClean: true,
  reason: '',
  code: 1000 }
[ws] [connection] Server closed the WebSocket connection: 1000
[ws] [connection] Clearing heartbeat interval
[ws] [connection] Attemping to reconnect in 5500ms...
[ws] [connection] Sending a heartbeat
[ws] [connection] Heartbeat acknowledged, latency of 117ms
[ws] [connection] Connecting to wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Connected to gateway wss://gateway.discord.gg/?v=6&encoding=json
[ws] [connection] Attempting to resume session a1439a15ac571117aa42bf1c7b5ba3af
[ws] [connection] Setting a heartbeat interval for 41250ms
[ws] [connection] RESUMED | replayed 2 events.

It continues to display code 1000 connection resets every 3 heartbeat intervals.

Possible theory - When djs receives Opcode 7 it begins the reconnection. Once reconnected it replays events which includes a close event (the expected 1001 from Discord requesting the reconnection) which also begins another reconnection attempt.

AdamMcD94 avatar Apr 27 '20 04:04 AdamMcD94