Reorganize JDAConnectionManager, add more log message handling. Implement Timeout helper class

This commit is contained in:
Vankka 2021-10-16 00:52:23 +03:00
parent 73815323e0
commit 0494c4a7bb
No known key found for this signature in database
GPG Key ID: 6E50CB7A29B96AD0
3 changed files with 307 additions and 172 deletions

View File

@ -37,6 +37,7 @@ import com.discordsrv.common.discord.api.user.DiscordUserImpl;
import com.discordsrv.common.discord.connection.DiscordConnectionManager;
import com.discordsrv.common.scheduler.Scheduler;
import com.discordsrv.common.scheduler.threadfactory.CountingThreadFactory;
import com.discordsrv.common.time.util.Timeout;
import com.neovisionaries.ws.client.WebSocketFactory;
import com.neovisionaries.ws.client.WebSocketFrame;
import net.dv8tion.jda.api.JDA;
@ -46,18 +47,18 @@ import net.dv8tion.jda.api.events.DisconnectEvent;
import net.dv8tion.jda.api.events.ShutdownEvent;
import net.dv8tion.jda.api.events.StatusChangeEvent;
import net.dv8tion.jda.api.exceptions.ErrorResponseException;
import net.dv8tion.jda.api.requests.CloseCode;
import net.dv8tion.jda.api.requests.ErrorResponse;
import net.dv8tion.jda.api.requests.GatewayIntent;
import net.dv8tion.jda.api.requests.RestAction;
import net.dv8tion.jda.api.exceptions.RateLimitedException;
import net.dv8tion.jda.api.requests.*;
import net.dv8tion.jda.api.utils.AllowedMentions;
import net.dv8tion.jda.api.utils.MemberCachePolicy;
import net.dv8tion.jda.internal.entities.ReceivedMessage;
import net.dv8tion.jda.internal.hooks.EventManagerProxy;
import net.dv8tion.jda.internal.utils.IOUtil;
import okhttp3.OkHttpClient;
import org.jetbrains.annotations.NotNull;
import javax.security.auth.login.LoginException;
import java.io.InterruptedIOException;
import java.util.*;
import java.util.concurrent.*;
import java.util.concurrent.atomic.AtomicReference;
@ -81,8 +82,12 @@ public class JDAConnectionManager implements DiscordConnectionManager {
private boolean detailsAccepted = true;
// Bot owner details
private final Timeout botOwnerTimeout = new Timeout(5, TimeUnit.MINUTES);
private final AtomicReference<CompletableFuture<DiscordUser>> botOwnerRequest = new AtomicReference<>();
private long botOwnerRetrievalTime;
// Logging timeouts
private final Timeout mfaTimeout = new Timeout(30, TimeUnit.SECONDS);
private final Timeout serverErrorTimeout = new Timeout(20, TimeUnit.SECONDS);
public JDAConnectionManager(DiscordSRV discordSRV) {
this.discordSRV = discordSRV;
@ -96,30 +101,7 @@ public class JDAConnectionManager implements DiscordConnectionManager {
);
// Set default failure handling
RestAction.setDefaultFailure(t -> {
if (t instanceof ErrorResponseException) {
ErrorResponse response = ((ErrorResponseException) t).getErrorResponse();
if (response == ErrorResponse.MFA_NOT_ENABLED) {
withBotOwner(user -> {
discordSRV.logger().error("+----------------------------------------------->");
discordSRV.logger().error("| Failed to complete a request:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot's owner needs to enable 2FA");
discordSRV.logger().error("| on their Discord account due to a Discord");
discordSRV.logger().error("| server requiring 2FA for moderation actions");
if (user != null) {
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot's owner is " + user.getAsTag() + " (" + user.getId() + ")");
}
discordSRV.logger().error("|");
discordSRV.logger().error("| You can view instructions for enabling 2FA here:");
discordSRV.logger().error("| https://support.discord.com/hc/en-us/articles/219576828-Setting-up-Two-Factor-Authentication");
discordSRV.logger().error("+----------------------------------------------->");
});
}
}
discordSRV.logger().error("Callback failed", t);
});
RestAction.setDefaultFailure(new DefaultFailureCallback());
// Disable all mentions by default for safety
AllowedMentions.setDefaultMentions(Collections.emptyList());
@ -127,16 +109,50 @@ public class JDAConnectionManager implements DiscordConnectionManager {
discordSRV.eventBus().subscribe(this);
}
private void withBotOwner(Consumer<DiscordUser> botOwnerConsumer) {
long currentTime = System.currentTimeMillis();
@Override
public JDA instance() {
return instance;
}
@Override
public boolean areDetailsAccepted() {
return detailsAccepted;
}
@Subscribe
public void onStatusChange(StatusChangeEvent event) {
DiscordSRV.Status currentStatus = discordSRV.status();
if (currentStatus.isShutdown() || currentStatus.isStartupError()) {
// Don't change the status if it's shutdown or failed to start
return;
}
JDA.Status status = event.getNewStatus();
int ordinal = status.ordinal();
DiscordSRV.Status newStatus;
if (ordinal < JDA.Status.CONNECTED.ordinal()) {
newStatus = DiscordSRV.Status.ATTEMPTING_TO_CONNECT;
} else if (ordinal < JDA.Status.SHUTTING_DOWN.ordinal()) {
newStatus = DiscordSRV.Status.CONNECTED;
} else {
newStatus = DiscordSRV.Status.FAILED_TO_CONNECT;
}
discordSRV.setStatus(newStatus);
}
/**
* Returns the bot owner as a {@link DiscordUser} or {@code null} within 10 seconds.
* The owner will be cached for 5 minutes, if available it will be passed to the consumer instantly.
* @param botOwnerConsumer the consumer that will be passed the bot owner or {@code null}
*/
private void withBotOwner(@NotNull Consumer<DiscordUser> botOwnerConsumer) {
CompletableFuture<DiscordUser> request = botOwnerRequest.get();
if (request != null && botOwnerRetrievalTime + TimeUnit.MINUTES.toMillis(5) < currentTime) {
if (request != null && !botOwnerTimeout.checkAndUpdate()) {
request.whenComplete((user, t) -> botOwnerConsumer.accept(t != null ? null : user));
return;
}
botOwnerRetrievalTime = currentTime;
CompletableFuture<DiscordUser> future = instance.retrieveApplicationInfo()
.timeout(10, TimeUnit.SECONDS)
.map(applicationInfo -> (DiscordUser) new DiscordUserImpl(applicationInfo.getOwner()))
@ -146,18 +162,13 @@ public class JDAConnectionManager implements DiscordConnectionManager {
future.whenComplete((user, t) -> botOwnerConsumer.accept(t != null ? null : user));
}
@Subscribe(priority = EventPriority.LATE)
public void onDSRVShuttingDown(DiscordSRVShuttingDownEvent event) {
// This has a timeout
shutdown().join();
}
@Subscribe(priority = EventPriority.EARLIEST)
public void onPlaceholderLookup(PlaceholderLookupEvent event) {
if (event.isProcessed()) {
return;
}
// Map JDA objects to 1st party API objects
Set<Object> newContext = new HashSet<>();
boolean anyConverted = false;
for (Object o : event.getContext()) {
@ -186,117 +197,16 @@ public class JDAConnectionManager implements DiscordConnectionManager {
}
newContext.add(converted);
}
// Prevent infinite recursion
if (anyConverted) {
event.process(PlaceholderLookupResult.newLookup(event.getPlaceholder(), newContext));
}
}
@Subscribe
public void onStatusChange(StatusChangeEvent event) {
DiscordSRV.Status currentStatus = discordSRV.status();
if (currentStatus.isShutdown() || currentStatus.isStartupError()) {
// Don't change the status if it's shutdown or failed to start
return;
}
JDA.Status status = event.getNewStatus();
int ordinal = status.ordinal();
DiscordSRV.Status newStatus;
if (ordinal < JDA.Status.CONNECTED.ordinal()) {
newStatus = DiscordSRV.Status.ATTEMPTING_TO_CONNECT;
} else if (ordinal < JDA.Status.SHUTTING_DOWN.ordinal()) {
newStatus = DiscordSRV.Status.CONNECTED;
} else {
newStatus = DiscordSRV.Status.FAILED_TO_CONNECT;
}
discordSRV.setStatus(newStatus);
}
@Subscribe
public void onDisconnect(DisconnectEvent event) {
CloseCode closeCode = event.getCloseCode();
if (checkCode(closeCode)) {
return;
}
boolean closedByServer = event.isClosedByServer();
WebSocketFrame frame = closedByServer ? event.getServiceCloseFrame() : event.getClientCloseFrame();
if (frame == null) {
throw new IllegalStateException("Could not get the close frame for a disconnect");
}
String message;
if (closedByServer) {
String closeReason = frame.getCloseReason();
message = "[JDA] [Server] Disconnected due to "
+ frame.getCloseCode() + ": "
+ (closeCode != null
? closeCode.getMeaning()
: (closeReason != null ? closeReason : "(Unknown close reason)"));
} else {
message = "[JDA] [Client] Disconnected due to "
+ frame.getCloseCode() + ": "
+ frame.getCloseReason();
}
if (closeCode != null && !closeCode.isReconnect()) {
discordSRV.logger().error(message);
} else {
discordSRV.logger().debug(message);
}
}
@Subscribe
public void onShutdown(ShutdownEvent event) {
checkCode(event.getCloseCode());
}
private boolean checkCode(CloseCode closeCode) {
if (closeCode == null) {
return false;
} else if (closeCode == CloseCode.DISALLOWED_INTENTS) {
Set<GatewayIntent> intents = discordSRV.discordConnectionDetails().getGatewayIntents();
discordSRV.logger().error("+-------------------------------------->");
discordSRV.logger().error("| Failed to connect to Discord:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot is lacking one or more");
discordSRV.logger().error("| privileged intents listed below");
discordSRV.logger().error("|");
for (GatewayIntent intent : intents) {
String displayName = PRIVILEGED_INTENTS.get(intent);
if (displayName != null) {
discordSRV.logger().error("| " + displayName);
}
}
discordSRV.logger().error("|");
discordSRV.logger().error("| Instructions for enabling privileged gateway intents:");
discordSRV.logger().error("| 1. Go to https://discord.com/developers/applications");
discordSRV.logger().error("| 2. Choose the bot you are using for DiscordSRV");
discordSRV.logger().error("| - Keep in mind it will only be visible to the ");
discordSRV.logger().error("| Discord user who created the bot");
discordSRV.logger().error("| 3. Go to the \"Bot\" tab");
discordSRV.logger().error("| 4. Make sure the intents listed above are all enabled");
discordSRV.logger().error("| 5. "); // TODO
discordSRV.logger().error("+-------------------------------------->");
return true;
} else if (closeCode == CloseCode.AUTHENTICATION_FAILED) {
invalidToken();
return true;
}
return false;
}
@Override
public JDA instance() {
return instance;
}
@Override
public boolean areDetailsAccepted() {
return detailsAccepted;
}
//
// (Re)connecting & Shutting down
//
@Override
public CompletableFuture<Void> connect() {
@ -365,20 +275,6 @@ public class JDAConnectionManager implements DiscordConnectionManager {
}
}
private void invalidToken() {
discordSRV.logger().error("+------------------------------>");
discordSRV.logger().error("| Failed to connect to Discord:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The token provided in the");
discordSRV.logger().error("| " + ConnectionConfig.FILE_NAME + " is invalid");
discordSRV.logger().error("|");
discordSRV.logger().error("| You can get the token for your bot from:");
discordSRV.logger().error("| https://discord.com/developers/applications");
discordSRV.logger().error("| - Keep in mind the bot is only visible to");
discordSRV.logger().error("| the Discord user that created the bot");
discordSRV.logger().error("+------------------------------>");
}
@Override
public CompletableFuture<Void> reconnect() {
return CompletableFuture.runAsync(() -> {
@ -387,6 +283,12 @@ public class JDAConnectionManager implements DiscordConnectionManager {
}, discordSRV.scheduler().executor());
}
@Subscribe(priority = EventPriority.LATE)
public void onDSRVShuttingDown(DiscordSRVShuttingDownEvent event) {
// This has a timeout
shutdown().join();
}
@Override
public CompletableFuture<Void> shutdown(long timeoutMillis) {
return CompletableFuture.runAsync(() -> shutdownInternal(timeoutMillis), discordSRV.scheduler().executor());
@ -436,4 +338,181 @@ public class JDAConnectionManager implements DiscordConnectionManager {
gatewayPool.shutdownNow();
rateLimitPool.shutdownNow();
}
//
// Logging
//
@Subscribe
public void onShutdown(ShutdownEvent event) {
checkCode(event.getCloseCode());
}
@Subscribe
public void onDisconnect(DisconnectEvent event) {
CloseCode closeCode = event.getCloseCode();
if (checkCode(closeCode)) {
return;
}
boolean closedByServer = event.isClosedByServer();
WebSocketFrame frame = closedByServer ? event.getServiceCloseFrame() : event.getClientCloseFrame();
if (frame == null) {
throw new IllegalStateException("Could not get the close frame for a disconnect");
}
String message;
if (closedByServer) {
String closeReason = frame.getCloseReason();
message = "[JDA] [Server] Disconnected due to "
+ frame.getCloseCode() + ": "
+ (closeCode != null
? closeCode.getMeaning()
: (closeReason != null ? closeReason : "(Unknown close reason)"));
} else {
message = "[JDA] [Client] Disconnected due to "
+ frame.getCloseCode() + ": "
+ frame.getCloseReason();
}
if (closeCode != null && !closeCode.isReconnect()) {
discordSRV.logger().error(message);
} else {
discordSRV.logger().debug(message);
}
}
private boolean checkCode(CloseCode closeCode) {
if (closeCode == null) {
return false;
} else if (closeCode == CloseCode.DISALLOWED_INTENTS) {
Set<GatewayIntent> intents = discordSRV.discordConnectionDetails().getGatewayIntents();
discordSRV.logger().error("+-------------------------------------->");
discordSRV.logger().error("| Failed to connect to Discord:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot is lacking one or more");
discordSRV.logger().error("| privileged intents listed below");
discordSRV.logger().error("|");
for (GatewayIntent intent : intents) {
String displayName = PRIVILEGED_INTENTS.get(intent);
if (displayName != null) {
discordSRV.logger().error("| " + displayName);
}
}
discordSRV.logger().error("|");
discordSRV.logger().error("| Instructions for enabling privileged gateway intents:");
discordSRV.logger().error("| 1. Go to https://discord.com/developers/applications");
discordSRV.logger().error("| 2. Choose the bot you are using for DiscordSRV");
discordSRV.logger().error("| - Keep in mind it will only be visible to the ");
discordSRV.logger().error("| Discord user who created the bot");
discordSRV.logger().error("| 3. Go to the \"Bot\" tab");
discordSRV.logger().error("| 4. Make sure the intents listed above are all enabled");
discordSRV.logger().error("| 5. "); // TODO
discordSRV.logger().error("+-------------------------------------->");
return true;
} else if (closeCode == CloseCode.AUTHENTICATION_FAILED) {
invalidToken();
return true;
}
return false;
}
private void invalidToken() {
discordSRV.logger().error("+------------------------------>");
discordSRV.logger().error("| Failed to connect to Discord:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The token provided in the");
discordSRV.logger().error("| " + ConnectionConfig.FILE_NAME + " is invalid");
discordSRV.logger().error("|");
discordSRV.logger().error("| You can get the token for your bot from:");
discordSRV.logger().error("| https://discord.com/developers/applications");
discordSRV.logger().error("| - Keep in mind the bot is only visible to");
discordSRV.logger().error("| the Discord user that created the bot");
discordSRV.logger().error("+------------------------------>");
}
private class DefaultFailureCallback implements Consumer<Throwable> {
@Override
public void accept(Throwable t) {
if ((t instanceof InterruptedIOException || t instanceof InterruptedException)
&& discordSRV.status().isShutdown()) {
// Ignore interrupted exceptions when DiscordSRV is shutting down or shutdown
return;
}
boolean cancelled;
if ((cancelled = t instanceof CancellationException) || t instanceof TimeoutException) {
// Cancelling/timing out requests is always intentional
discordSRV.logger().debug("A request " + (cancelled ? "was cancelled" : "timed out"), t.getCause());
} else if (t instanceof RateLimitedException) {
// Log route & retry after on warn & context on debug
RateLimitedException exception = ((RateLimitedException) t);
discordSRV.logger().warning("A request on route " + exception.getRateLimitedRoute()
+ " was rate-limited for " + exception.getRetryAfter() + "ms");
discordSRV.logger().debug(exception.getCause());
} else if (t instanceof ErrorResponseException) {
ErrorResponseException exception = (ErrorResponseException) t;
if (exception.getErrorCode() == Response.ERROR_CODE) {
// There is no response due to a client error
Throwable cause = exception.getCause();
if (cause != null) {
// Run the cause through this method again
accept(cause);
} else {
discordSRV.logger().error("Failed to complete request for a unknown reason", exception);
}
return;
}
ErrorResponse response = exception.getErrorResponse();
switch (response) {
case MFA_NOT_ENABLED: {
if (!mfaTimeout.checkAndUpdate()) {
return;
}
withBotOwner(user -> {
discordSRV.logger().error("+----------------------------------------------->");
discordSRV.logger().error("| Failed to complete a request:");
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot's owner needs to enable 2FA");
discordSRV.logger().error("| on their Discord account due to a Discord");
discordSRV.logger().error("| server requiring 2FA for moderation actions");
if (user != null) {
discordSRV.logger().error("|");
discordSRV.logger().error("| The Discord bot's owner is " + user.getAsTag() + " (" + user.getId() + ")");
}
discordSRV.logger().error("|");
discordSRV.logger().error("| You can view instructions for enabling 2FA here:");
discordSRV.logger().error("| https://support.discord.com/hc/en-us/articles/219576828-Setting-up-Two-Factor-Authentication");
discordSRV.logger().error("+----------------------------------------------->");
});
return;
}
case SERVER_ERROR: {
if (serverErrorTimeout.checkAndUpdate()) {
discordSRV.logger().error("+--------------------------------------------------------------->");
discordSRV.logger().error("| Failed to complete a request:");
discordSRV.logger().error("|");
discordSRV.logger().error("| Discord sent a server error (HTTP 500) as a response.");
discordSRV.logger().error("| This is usually caused by a outage (https://discordstatus.com)");
discordSRV.logger().error("| and will stop happening once Discord stabilizes");
discordSRV.logger().error("+--------------------------------------------------------------->");
} else {
// Log as debug as to not spam out the server console/log
discordSRV.logger().debug("Failed to complete a request, Discord returned a server error (HTTP 500)");
}
// Log context to find what made the request
discordSRV.logger().debug(exception.getCause());
return;
}
default: break;
}
discordSRV.logger().error("Failed to complete a request: " + response.getMeaning());
discordSRV.logger().debug(exception);
}
}
}
}

View File

@ -28,15 +28,20 @@ import java.util.*;
public class DependencyLoggingFilter implements LogFilter {
private static final List<String> BLACKLISTED_MESSAGES = Arrays.asList(
// We have our own more informative log messages for this
"WebSocket connection was closed and cannot be recovered due to identification issues"
);
private static final Map<String, List<String>> BLACKLISTED_MESSAGES = new HashMap<>();
private static final Map<String, String> LOGGER_MAPPINGS = new HashMap<>();
static {
// Will get relocated, which is fine
// Class names here will get relocated, which is fine
LOGGER_MAPPINGS.put("net.dv8tion.jda", "JDA");
BLACKLISTED_MESSAGES.put("net.dv8tion.jda", Arrays.asList(
// We have our own more informative log messages for this
"WebSocket connection was closed and cannot be recovered due to identification issues",
// Failed JDA requests (handled with RestAction default failure)
"There was an I/O error while executing a REST request: ",
"There was an unexpected error while executing a REST request"
));
}
private final DiscordSRV discordSRV;
@ -51,6 +56,25 @@ public class DependencyLoggingFilter implements LogFilter {
return Result.IGNORE;
}
if (message != null) {
List<String> blacklistedMessages = new ArrayList<>();
// Get blacklisted messages for the logger
for (Map.Entry<String, List<String>> entry : BLACKLISTED_MESSAGES.entrySet()) {
if (loggerName.startsWith(entry.getKey())) {
blacklistedMessages.addAll(entry.getValue());
}
}
// Go through the blacklisted messages we gathered
for (String blacklistedMessage : blacklistedMessages) {
if (message.contains(blacklistedMessage)) {
return Result.BLOCK;
}
}
}
// Prettify logger name, if possible
String name = loggerName;
for (Map.Entry<String, String> entry : LOGGER_MAPPINGS.entrySet()) {
if (name.startsWith(entry.getKey())) {
@ -59,14 +83,6 @@ public class DependencyLoggingFilter implements LogFilter {
}
}
if (message != null) {
for (String blacklistedMessage : BLACKLISTED_MESSAGES) {
if (message.contains(blacklistedMessage)) {
return Result.BLOCK;
}
}
}
discordSRV.logger().log(logLevel, "[" + name + "]" + (message != null ? " " + message : ""), throwable);
return Result.BLOCK;
}

View File

@ -0,0 +1,40 @@
package com.discordsrv.common.time.util;
import org.jetbrains.annotations.NotNull;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
/**
* Helper class to track of time since something was done last, to avoid repeating tasks within a short timespan.
*/
public class Timeout {
private final AtomicLong last = new AtomicLong(0);
private final long timeoutMS;
public Timeout(long time, @NotNull TimeUnit unit) {
this(unit.toMillis(time));
}
public Timeout(long timeoutMS) {
this.timeoutMS = timeoutMS;
}
/**
* Checks if the last invocation of this method was not within the timeout period,
* if true updates the time to the current time.
* @return if the last time this was invoked was outside the timeout period
*/
public boolean checkAndUpdate() {
long currentTime = System.currentTimeMillis();
synchronized (last) {
long time = last.get();
if (time + timeoutMS < currentTime) {
last.set(currentTime);
return true;
}
}
return false;
}
}