Fix xp quicktake/store orb spawn value race; gate xp debug logs

Author: phoenixlzx

src/main/java/cat/nyaa/ukit/utils/ExperienceUtils.java

@@ -9,6 +9,7 @@
 
 import java.util.List;
 import java.util.Random;
+import java.util.function.Consumer;
 
 
 public final class ExperienceUtils {
@@ -78,13 +79,23 @@ public static double conditionalRounding(double value) {
     }
 
     public static void splashExp(int amount, Location location) {
+        splashExp(amount, location, null);
+    }
+
+    public static void splashExp(int amount, Location location, Consumer<ExperienceOrb> orbCustomizer) {
         var nextOrbValueIndex = 0;
         while (amount > 0) {
             nextOrbValueIndex = firstMatchedExpIndex(amount, nextOrbValueIndex);
             var nextOrbValue = usableSplashExpList.get(nextOrbValueIndex);
-            var experienceOrb = location.getWorld().spawn(location, ExperienceOrb.class, CreatureSpawnEvent.SpawnReason.CUSTOM);
-            experienceOrb.setExperience(nextOrbValue);
-            experienceOrb.setVelocity(randomVector().multiply(0.3));
+            location.getWorld().spawn(location, ExperienceOrb.class, orb -> {
+                // Configure orb value before it is added to world so merge-on-spawn
+                // sees the final value instead of default 0.
+                orb.setExperience(nextOrbValue);
+                orb.setVelocity(randomVector().multiply(0.3));
+                if (orbCustomizer != null) {
+                    orbCustomizer.accept(orb);
+                }
+            }, CreatureSpawnEvent.SpawnReason.CUSTOM);
             amount -= nextOrbValue;
         }
     }

src/main/java/cat/nyaa/ukit/xpstore/XpStoreConfig.java

@@ -6,4 +6,6 @@ public class XpStoreConfig {
     public int quickTakeMinimumAmount = 10;
     public int quickTakeArmTimeInMillisecond = 2000;
     public double quickTakeRatio = 0.01;
+    public boolean debugLog = false;
+    public boolean debugVerbose = false;
 }

src/main/java/cat/nyaa/ukit/xpstore/XpStoreFunction.java

@@ -37,6 +37,7 @@ public class XpStoreFunction implements SubCommandExecutor, SubTabCompleter, Lis
     private final NamespacedKey QuickTakePreferenceKey;
     private final NamespacedKey QuickTakeLoreIndexKey;
     private final NamespacedKey ThrownExpAmountKey;
+    private final NamespacedKey XpStoreOrbMarkerKey;
     private final String EXPBOTTLE_PERMISSION_NODE = "ukit.xpstore";
     private final Map<UUID, Long> quickTakeArmMap = new HashMap<>();
     private final List<String> subCommands = List.of("store", "take", "quicktake");
@@ -48,6 +49,7 @@ public XpStoreFunction(SpigotLoader pluginInstance) {
         QuickTakeLoreIndexKey = new NamespacedKey(pluginInstance, "QUICK_TAKE_LORE_INDEX");
         QuickTakePreferenceKey = new NamespacedKey(pluginInstance, "QUICK_TAKE_AMOUNT");
         ThrownExpAmountKey = new NamespacedKey(pluginInstance, "THROWN_EXP_AMOUNT");
+        XpStoreOrbMarkerKey = new NamespacedKey(pluginInstance, "XPSTORE_ORB_MARKER");
     }
 
     @Override
@@ -91,6 +93,13 @@ public boolean invokeCommand(CommandSender commandSender, Command command, Strin
         }
         if (args[0].equalsIgnoreCase("store")) {
             var expTotal = amountItem * amountInput;
+            debugLog("store request player=" + senderPlayer.getName()
+                    + " thread=" + Thread.currentThread().getName()
+                    + " bottles=" + amountItem
+                    + " amount_per_bottle=" + amountInput
+                    + " total=" + expTotal
+                    + " exp_in_item=" + expInItem
+                    + " exp_player=" + ExperienceUtils.getExpPoints(senderPlayer));
             if (ExperienceUtils.getExpPoints(senderPlayer) < expTotal) {
                 senderPlayer.sendMessage(pluginInstance.language.xpStoreLang.notEnoughExp.produce(
                         Pair.of("expTotal", expTotal),
@@ -115,6 +124,13 @@ public boolean invokeCommand(CommandSender commandSender, Command command, Strin
             var expTotal = getMinimumDivisible(amountInput, amountItem);
             var amountAverage = expTotal / amountItem;
             var amountContained = getExpContained(itemInHand);
+            debugLog("take request player=" + senderPlayer.getName()
+                    + " thread=" + Thread.currentThread().getName()
+                    + " bottles=" + amountItem
+                    + " ask_total=" + amountInput
+                    + " actual_total=" + expTotal
+                    + " amount_per_bottle=" + amountAverage
+                    + " amount_contained=" + amountContained);
             if (amountContained < amountAverage) {
                 senderPlayer.sendMessage(pluginInstance.language.xpStoreLang.notEnoughExpInBottle.produce(
                         Pair.of("amount", amountAverage)
@@ -285,6 +301,19 @@ private Integer getQuickTakePreference(ItemStack itemStack) {
             return meta.getPersistentDataContainer().get(QuickTakePreferenceKey, PersistentDataType.INTEGER);
     }
 
+    private boolean isDebugEnabled() {
+        return pluginInstance.config.xpStoreConfig.debugLog;
+    }
+
+    private boolean isDebugVerbose() {
+        return pluginInstance.config.xpStoreConfig.debugVerbose;
+    }
+
+    private void debugLog(String message) {
+        if (!isDebugEnabled()) return;
+        pluginInstance.getLogger().info("[xpstore-debug] " + message);
+    }
+
     @EventHandler(ignoreCancelled = true)
     public void onPlayerLaunchExpBottle(PlayerLaunchProjectileEvent event) {
         if (!(event.getProjectile() instanceof ThrownExpBottle thrownExpBottle)) return;
@@ -293,6 +322,12 @@ public void onPlayerLaunchExpBottle(PlayerLaunchProjectileEvent event) {
         int expAmount = getExpContained(item);
         if (expAmount <= 0) return;
         thrownExpBottle.getPersistentDataContainer().set(ThrownExpAmountKey, PersistentDataType.INTEGER, expAmount);
+        if (isDebugVerbose()) {
+            debugLog("launch(PlayerLaunchProjectileEvent) thread=" + Thread.currentThread().getName()
+                    + " player=" + event.getPlayer().getName()
+                    + " projectile=" + thrownExpBottle.getUniqueId()
+                    + " exp_amount=" + expAmount);
+        }
     }
 
     @EventHandler(ignoreCancelled = true)
@@ -304,21 +339,36 @@ public void onExpBottleLaunch(ProjectileLaunchEvent event) {
         int expAmount = getExpContained(item);
         if (expAmount <= 0) return;
         thrownExpBottle.getPersistentDataContainer().set(ThrownExpAmountKey, PersistentDataType.INTEGER, expAmount);
+        if (isDebugVerbose()) {
+            debugLog("launch(ProjectileLaunchEvent) thread=" + Thread.currentThread().getName()
+                    + " projectile=" + thrownExpBottle.getUniqueId()
+                    + " exp_amount=" + expAmount);
+        }
     }
 
     @EventHandler(priority = EventPriority.HIGHEST)
     public void onExpBottleHit(ExpBottleEvent event) {
         ThrownExpBottle thrownExpBottle = event.getEntity();
+        int vanillaExp = event.getExperience();
         Integer expAmount = thrownExpBottle.getPersistentDataContainer().get(ThrownExpAmountKey, PersistentDataType.INTEGER);
+        boolean fromProjectilePdc = expAmount != null;
         if (expAmount == null) {
             var item = thrownExpBottle.getItem();
             if (!isExpContainer(item)) return;
             expAmount = getExpContained(item);
         }
         if (expAmount <= 0) return;
         event.setExperience(0);
-        ExperienceUtils.splashExp(expAmount, thrownExpBottle.getLocation());
+        ExperienceUtils.splashExp(expAmount, thrownExpBottle.getLocation(), orb ->
+                orb.getPersistentDataContainer().set(XpStoreOrbMarkerKey, PersistentDataType.BYTE, (byte) 1)
+        );
         thrownExpBottle.getPersistentDataContainer().remove(ThrownExpAmountKey);
+        debugLog("hit(ExpBottleEvent) thread=" + Thread.currentThread().getName()
+                + " projectile=" + thrownExpBottle.getUniqueId()
+                + " vanilla_exp=" + vanillaExp
+                + " ukit_exp=" + expAmount
+                + " source=" + (fromProjectilePdc ? "projectile_pdc" : "item_pdc_fallback")
+                + " show_effect=" + event.getShowEffect());
     }
 
     @EventHandler
@@ -351,7 +401,15 @@ public void onRightClickBottle(PlayerInteractEvent event) {
         addExpToItemStack(item, -amountTake);
         Utils.setItemInHand(event.getPlayer(), Pair.of(event.getHand(), item));
         var amountTotal = itemAmount * amountTake;
-        ExperienceUtils.splashExp(amountTotal, event.getPlayer().getLocation());
+        ExperienceUtils.splashExp(amountTotal, event.getPlayer().getLocation(), orb ->
+                orb.getPersistentDataContainer().set(XpStoreOrbMarkerKey, PersistentDataType.BYTE, (byte) 1)
+        );
+        debugLog("quicktake produce thread=" + Thread.currentThread().getName()
+                + " player=" + event.getPlayer().getName()
+                + " item_amount=" + itemAmount
+                + " amount_take_per_bottle=" + amountTake
+                + " total_spawned=" + amountTotal
+                + " remaining_per_bottle=" + getExpContained(item));
 
         event.getPlayer().sendActionBar(pluginInstance.language.xpStoreLang.quickTakeNotice.produce(
                 Pair.of("amount", amountTotal),