hypherionmc / sdlink

A simple to use Minecraft to Discord Chat linker with Whitelisting
MIT License
23 stars 7 forks source link

Server crashes on usingb /verify command #117

Closed joeyak closed 4 months ago

joeyak commented 4 months ago

I'm using sdlink 3.1.2 with minecraft 1.21 and fabric loader 0.15.11. When someone uses the /verify command in discord, I get the exception below

[01:45:40] [User Authenticator #1/INFO]: UUID of player jojoa1997 is 4d18fb0a-1b22-4170-95b8-1aa3ca484209
[01:45:40] [Server thread/INFO]: Disconnecting jojoa1997 (/184.89.132.94:58102): This server requires account verification. Your verification code is: 4363. Use "/verify 4363" on the discord minecraft channel to verify your account.
[01:45:40] [Server thread/INFO]: jojoa1997 (/184.89.132.94:58102) lost connection: This server requires account verification. Your verification code is: 4363. Use "/verify 4363" on the discord minecraft channel to verify your account.
[01:45:40] [Server thread/WARN]: handleDisconnection() called twice
[01:45:52] [ForkJoinPool.commonPool-worker-2/ERROR]: RestAction queue returned failure: [ErrorResponseException] 10062: Unknown interaction
com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException: null
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException.here(ContextException.java:54) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.Request.<init>(Request.java:77) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.RestActionImpl.queue(RestActionImpl.java:203) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.restaction.interactions.InteractionCallbackImpl.queue(InteractionCallbackImpl.java:74) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:572) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:538) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.core.discord.commands.slash.verification.VerifyAccountCommand.execute(VerifyAccountCommand.java:33) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.SlashCommand.run(SlashCommand.java:322) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onSlashCommand(CommandClientImpl.java:936) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onEvent(CommandClientImpl.java:626) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.hooks.InterfacedEventManager.handle(InterfacedEventManager.java:96) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.util.ThreadedEventManager.lambda$handle$0(ThreadedEventManager.java:20) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
    at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
hypherionmc commented 4 months ago

That's a new one. Would you mind sharing your full log please?

joeyak commented 4 months ago

Attached are the logs and the config file. Had to change the extension of the config file to upload it here and I redacted all tokens/ids. Also it does save to the sdlinkstorage/verifiedaccounts.json file correctly. When the server restarts, I can log in. latest.log simple-discord-link.toml.txt

hypherionmc commented 4 months ago

Thank you for those.

According to the log you attached, the server did not crash at all. This log just contains an error, and then the player logged in, and a couple of second later, your server got shut down by an RCON command

[15:10:39] [Server thread/INFO]: [Rcon] Server shutting down in 15 seconds

This seems like a scheduled restart, from either your host or a cron job.

So overall I am a bit confused here, because the report is saying the server crashed, but the log says the server was running fine.

Could it be that a restart just happened to happen at the same time this error occurred, giving the impression that the server crashed? Because these types of errors (discord errors), are just logged and should never result in a crash. In fact, there is very little, if anything in the mod that would result in a server crash (unless there is a physical bug, like the 2 discovered just after the initial 1.21 release)

joeyak commented 4 months ago

ok, that shutdown was me shutting down the server after I tested it. I thought it crashed when I first encountered it, but that might not be the case that it crashes and I stopped it by accident. Do you know what the issue is with the error? That's stopping me from adding the sdlink whitelisting to the server.

hypherionmc commented 4 months ago

That error is a weird one, because it happened when the command was executed.

Basically, this error means "Discord doesn't know where the event came from", which is weird, because it was triggered from the slash command, so them not knowing where it comes from, is very unusual.

Is this a recurring error?

joeyak commented 4 months ago

I tested it again and the same error occurred. This is what it looked like from the discord server. image

hypherionmc commented 4 months ago

This is really weird, because the specific line that's giving the error is the line that should say Minecraft Server is thinking... and then replace that with Account has been verified etc.

Will have to test this on our side to see if it's reproducible at all, but I doubt it because this is the very first report we get of this specific error, and a lot of people are actively using the verification system.

Is there a way you can possibly time more or less how long between you executing the command, and the error occurring takes?

joeyak commented 4 months ago

sdlink-issue.zip

I've added how my system is set up. I use docker to run minecraft with https://docker-minecraft-server.readthedocs.io. You would just need to update the sdlink configs and run docker compose up in the unzipped directory. There's also a packwiz directory it uses which has all the mods and datapacks that are used.

As for how long it takes, I haven't been able to test as people have been on the server when I could check, but I remember it taking a short time. Between 0.5 and 3 seconds. I'll try to catch no one on the server and test it since it requires a restart to disable whitelisting.

joeyak commented 4 months ago

I noticed I could still do the command and get the error. I ran /verify 1234 at 14:40:10 and the error logged at 14:40:15.

Seemed to work half the time

image

[14:39:25] [ForkJoinPool.commonPool-worker-14/ERROR]: RestAction queue returned failure: [ErrorResponseException] 10062: Unknown interaction
com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException: null
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException.here(ContextException.java:54) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.Request.<init>(Request.java:77) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.RestActionImpl.queue(RestActionImpl.java:203) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.restaction.interactions.InteractionCallbackImpl.queue(InteractionCallbackImpl.java:74) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:572) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:538) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.core.discord.commands.slash.verification.VerifyAccountCommand.execute(VerifyAccountCommand.java:33) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.SlashCommand.run(SlashCommand.java:322) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onSlashCommand(CommandClientImpl.java:936) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onEvent(CommandClientImpl.java:626) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.hooks.InterfacedEventManager.handle(InterfacedEventManager.java:96) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.util.ThreadedEventManager.lambda$handle$0(ThreadedEventManager.java:20) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
    at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
[14:40:15] [ForkJoinPool.commonPool-worker-17/ERROR]: RestAction queue returned failure: [ErrorResponseException] 10062: Unknown interaction
com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException: null
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.exceptions.ContextException.here(ContextException.java:54) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.Request.<init>(Request.java:77) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.RestActionImpl.queue(RestActionImpl.java:203) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.internal.requests.restaction.interactions.InteractionCallbackImpl.queue(InteractionCallbackImpl.java:74) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:572) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.requests.RestAction.queue(RestAction.java:538) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.core.discord.commands.slash.verification.VerifyAccountCommand.execute(VerifyAccountCommand.java:33) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.SlashCommand.run(SlashCommand.java:322) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onSlashCommand(CommandClientImpl.java:936) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.jagrosh.jdautilities.command.impl.CommandClientImpl.onEvent(CommandClientImpl.java:626) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.shaded.dv8tion.jda.api.hooks.InterfacedEventManager.handle(InterfacedEventManager.java:96) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at com.hypherionmc.sdlink.util.ThreadedEventManager.lambda$handle$0(ThreadedEventManager.java:20) ~[SimpleDiscordLink-Universal-3.1.2.jar:?]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
    at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
hypherionmc commented 4 months ago

Okay that last part confirms my suspicions.

This seems to be a delay issue. When a discord command is executed, your bot has 3 seconds to respond to the command, if it doesn't, you get the "Application did not respond" message in discord, and the error in your log when it does finally reach the bot.

So basically, the connection between your server, and discord is not fast enough to handle the commands, so they are timing out. This is not an issue with our mod, but the server connection itself.

joeyak commented 4 months ago

Ah that makes sense. Don't know why it's so slow, but it's good to know.