SquidDev-CC / FAQBot-CC

A Discord bot for answering frequently asked questions regarding CC.
MIT License
7 stars 11 forks source link

Requests to tweaked.cc/index.json take too long #26

Closed SquidDev closed 3 years ago

SquidDev commented 3 years ago

We're getting an awful lot of failures in the logs recently:

Graph showing failures over the last 7 days

[2021-03-15 04:13:12.741] [INFO/cached_request] Fetching https://tweaked.cc/index.json
[2021-03-15 04:13:17.877] [INFO/cached_request] ETag matched, doing nothing
[2021-03-15 04:13:17.878] [INFO/ccfaq.commands.docs] event=search search="parallel.waitForAny"
[2021-03-15 04:13:17.892] [INFO/ccfaq.commands.docs] event=search search="parallel.waitForAny"
[2021-03-15 04:13:18.130] [ERROR/discord_slash] An exception has occurred while executing command `docs`:
Traceback (most recent call last):
  File "/home/vampy/.cache/pypoetry/virtualenvs/faqbot-cc-VsnhxLU2-py3.8/lib/python3.8/site-packages/discord_slash/client.py", line 661, in on_socket_response
    await selected_cmd.invoke(ctx, *args)
  File "/src/ccfaq/commands/docs.py", line 124, in doc_slash
    await self._search_docs(ctx, name, lambda x: f"https://tweaked.cc/{x['url']}")
  File "/src/ccfaq/commands/docs.py", line 64, in _search_docs
    await ctx.send(embeds=[_embed(methods[search_k], link)])
  File "/home/vampy/.cache/pypoetry/virtualenvs/faqbot-cc-VsnhxLU2-py3.8/lib/python3.8/site-packages/discord_slash/model.py", line 125, in send
    resp = await self._http.post(base, self._discord.user.id, self.interaction_id, self.__token, initial)
  File "/home/vampy/.cache/pypoetry/virtualenvs/faqbot-cc-VsnhxLU2-py3.8/lib/python3.8/site-packages/discord/http.py", line 243, in request
    raise NotFound(r, data)
discord.errors.NotFound: 404 Not Found (error code: 10062): Unknown interaction

The issue here is that the request is taking 5 seconds (04:13:12.7 to 04:13:17.9). I'm not sure why - curl takes 0.2s from the same container. Looking at our logs, we can see the actual request is pretty much instantaneous.

2021-03-15 04:13:17 server=tweaked.cc remote=172.18.0.4 request="GET /index.json HTTP/1.1" status=304 body_size=739 request_time=0.000

The 5s delay means that our token for posting a slash command response has timed out, and so we never respond to the user.

I think there's a couple of solutions here:

SquidDev commented 3 years ago

Another error graph over the last 4 days

Still errors occurring relatively often (note the bot isn't used that much anyway, so there's a good chunk of requests failing).

I've migrated the bot to run under podman instead (makes it easier to manage via systemd). Curious to see if this effects the network connectivity at all.

SquidDev commented 3 years ago
[2021-03-22 20:50:35.590] [INFO/ccfaq.commands.docs] event=search search="textutils.serialize"
[2021-03-22 20:50:35.586] [INFO/ccfaq.commands.docs] event=search search="textutils.serialise"
[2021-03-22 20:50:35.579] [INFO/cached_request] Finished request.
[2021-03-22 20:50:35.079] [INFO/ccfaq] Fired doc by XXX
[2021-03-22 20:50:24.026] [INFO/cached_request] Fetching https://tweaked.cc/index.json
[2021-03-22 20:50:24.025] [INFO/ccfaq] Fired doc by XXX

Reopening, as the poor latency does still cause confusion when people use %doc instead of /docs. Here we can see someone triggering the command once, getting irritated and triggering it again. Understandable - 10s of latency is not good!

We could try switching over to aiohttp - would mean we don't need threads and might be better than urllib. Still don't know where the latency is :/.

SquidDev commented 3 years ago

The latency appeared to be in DNS resolution. I've updated my DNS config to use a different server and this appears to have resolved the issue.