automuteus / galactus

The All-Powerful Socket.io Connection Aggregator
MIT License
22 stars 11 forks source link

[v7] Default DiscordMessageTimeout (5s) is too short for low-spec environment #12

Open kurokobo opened 3 years ago

kurokobo commented 3 years ago

Describe the bug

In a low-spec environment, guildCreateHandlers on AutoMuteUs side may not be triggered on startup if the bot is already a member of a guild.

This happens because the DiscordMessage that Galactus pushed to Redis has been expired after DiscordMessageTimeout (5s) when the polling from AutoMuteUs has started.

I had to rebuild Galactus with modifying that timeout to make AutoMuteUs works on some low-spec environment. From the log, it takes about 10 seconds in some case from DiscordMessage pushed by Galactus to poped by AutoMuteUs.

Environment Duration
Ubuntu VM on ESXi < 1s
WSL on Windows 10 1s
Raspbian on RPi 4B 9s
Raspbian on RPi 3B+ 10s
n1-standard on GCP 2s
f1-micro on GCP 6s

This problem seems to occur only immediately after startup, when multiple containers perform many processes at the same time. This doesN't occur after the state has stabilized after startup.

The following suggestions are possible, but please let me know if you have a preferred solution :thinking:

To Reproduce

Steps to reproduce the behavior:

  1. Invite the bot to guild
  2. docker-compose down -v
  3. docker-compose up -d

Expected behavior

AutoMuteUs and Galactus handle guilds properly on its startup.

$ docker-compose logs | grep -i guild
automuteus_1  | 2021/03/07 18:14:05 No EMOJI_GUILD_ID specified!!! Emojis will be added to a RANDOM guild, I recommend you specify which guild you'd like me to add emojis to by specifying EMOJI_GUILD_ID
automuteus_1  | {"level":"info","ts":1615140848.3485575,"caller":"client/client.go:155","msg":"discord message handler registered","type":"GuildDelete"}
automuteus_1  | {"level":"info","ts":1615140848.3486629,"caller":"client/client.go:155","msg":"discord message handler registered","type":"GuildCreate"}
automuteus_1  | 2021/03/07 18:14:08 Added to new Guild, id 8025**********6117, name kuro-sandbox πŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆ
automuteus_1  | 2021/03/07 18:14:08 Adding any missing emojis to guild 8025**********6117. On first startup, this can take a long time to complete (Discord's rate-limits on adding emojis)
galactus_1    | {"level":"info","ts":1615140848.1920583,"caller":"handler/guild_create.go:39","msg":"pushed discord message to Redis","type":"GuildCreate","guild_id":"8025**********6117","user_id":"483272567797579778","id":"8025**********6117"} πŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆ
galactus_1    | {"level":"info","ts":1615140848.5512645,"caller":"galactus/guild.go:166","msg":"fetched guild emojis","guildID":"8025**********6117"} πŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆ
postgres_1    | 2021-03-07 18:14:08.357 UTC [61] ERROR:  relation "guilds" does not exist at character 15
postgres_1    | 2021-03-07 18:14:08.357 UTC [61] STATEMENT:  SELECT * FROM guilds WHERE guild_id=$1
postgres_1    | 2021-03-07 18:14:08.357 UTC [61] ERROR:  relation "guilds" does not exist at character 13
postgres_1    | 2021-03-07 18:14:08.357 UTC [61] STATEMENT:  INSERT INTO guilds VALUES ($1, $2, 0); 

Screenshots

Once this issue occur, Galactus pushed the message to Redis, but not read from AutoMuteUs.

$ docker-compose logs | grep -i guild
automuteus_1  | 2021/03/09 13:55:47 No EMOJI_GUILD_ID specified!!! Emojis will be added to a RANDOM guild, I recommend you specify which guild you'd like me to add emojis to by specifying EMOJI_GUILD_ID
automuteus_1  | 2021/03/09 13:55:51 No EMOJI_GUILD_ID specified!!! Emojis will be added to a RANDOM guild, I recommend you specify which guild you'd like me to add emojis to by specifying EMOJI_GUILD_ID
automuteus_1  | {"level":"info","ts":1615298151.7905712,"caller":"client/client.go:155","msg":"discord message handler registered","type":"GuildDelete"}
automuteus_1  | {"level":"info","ts":1615298151.7908564,"caller":"client/client.go:155","msg":"discord message handler registered","type":"GuildCreate"}
galactus_1    | {"level":"info","ts":1615298138.1361215,"caller":"handler/guild_create.go:39","msg":"pushed discord message to Redis","type":"GuildCreate","guild_id":"8025**********6117","user_id":"483272567797579778","id":"8025**********6117"} πŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆπŸ‘ˆ

Version of bot & capture

denverquane commented 3 years ago

Thanks for the detailed report, I really appreciate it!

I wondered what the typical latency would look like for different spec machines. Tentatively I thought "any messages that are older than 5 seconds are stale enough that they shouldn't be processed", but you make an excellent point that on startup, the bot is under heavier load, and it makes sense that the latency should/would be longer. Really appreciate you providing concrete numbers.

I think I would probably opt for a higher default value (maybe 10 seconds), but additionally allow for it to be specified in ENV for flexibility. If even because, while 10+ seconds might be good enough in most situations, depending on the load of the system it might fluctuate and need to be more robust.

I think I'll spend a bit of time right now working on this, thanks for the report @kurokobo ! :)

(okay maybe not right now because I'm on vacation πŸ˜† . But it should be a pretty simple addition)

kurokobo commented 3 years ago

Thanks for your comment, I'm glad I could provide useful information.

Implicitly reading ENV from internal packages works but not very well-behaved / elegant, so I was thinking that the most straightforward way to use ENV is to create setter in internal/redis, and call it from the MakeShardManager (or AddHandler).

Have a nice vacation!