Skip to content

Conversation

@Exirel
Copy link
Contributor

@Exirel Exirel commented Mar 24, 2023

Description

Tin. Based on #2430, closes #2350.

To elaborate a bit: I realized that having a connection error and other uncaught exception in the run-forever loop (await read task, await write task) would lock the bot, and so it's not just friendly error messages, it is also a better exception handling.

Checklist

  • I have read CONTRIBUTING.md
  • I can and do license this contribution under the EFLv2
  • No issues are reported by make qa (runs make quality and make test)
  • I have tested the functionality of the things this change touches

@Exirel Exirel added this to the 8.0.0 milestone Mar 24, 2023
Copy link
Member

@dgw dgw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm nitpicking… Maybe the final commit/PR title line should say "exceptions in the run-forever loop"?

@Exirel Exirel force-pushed the irc-backend-connection-error branch from 246d766 to c1e0cc7 Compare April 8, 2023 22:53
@Exirel Exirel force-pushed the irc-backend-connection-error branch from ba1a4ac to ad21253 Compare April 19, 2023 08:53
@dgw
Copy link
Member

dgw commented May 2, 2023

Is this in a state I could check out on one of my bots for testing? Seems related to #2449 and #2407, perhaps others.

@Exirel
Copy link
Contributor Author

Exirel commented May 3, 2023

Is this in a state I could check out on one of my bots for testing? Seems related to #2449 and #2407, perhaps others.

As said on IRC: yes go on! And btw, #2430 is approved and ready to merge, that would make this PR only 1 commit. 😄

@Exirel Exirel marked this pull request as ready for review May 3, 2023 12:00
Copy link
Member

@dgw dgw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Had to wait quite a while for my test bots to time out, but they both disconnected due to ping timeout at the same minute, and both reconnected automatically about 30 seconds later with no manual intervention. Win for this patch!

Both affected bots were started a few seconds apart, and pinged out a few seconds apart, pointing to an actual, brief, network issue as the root cause. In both bots' logs (example below), there is clearly time between the final PING and "Reached timeout" for another PING attempt to avert closing the socket after only one PONG is missed. It makes me think Sopel's ping timeout detection might warrant some further tweaks, perhaps in 8.1.

[2023-05-19 09:29:34,886] sopel.irc.backends   DEBUG    - Sending PING after 54.0s of inactivity.
[2023-05-19 09:30:29,037] sopel.irc.backends   DEBUG    - Sending PING after 54.0s of inactivity.
[2023-05-19 09:31:35,074] sopel.irc.backends   WARNING  - Reached timeout (120.0s); closing connection.
[2023-05-19 09:31:35,075] sopel.irc.backends   DEBUG    - Read task was cancelled.
[2023-05-19 09:31:35,076] sopel.irc.backends   DEBUG    - Shutting down writer.
[2023-05-19 09:31:40,743] sopel.irc.backends   ERROR    - Unexpected error while shutting down socket.
[2023-05-19 09:31:40,753] sopel.irc.backends   DEBUG    - All clear, exiting now.
[2023-05-19 09:31:40,758] sopel.irc.backends   INFO     - Connection backend stopped.
[2023-05-19 09:31:40,758] sopel.bot            INFO     - Shutting down
[2023-05-19 09:31:40,759] sopel.bot            INFO     - Stopping the Job Scheduler.
[2023-05-19 09:31:40,865] sopel.bot            INFO     - Job Scheduler stopped.
[2023-05-19 09:31:40,866] sopel.plugins.jobs   DEBUG    - Successfully unregistered all jobs
[2023-05-19 09:31:40,866] sopel.bot            INFO     - Calling shutdown for 2 plugins.
[2023-05-19 09:31:40,866] sopel.bot            DEBUG    - Calling sopel.modules.find.shutdown
[2023-05-19 09:31:40,867] sopel.bot            DEBUG    - Calling sopel.coretasks.shutdown
[2023-05-19 09:31:40,867] sopel.cli.run        WARNING  - Disconnected. Reconnecting in 20 seconds...
[2023-05-19 09:32:00,908] sopel.bot            INFO     - Loading plugins...

@dgw dgw linked an issue May 21, 2023 that may be closed by this pull request
@dgw dgw added the Bugfix Generally, PRs that reference (and fix) one or more issue(s) label May 21, 2023
@dgw dgw changed the base branch from master to common-connection-errors-output May 23, 2023 07:39
@dgw dgw changed the base branch from common-connection-errors-output to master May 23, 2023 07:39
@dgw
Copy link
Member

dgw commented May 23, 2023

Base branch gymnastics to make GH update its (cached, I assume) idea of which commits are new in this PR. Can merge now.

@dgw dgw merged commit 3d85225 into sopel-irc:master May 23, 2023
@Exirel Exirel deleted the irc-backend-connection-error branch June 15, 2023 20:39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Bugfix Generally, PRs that reference (and fix) one or more issue(s) Core/Networking Tweak

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Hang after ping timeout w/asyncio Bot should properly handle ConnectionResetError

2 participants