From 082b3e6c424b9a28c8df379e7dc18b6b2533eafe Mon Sep 17 00:00:00 2001 From: William Date: Wed, 13 Jul 2022 10:26:07 +0100 Subject: [PATCH 1/4] Tweak debug logging when reading Redis keys --- .../husksync/listener/EventListener.java | 4 ++-- .../husksync/redis/RedisManager.java | 20 +++++++++++++------ 2 files changed, 16 insertions(+), 8 deletions(-) diff --git a/common/src/main/java/net/william278/husksync/listener/EventListener.java b/common/src/main/java/net/william278/husksync/listener/EventListener.java index 019002f7..3d55888b 100644 --- a/common/src/main/java/net/william278/husksync/listener/EventListener.java +++ b/common/src/main/java/net/william278/husksync/listener/EventListener.java @@ -79,8 +79,8 @@ public abstract class EventListener { } if (disabling || currentMilliseconds.get() > TIME_OUT_MILLISECONDS) { executor.shutdown(); - setUserFromDatabase(user) - .thenAccept(succeeded -> handleSynchronisationCompletion(user, succeeded)); + setUserFromDatabase(user).thenAccept( + succeeded -> handleSynchronisationCompletion(user, succeeded)); return; } plugin.getRedisManager().getUserData(user).thenAccept(redisUserData -> diff --git a/common/src/main/java/net/william278/husksync/redis/RedisManager.java b/common/src/main/java/net/william278/husksync/redis/RedisManager.java index 51ce6ab4..949e41a1 100644 --- a/common/src/main/java/net/william278/husksync/redis/RedisManager.java +++ b/common/src/main/java/net/william278/husksync/redis/RedisManager.java @@ -165,13 +165,17 @@ public class RedisManager { return CompletableFuture.supplyAsync(() -> { try (Jedis jedis = jedisPool.getResource()) { final byte[] key = getKey(RedisKeyType.DATA_UPDATE, user.uuid); - plugin.getLoggingAdapter().debug("[" + user.username + "] Read " + RedisKeyType.DATA_UPDATE.name() - + " key from redis at: " + - new SimpleDateFormat("mm:ss.SSS").format(new Date())); final byte[] dataByteArray = jedis.get(key); if (dataByteArray == null) { + plugin.getLoggingAdapter().debug("[" + user.username + "] Could not read " + + RedisKeyType.DATA_UPDATE.name() + " key from redis at: " + + new SimpleDateFormat("mm:ss.SSS").format(new Date())); return Optional.empty(); } + plugin.getLoggingAdapter().debug("[" + user.username + "] Successfully read " + + RedisKeyType.DATA_UPDATE.name() + " key from redis at: " + + new SimpleDateFormat("mm:ss.SSS").format(new Date())); + // Consume the key (delete from redis) jedis.del(key); @@ -188,13 +192,17 @@ public class RedisManager { return CompletableFuture.supplyAsync(() -> { try (Jedis jedis = jedisPool.getResource()) { final byte[] key = getKey(RedisKeyType.SERVER_SWITCH, user.uuid); - plugin.getLoggingAdapter().debug("[" + user.username + "] Read " + RedisKeyType.SERVER_SWITCH.name() - + " key from redis at: " + - new SimpleDateFormat("mm:ss.SSS").format(new Date())); final byte[] readData = jedis.get(key); if (readData == null) { + plugin.getLoggingAdapter().debug("[" + user.username + "] Could not read " + + RedisKeyType.SERVER_SWITCH.name() + " key from redis at: " + + new SimpleDateFormat("mm:ss.SSS").format(new Date())); return false; } + plugin.getLoggingAdapter().debug("[" + user.username + "] Successfully read " + + RedisKeyType.SERVER_SWITCH.name() + " key from redis at: " + + new SimpleDateFormat("mm:ss.SSS").format(new Date())); + // Consume the key (delete from redis) jedis.del(key); return true; From 60a3bba165f0cfeb53681fb2d40c85a2a9823e9d Mon Sep 17 00:00:00 2001 From: William Date: Wed, 13 Jul 2022 10:48:34 +0100 Subject: [PATCH 2/4] Additional error handling --- .../husksync/api/BaseHuskSyncAPI.java | 6 +++--- .../husksync/listener/EventListener.java | 16 ++++++++------- .../husksync/player/OnlineUser.java | 20 +++++++++++++------ 3 files changed, 26 insertions(+), 16 deletions(-) diff --git a/common/src/main/java/net/william278/husksync/api/BaseHuskSyncAPI.java b/common/src/main/java/net/william278/husksync/api/BaseHuskSyncAPI.java index fe1fc24f..3827e8c6 100644 --- a/common/src/main/java/net/william278/husksync/api/BaseHuskSyncAPI.java +++ b/common/src/main/java/net/william278/husksync/api/BaseHuskSyncAPI.java @@ -72,7 +72,7 @@ public abstract class BaseHuskSyncAPI { public final CompletableFuture> getUserData(@NotNull User user) { return CompletableFuture.supplyAsync(() -> { if (user instanceof OnlineUser) { - return Optional.of(((OnlineUser) user).getUserData().join()); + return ((OnlineUser) user).getUserData(plugin.getLoggingAdapter()).join(); } else { return plugin.getDatabase().getCurrentUserData(user).join().map(UserDataSnapshot::userData); } @@ -103,8 +103,8 @@ public abstract class BaseHuskSyncAPI { * @since 2.0 */ public final CompletableFuture saveUserData(@NotNull OnlineUser user) { - return CompletableFuture.runAsync(() -> user.getUserData().thenAccept(userData -> - plugin.getDatabase().setUserData(user, userData, DataSaveCause.API).join())); + return CompletableFuture.runAsync(() -> user.getUserData(plugin.getLoggingAdapter()).thenAccept(optionalUserData -> optionalUserData.ifPresent( + userData -> plugin.getDatabase().setUserData(user, userData, DataSaveCause.API).join()))); } /** diff --git a/common/src/main/java/net/william278/husksync/listener/EventListener.java b/common/src/main/java/net/william278/husksync/listener/EventListener.java index 3d55888b..5c0f98d6 100644 --- a/common/src/main/java/net/william278/husksync/listener/EventListener.java +++ b/common/src/main/java/net/william278/husksync/listener/EventListener.java @@ -148,9 +148,10 @@ public abstract class EventListener { if (usersAwaitingSync.contains(user.uuid)) { return; } - plugin.getRedisManager().setUserServerSwitch(user).thenRun(() -> user.getUserData().thenAccept( - userData -> plugin.getRedisManager().setUserData(user, userData).thenRun( - () -> plugin.getDatabase().setUserData(user, userData, DataSaveCause.DISCONNECT).join()))); + plugin.getRedisManager().setUserServerSwitch(user).thenRun(() -> user.getUserData(plugin.getLoggingAdapter()).thenAccept( + optionalUserData -> optionalUserData.ifPresent( + userData -> plugin.getRedisManager().setUserData(user, userData).thenRun( + () -> plugin.getDatabase().setUserData(user, userData, DataSaveCause.DISCONNECT).join())))); usersAwaitingSync.remove(user.uuid); } @@ -163,8 +164,8 @@ public abstract class EventListener { if (disabling || !plugin.getSettings().getBooleanValue(Settings.ConfigOption.SYNCHRONIZATION_SAVE_ON_WORLD_SAVE)) { return; } - usersInWorld.forEach(user -> plugin.getDatabase().setUserData(user, user.getUserData().join(), - DataSaveCause.WORLD_SAVE).join()); + usersInWorld.forEach(user -> user.getUserData(plugin.getLoggingAdapter()).join().ifPresent( + userData -> plugin.getDatabase().setUserData(user, userData, DataSaveCause.WORLD_SAVE).join())); } /** @@ -207,8 +208,9 @@ public abstract class EventListener { public final void handlePluginDisable() { disabling = true; - plugin.getOnlineUsers().stream().filter(user -> !usersAwaitingSync.contains(user.uuid)).forEach(user -> - plugin.getDatabase().setUserData(user, user.getUserData().join(), DataSaveCause.SERVER_SHUTDOWN).join()); + plugin.getOnlineUsers().stream().filter(user -> !usersAwaitingSync.contains(user.uuid)).forEach( + user -> user.getUserData(plugin.getLoggingAdapter()).join().ifPresent( + userData -> plugin.getDatabase().setUserData(user, userData, DataSaveCause.SERVER_SHUTDOWN).join())); plugin.getDatabase().close(); plugin.getRedisManager().close(); diff --git a/common/src/main/java/net/william278/husksync/player/OnlineUser.java b/common/src/main/java/net/william278/husksync/player/OnlineUser.java index c9007828..26a63935 100644 --- a/common/src/main/java/net/william278/husksync/player/OnlineUser.java +++ b/common/src/main/java/net/william278/husksync/player/OnlineUser.java @@ -12,6 +12,7 @@ import org.jetbrains.annotations.NotNull; import java.util.ArrayList; import java.util.List; +import java.util.Optional; import java.util.UUID; import java.util.concurrent.CompletableFuture; import java.util.logging.Level; @@ -258,16 +259,23 @@ public abstract class OnlineUser extends User { public abstract void showMenu(@NotNull ItemEditorMenu menu); /** - * Get the player's current {@link UserData} + * Get the player's current {@link UserData} in an {@link Optional} + *

+ * If the user data could not be returned due to an exception, the optional will return empty * - * @return the player's current {@link UserData} + * @param logger The logger to use for handling exceptions + * @return the player's current {@link UserData} in an optional; empty if an exception occurs */ - public final CompletableFuture getUserData() { - return CompletableFuture.supplyAsync( - () -> new UserData(getStatus().join(), getInventory().join(), + public final CompletableFuture> getUserData(@NotNull Logger logger) { + return CompletableFuture.supplyAsync(() -> Optional.of(new UserData(getStatus().join(), getInventory().join(), getEnderChest().join(), getPotionEffects().join(), getAdvancements().join(), getStatistics().join(), getLocation().join(), getPersistentDataContainer().join(), - getMinecraftVersion().toString())); + getMinecraftVersion().toString()))) + .exceptionally(exception -> { + logger.log(Level.SEVERE, "Failed to fetch user data for online player " + username + " (" + exception.getMessage() + ")"); + exception.printStackTrace(); + return Optional.empty(); + }); } } From 8760fcea1fdccbc260b0707b3019994085ed3e5e Mon Sep 17 00:00:00 2001 From: William Date: Wed, 13 Jul 2022 11:15:43 +0100 Subject: [PATCH 3/4] Fix tests --- .../husksync/data/DataAdaptionTests.java | 97 ++++++++++--------- .../husksync/logger/DummyLogger.java | 44 +++++++++ 2 files changed, 96 insertions(+), 45 deletions(-) create mode 100644 common/src/test/java/net/william278/husksync/logger/DummyLogger.java diff --git a/common/src/test/java/net/william278/husksync/data/DataAdaptionTests.java b/common/src/test/java/net/william278/husksync/data/DataAdaptionTests.java index a9c6c11f..2da22ec8 100644 --- a/common/src/test/java/net/william278/husksync/data/DataAdaptionTests.java +++ b/common/src/test/java/net/william278/husksync/data/DataAdaptionTests.java @@ -1,11 +1,14 @@ package net.william278.husksync.data; +import net.william278.husksync.logger.DummyLogger; import net.william278.husksync.player.DummyPlayer; import net.william278.husksync.player.OnlineUser; import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.Test; import java.nio.charset.StandardCharsets; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicReference; /** * Tests for the data system {@link DataAdapter} @@ -15,64 +18,68 @@ public class DataAdaptionTests { @Test public void testJsonDataAdapter() { final OnlineUser dummyUser = DummyPlayer.create(); - final UserData dummyUserData = dummyUser.getUserData().join(); - final DataAdapter dataAdapter = new JsonDataAdapter(); - final byte[] data = dataAdapter.toBytes(dummyUserData); - final UserData deserializedUserData = dataAdapter.fromBytes(data); + final AtomicBoolean isEquals = new AtomicBoolean(false); + dummyUser.getUserData(new DummyLogger()).join().ifPresent(dummyUserData -> { + final DataAdapter dataAdapter = new JsonDataAdapter(); + final byte[] data = dataAdapter.toBytes(dummyUserData); + final UserData deserializedUserData = dataAdapter.fromBytes(data); - boolean isEquals = deserializedUserData.getInventoryData().serializedItems - .equals(dummyUserData.getInventoryData().serializedItems) - && deserializedUserData.getEnderChestData().serializedItems - .equals(dummyUserData.getEnderChestData().serializedItems) - && deserializedUserData.getPotionEffectsData().serializedPotionEffects - .equals(dummyUserData.getPotionEffectsData().serializedPotionEffects) - && deserializedUserData.getStatusData().health == dummyUserData.getStatusData().health - && deserializedUserData.getStatusData().hunger == dummyUserData.getStatusData().hunger - && deserializedUserData.getStatusData().saturation == dummyUserData.getStatusData().saturation - && deserializedUserData.getStatusData().saturationExhaustion == dummyUserData.getStatusData().saturationExhaustion - && deserializedUserData.getStatusData().selectedItemSlot == dummyUserData.getStatusData().selectedItemSlot - && deserializedUserData.getStatusData().totalExperience == dummyUserData.getStatusData().totalExperience - && deserializedUserData.getStatusData().maxHealth == dummyUserData.getStatusData().maxHealth - && deserializedUserData.getStatusData().healthScale == dummyUserData.getStatusData().healthScale; - - Assertions.assertTrue(isEquals); + isEquals.set(deserializedUserData.getInventoryData().serializedItems + .equals(dummyUserData.getInventoryData().serializedItems) + && deserializedUserData.getEnderChestData().serializedItems + .equals(dummyUserData.getEnderChestData().serializedItems) + && deserializedUserData.getPotionEffectsData().serializedPotionEffects + .equals(dummyUserData.getPotionEffectsData().serializedPotionEffects) + && deserializedUserData.getStatusData().health == dummyUserData.getStatusData().health + && deserializedUserData.getStatusData().hunger == dummyUserData.getStatusData().hunger + && deserializedUserData.getStatusData().saturation == dummyUserData.getStatusData().saturation + && deserializedUserData.getStatusData().saturationExhaustion == dummyUserData.getStatusData().saturationExhaustion + && deserializedUserData.getStatusData().selectedItemSlot == dummyUserData.getStatusData().selectedItemSlot + && deserializedUserData.getStatusData().totalExperience == dummyUserData.getStatusData().totalExperience + && deserializedUserData.getStatusData().maxHealth == dummyUserData.getStatusData().maxHealth + && deserializedUserData.getStatusData().healthScale == dummyUserData.getStatusData().healthScale); + }); + Assertions.assertTrue(isEquals.get()); } @Test public void testJsonFormat() { final OnlineUser dummyUser = DummyPlayer.create(); - final UserData dummyUserData = dummyUser.getUserData().join(); - final DataAdapter dataAdapter = new JsonDataAdapter(); - final byte[] data = dataAdapter.toBytes(dummyUserData); - final String json = new String(data, StandardCharsets.UTF_8); final String expectedJson = "{\"status\":{\"health\":20.0,\"max_health\":20.0,\"health_scale\":0.0,\"hunger\":20,\"saturation\":5.0,\"saturation_exhaustion\":5.0,\"selected_item_slot\":1,\"total_experience\":100,\"experience_level\":1,\"experience_progress\":1.0,\"game_mode\":\"SURVIVAL\",\"is_flying\":false},\"inventory\":{\"serialized_items\":\"\"},\"ender_chest\":{\"serialized_items\":\"\"},\"potion_effects\":{\"serialized_potion_effects\":\"\"},\"advancements\":[],\"statistics\":{\"untyped_statistics\":{},\"block_statistics\":{},\"item_statistics\":{},\"entity_statistics\":{}},\"location\":{\"world_name\":\"dummy_world\",\"world_uuid\":\"00000000-0000-0000-0000-000000000000\",\"world_environment\":\"NORMAL\",\"x\":0.0,\"y\":64.0,\"z\":0.0,\"yaw\":90.0,\"pitch\":180.0},\"persistent_data_container\":{\"persistent_data_map\":{}},\"minecraft_version\":\"1.19-beta123456\",\"format_version\":1}"; - Assertions.assertEquals(expectedJson, json); + AtomicReference json = new AtomicReference<>(); + dummyUser.getUserData(new DummyLogger()).join().ifPresent(dummyUserData -> { + final DataAdapter dataAdapter = new JsonDataAdapter(); + final byte[] data = dataAdapter.toBytes(dummyUserData); + json.set(new String(data, StandardCharsets.UTF_8)); + }); + Assertions.assertEquals(expectedJson, json.get()); } @Test public void testCompressedDataAdapter() { final OnlineUser dummyUser = DummyPlayer.create(); - final UserData dummyUserData = dummyUser.getUserData().join(); - final DataAdapter dataAdapter = new CompressedDataAdapter(); - final byte[] data = dataAdapter.toBytes(dummyUserData); - final UserData deserializedUserData = dataAdapter.fromBytes(data); - - boolean isEquals = deserializedUserData.getInventoryData().serializedItems - .equals(dummyUserData.getInventoryData().serializedItems) - && deserializedUserData.getEnderChestData().serializedItems - .equals(dummyUserData.getEnderChestData().serializedItems) - && deserializedUserData.getPotionEffectsData().serializedPotionEffects - .equals(dummyUserData.getPotionEffectsData().serializedPotionEffects) - && deserializedUserData.getStatusData().health == dummyUserData.getStatusData().health - && deserializedUserData.getStatusData().hunger == dummyUserData.getStatusData().hunger - && deserializedUserData.getStatusData().saturation == dummyUserData.getStatusData().saturation - && deserializedUserData.getStatusData().saturationExhaustion == dummyUserData.getStatusData().saturationExhaustion - && deserializedUserData.getStatusData().selectedItemSlot == dummyUserData.getStatusData().selectedItemSlot - && deserializedUserData.getStatusData().totalExperience == dummyUserData.getStatusData().totalExperience - && deserializedUserData.getStatusData().maxHealth == dummyUserData.getStatusData().maxHealth - && deserializedUserData.getStatusData().healthScale == dummyUserData.getStatusData().healthScale; + AtomicBoolean isEquals = new AtomicBoolean(false); + dummyUser.getUserData(new DummyLogger()).join().ifPresent(dummyUserData -> { + final DataAdapter dataAdapter = new CompressedDataAdapter(); + final byte[] data = dataAdapter.toBytes(dummyUserData); + final UserData deserializedUserData = dataAdapter.fromBytes(data); - Assertions.assertTrue(isEquals); + isEquals.set(deserializedUserData.getInventoryData().serializedItems + .equals(dummyUserData.getInventoryData().serializedItems) + && deserializedUserData.getEnderChestData().serializedItems + .equals(dummyUserData.getEnderChestData().serializedItems) + && deserializedUserData.getPotionEffectsData().serializedPotionEffects + .equals(dummyUserData.getPotionEffectsData().serializedPotionEffects) + && deserializedUserData.getStatusData().health == dummyUserData.getStatusData().health + && deserializedUserData.getStatusData().hunger == dummyUserData.getStatusData().hunger + && deserializedUserData.getStatusData().saturation == dummyUserData.getStatusData().saturation + && deserializedUserData.getStatusData().saturationExhaustion == dummyUserData.getStatusData().saturationExhaustion + && deserializedUserData.getStatusData().selectedItemSlot == dummyUserData.getStatusData().selectedItemSlot + && deserializedUserData.getStatusData().totalExperience == dummyUserData.getStatusData().totalExperience + && deserializedUserData.getStatusData().maxHealth == dummyUserData.getStatusData().maxHealth + && deserializedUserData.getStatusData().healthScale == dummyUserData.getStatusData().healthScale); + }); + Assertions.assertTrue(isEquals.get()); } } diff --git a/common/src/test/java/net/william278/husksync/logger/DummyLogger.java b/common/src/test/java/net/william278/husksync/logger/DummyLogger.java new file mode 100644 index 00000000..c44378a1 --- /dev/null +++ b/common/src/test/java/net/william278/husksync/logger/DummyLogger.java @@ -0,0 +1,44 @@ +package net.william278.husksync.logger; + +import de.themoep.minedown.MineDown; +import net.william278.husksync.util.Logger; +import org.jetbrains.annotations.NotNull; + +import java.util.logging.Level; + +public class DummyLogger extends Logger { + + public DummyLogger() { + } + + @Override + public void log(@NotNull Level level, @NotNull String message, @NotNull Exception e) { + System.out.println(level.getName() + ": " + message); + e.printStackTrace(); + } + + @Override + public void log(@NotNull Level level, @NotNull String message) { + System.out.println(level.getName() + ": " + message); + } + + @Override + public void log(@NotNull Level level, @NotNull MineDown mineDown) { + System.out.println(level.getName() + ": " + mineDown.message()); + } + + @Override + public void info(@NotNull String message) { + System.out.println(Level.INFO.getName() + ": " + message); + } + + @Override + public void severe(@NotNull String message) { + System.out.println(Level.SEVERE.getName() + ": " + message); + } + + @Override + public void config(@NotNull String message) { + System.out.println(Level.CONFIG.getName() + ": " + message); + } +} From 9d6da91a5e1b6c1ed21ab5cc93ebe3f7ae94b057 Mon Sep 17 00:00:00 2001 From: William Date: Wed, 13 Jul 2022 11:48:09 +0100 Subject: [PATCH 4/4] Bump up to 2.1 --- gradle.properties | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/gradle.properties b/gradle.properties index 8d5cd6a9..20a73e28 100644 --- a/gradle.properties +++ b/gradle.properties @@ -3,5 +3,5 @@ org.gradle.jvmargs='-Dfile.encoding=UTF-8' org.gradle.daemon=true javaVersion=16 -plugin_version=2.0 +plugin_version=2.1 plugin_archive=husksync \ No newline at end of file