shuppet / raku-api-discord

Raku module for interacting with the Discord API.
https://shuppet.com
BSD 3-Clause "New" or "Revised" License
30 stars 3 forks source link

Reconnect doesn't work on missed heartbeat #35

Closed Altreus closed 4 years ago

Altreus commented 4 years ago

Seems like we never find out if the websocket was closed:


...

[TRACE(anon 3)] Cro::WebSocket::MessageSerializer EMIT WebSocket Frame - Continuation

[TRACE(anon 3)] Cro::WebSocket::FrameSerializer EMIT TCP Message
  80 80 9a 03 dd 47                                .....G

[TRACE(anon 1)] Cro::HTTP::RequestSerializer EMIT TCP Message
  80 80 9a 03 dd 47                                .....G

« ♥
[TRACE(anon 3)] SetBodySerializers EMIT WebSocket Message - Binary

[TRACE(anon 3)] Cro::WebSocket::MessageSerializer EMIT WebSocket Frame - Text
  7b 0a 20 20 22 6f 70 22 3a 20 31 2c 0a 20 20 22  {.  "op": 1,.  "
  64 22 3a 20 6e 75 6c 6c 0a 7d                    d": null.}

[TRACE(anon 3)] Cro::WebSocket::FrameSerializer EMIT TCP Message
  01 9a 00 f0 4c 69 7b fa 6c 49 22 9f 3c 4b 3a d0  ....Li{.lI".<K:.
  7d 45 0a d0 6c 4b 64 d2 76 49 6e 85 20 05 0a 8d  }E..lKd.vIn. ...

[TRACE(anon 1)] Cro::HTTP::RequestSerializer EMIT TCP Message
  01 9a 00 f0 4c 69 7b fa 6c 49 22 9f 3c 4b 3a d0  ....Li{.lI".<K:.
  7d 45 0a d0 6c 4b 64 d2 76 49 6e 85 20 05 0a 8d  }E..lKd.vIn. ...

[TRACE(anon 3)] Cro::WebSocket::MessageSerializer EMIT WebSocket Frame - Continuation

[TRACE(anon 3)] Cro::WebSocket::FrameSerializer EMIT TCP Message
  80 80 07 56 eb aa                                ...V..

[TRACE(anon 1)] Cro::HTTP::RequestSerializer EMIT TCP Message
  80 80 07 56 eb aa                                ...V..

[TRACE(anon 1)] Cro::TLS::Connector EMIT TCP Message
  88 18 0f a4 41 75 74 68 65 6e 74 69 63 61 74 69  ....Authenticati
  6f 6e 20 66 61 69 6c 65 64 2e                    on failed.

[TRACE(anon 2)] Cro::WebSocket::FrameParser EMIT WebSocket Frame - Close
  0f a4 41 75 74 68 65 6e 74 69 63 61 74 69 6f 6e  ..Authentication
  20 66 61 69 6c 65 64 2e                           failed.

[TRACE(anon 2)] Cro::WebSocket::MessageParser EMIT WebSocket Message - Close

[TRACE(anon 2)] SetBodyParsers EMIT WebSocket Message - Close

[TRACE(anon 3)] SetBodySerializers EMIT WebSocket Message - Close

[TRACE(anon 1)] Cro::TLS::Connector DONE
[TRACE(anon 3)] Cro::WebSocket::MessageSerializer EMIT WebSocket Frame - Close
  e8 03                                            ..

[TRACE(anon 2)] Cro::WebSocket::FrameParser DONE
[TRACE(anon 2)] Cro::WebSocket::MessageParser DONE
[TRACE(anon 2)] SetBodyParsers DONE
[TRACE(anon 1)] Cro::HTTP::ResponseParser DONE
[TRACE(anon 3)] Cro::WebSocket::FrameSerializer EMIT TCP Message
  88 82 6d 47 2c a9 85 44                          ..mG,..D

[TRACE(anon 3)] SetBodySerializers DONE
[TRACE(anon 3)] Cro::WebSocket::MessageSerializer DONE
[TRACE(anon 3)] Cro::WebSocket::FrameSerializer DONE
« ♥
Unhandled exception in code scheduled on thread 9
Cannot send on a closed WebSocket connection
  in method ensure-open at /home/adouglas/src/rakudo-2019.07.1/install/share/perl6/site/sources/A9296BB9102DC15B5CB04F24DCDE4D337413E54A (Cro::WebSocket::Client::Connection) line 172
  in method send at /home/adouglas/src/rakudo-2019.07.1/install/share/perl6/site/sources/A9296BB9102DC15B5CB04F24DCDE4D337413E54A (Cro::WebSocket::Client::Connection) line 106
  in method send at /home/adouglas/src/rakudo-2019.07.1/install/share/perl6/site/sources/A9296BB9102DC15B5CB04F24DCDE4D337413E54A (Cro::WebSocket::Client::Connection) line 112
  in block  at /home/adouglas/src/p6-api-discord/lib/API/Discord/Connection.pm6 (API::Discord::Connection) line 185
Altreus commented 4 years ago

This came from the fix-existing-comms branch; behaviour on master is weirder

Altreus commented 4 years ago

This seems to have faded away. We should try to test it.

Altreus commented 4 years ago

This still happens, but it can take a long time.

« ♥
« ♥
Unhandled exception in code scheduled on thread 8
Cannot send on a closed WebSocket connection
  in method ensure-open at /home/altreus/rakus/rakudo-2020.02.1/share/perl6/site/sources/2168AC86EF429E6C017A051527384770C7281F2E (Cro::WebSocket::Client::Connection) line 171                 
  in method send at /home/altreus/rakus/rakudo-2020.02.1/share/perl6/site/sources/2168AC86EF429E6C017A051527384770C7281F2E (Cro::WebSocket::Client::Connection) line 105                        
  in block  at /home/altreus/rakus/rakudo-2020.02.1/share/perl6/site/sources/72317C3AF2317FAA95422F5F9CECEEC782156F90 (API::Discord::Connection) line 182                                       
Altreus commented 4 years ago

This is probably caused by the heartbeat being sent, because nothing else was being done.

Altreus commented 4 years ago

Observe that we get two outbound heartbeat requests and no inbound. It looks like we send the next heartbeat request, instead of trying to reconnect because we didn't hear back.

Altreus commented 4 years ago

I'm extending this issue to reconnection in general. I think I've managed to get the two issues to converge at the same point.

Here is my current output from Connection.pm6 when Discord tells us to reconnect:

reconnect                                                                                                      
Closing connection
closed
connect ...
New websocket connection...
Done
Stopping message handler
Starting message handler

Now nothing happens - but it should be responding to events from the new websocket!

Altreus commented 4 years ago

Closing this in favour of #41