diff --git a/src/main/java/vip/fubuki/playersync/PlayerSync.java b/src/main/java/vip/fubuki/playersync/PlayerSync.java index b73e49b..e0ceab0 100644 --- a/src/main/java/vip/fubuki/playersync/PlayerSync.java +++ b/src/main/java/vip/fubuki/playersync/PlayerSync.java @@ -222,6 +222,9 @@ public class PlayerSync { // Phase 4: periodic full-flush scheduler (default 10 min). vip.fubuki.playersync.util.PeriodicSaveService.start(); + // Phase 5: pool / executor stats reporter (every 5 min into sync.log). + vip.fubuki.playersync.util.PoolStatsReporter.start(); + LOGGER.info("PlayerSync is ready!"); } diff --git a/src/main/java/vip/fubuki/playersync/sync/VanillaSync.java b/src/main/java/vip/fubuki/playersync/sync/VanillaSync.java index 656e21d..b24e0d9 100644 --- a/src/main/java/vip/fubuki/playersync/sync/VanillaSync.java +++ b/src/main/java/vip/fubuki/playersync/sync/VanillaSync.java @@ -1102,6 +1102,8 @@ public class VanillaSync { vip.fubuki.playersync.util.HeartbeatService.stop(); // Phase 4: stop periodic-save scheduler before pool shutdown. vip.fubuki.playersync.util.PeriodicSaveService.stop(); + // Phase 5: stop pool-stats reporter. + vip.fubuki.playersync.util.PoolStatsReporter.stop(); // Shut down the background executor — no new tasks after this point executorService.shutdown(); @@ -1246,6 +1248,7 @@ public class VanillaSync { // Closing the container menu ensures no further modifications can occur. if (player instanceof ServerPlayer sp && sp.containerMenu != sp.inventoryMenu) { sp.closeContainer(); + SyncLogger.containerForceClosed(player_uuid, "self container on logout"); } // FIX CRITICAL ANTI-DUP: close every other player's container menu if it was // opened against this disconnecting player's inventory/backpack. If another @@ -1276,7 +1279,11 @@ public class VanillaSync { } } catch (Exception ignored) {} if (shouldClose) { - try { other.closeContainer(); } catch (Exception ignored) {} + try { + other.closeContainer(); + SyncLogger.containerForceClosed(player_uuid, + "viewer " + other.getUUID() + " had a menu referencing disconnecting player's inv/enderchest"); + } catch (Exception ignored) {} } } } diff --git a/src/main/java/vip/fubuki/playersync/sync/addons/ModCompatSync.java b/src/main/java/vip/fubuki/playersync/sync/addons/ModCompatSync.java index d0a4c36..16db112 100644 --- a/src/main/java/vip/fubuki/playersync/sync/addons/ModCompatSync.java +++ b/src/main/java/vip/fubuki/playersync/sync/addons/ModCompatSync.java @@ -488,7 +488,12 @@ public class ModCompatSync { // FIX ANTI-LOSS (A2): cap==null means the capability isn't attached yet — // return null to SKIP write and preserve DB. Do NOT return "{}" here, as that // would wipe a legitimate accessories record. - if (cap == null) return null; + if (cap == null) { + vip.fubuki.playersync.util.SyncLogger.modCompatSkip( + player.getUUID().toString(), "accessories", + "capability unavailable — skipping write to preserve DB"); + return null; + } Map flatMap = new HashMap<>(); for (Map.Entry entry : cap.getContainers().entrySet()) { String slotType = entry.getKey(); diff --git a/src/main/java/vip/fubuki/playersync/util/JDBCsetUp.java b/src/main/java/vip/fubuki/playersync/util/JDBCsetUp.java index 732602b..a73163e 100644 --- a/src/main/java/vip/fubuki/playersync/util/JDBCsetUp.java +++ b/src/main/java/vip/fubuki/playersync/util/JDBCsetUp.java @@ -78,6 +78,19 @@ public class JDBCsetUp { } } + /** + * Exposes the HikariCP MBean for monitoring. Returns {@code null} if the + * pool is not initialised or already closed. Used by PoolStatsReporter. + */ + public static com.zaxxer.hikari.HikariPoolMXBean getPoolMXBean() { + try { + if (dataSource == null || dataSource.isClosed()) return null; + return dataSource.getHikariPoolMXBean(); + } catch (Throwable t) { + return null; + } + } + // ------------------------------------------------------------------------- // Internal helpers // ------------------------------------------------------------------------- diff --git a/src/main/java/vip/fubuki/playersync/util/PoolStatsReporter.java b/src/main/java/vip/fubuki/playersync/util/PoolStatsReporter.java new file mode 100644 index 0000000..dd10e40 --- /dev/null +++ b/src/main/java/vip/fubuki/playersync/util/PoolStatsReporter.java @@ -0,0 +1,87 @@ +package vip.fubuki.playersync.util; + +import com.zaxxer.hikari.HikariPoolMXBean; +import vip.fubuki.playersync.PlayerSync; + +import java.lang.reflect.Method; +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.ThreadPoolExecutor; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; + +/** + * Periodic reporter that logs executor + HikariCP stats every 5 minutes into + * the PlayerSync sync.log. Lets admins spot queue saturation or pool + * exhaustion trends without waiting for a crash. Non-invasive — pure read-only. + * + * @author vyrriox + */ +public final class PoolStatsReporter { + + private PoolStatsReporter() {} + + private static final long PERIOD_MS = 5 * 60 * 1000L; + + private static final AtomicBoolean RUNNING = new AtomicBoolean(false); + private static ScheduledExecutorService scheduler; + + public static void start() { + if (!RUNNING.compareAndSet(false, true)) return; + scheduler = Executors.newSingleThreadScheduledExecutor(r -> { + Thread t = new Thread(r, "PlayerSync-pool-stats"); + t.setDaemon(true); + t.setPriority(Thread.MIN_PRIORITY); + return t; + }); + scheduler.scheduleAtFixedRate(PoolStatsReporter::tick, PERIOD_MS, PERIOD_MS, TimeUnit.MILLISECONDS); + PlayerSync.LOGGER.info("[pool-stats] reporter started (period={}ms)", PERIOD_MS); + } + + public static void stop() { + if (!RUNNING.compareAndSet(true, false)) return; + if (scheduler != null) { + scheduler.shutdownNow(); + scheduler = null; + } + } + + private static void tick() { + try { + // Pull executor stats via reflection — VanillaSync.executorService is package-private static + ThreadPoolExecutor exec = getExecutor(); + int active = exec != null ? exec.getActiveCount() : -1; + int queue = exec != null ? exec.getQueue().size() : -1; + int idle = exec != null ? exec.getPoolSize() - exec.getActiveCount() : -1; + + HikariPoolMXBean hikari = JDBCsetUp.getPoolMXBean(); + int hActive = hikari != null ? hikari.getActiveConnections() : -1; + int hIdle = hikari != null ? hikari.getIdleConnections() : -1; + + SyncLogger.poolStats(active, queue, idle, hActive, hIdle); + + // Warn if queue is getting dangerously full + if (queue > 400) { + PlayerSync.LOGGER.warn("[pool-stats] executor queue high: {}/512 — risk of CallerRunsPolicy blocking main thread", queue); + SyncLogger.warnPlayer("SYSTEM", "Executor queue high: " + queue + "/512"); + } + if (hActive >= 0 && hActive >= 14) { + PlayerSync.LOGGER.warn("[pool-stats] HikariCP active connections high: {}/15 — risk of connection starvation", hActive); + SyncLogger.warnPlayer("SYSTEM", "HikariCP active: " + hActive + "/15"); + } + } catch (Throwable t) { + PlayerSync.LOGGER.warn("[pool-stats] tick failed: {}", t.getMessage()); + } + } + + private static ThreadPoolExecutor getExecutor() { + try { + Class c = Class.forName("vip.fubuki.playersync.sync.VanillaSync"); + java.lang.reflect.Field f = c.getDeclaredField("executorService"); + f.setAccessible(true); + Object o = f.get(null); + if (o instanceof ThreadPoolExecutor tpe) return tpe; + } catch (Throwable ignored) {} + return null; + } +} diff --git a/src/main/java/vip/fubuki/playersync/util/SyncLogger.java b/src/main/java/vip/fubuki/playersync/util/SyncLogger.java index 911cda6..983abb0 100644 --- a/src/main/java/vip/fubuki/playersync/util/SyncLogger.java +++ b/src/main/java/vip/fubuki/playersync/util/SyncLogger.java @@ -154,6 +154,51 @@ public class SyncLogger { log("RESTORE_FAIL", "[{}] Data restore FAILED: {}", playerUuid, reason); } + // ------------------------------------------------------------------------- + // Phase 5: structured diagnostic events + // ------------------------------------------------------------------------- + + /** Force-close of a container on player logout (anti-duplication). */ + public static void containerForceClosed(String playerUuid, String reason) { + log("CONTAINER_CLOSE", "[{}] {}", playerUuid, reason); + } + + /** Mod-compat save skipped because capability/handler was unavailable. */ + public static void modCompatSkip(String playerUuid, String modId, String reason) { + log("MOD_SKIP", "[{}] {} — {}", playerUuid, modId, reason); + } + + /** Mod-compat save succeeded with metadata (e.g. slot count, NBT keys). */ + public static void modCompatSaved(String playerUuid, String modId, String detail) { + log("MOD_SAVE", "[{}] {} — {}", playerUuid, modId, detail); + } + + /** Mod-compat restore succeeded with metadata. */ + public static void modCompatRestored(String playerUuid, String modId, String detail) { + log("MOD_RESTORE", "[{}] {} — {}", playerUuid, modId, detail); + } + + /** RS2/backpack/SS storage-level save detail (keyed by storage UUID, not player). */ + public static void storageSave(String storageUuid, String kind, String detail) { + log("STORAGE", "[{}] {} — {}", storageUuid, kind, detail); + } + + /** Periodic pool / queue status snapshot (every N minutes). */ + public static void poolStats(int active, int queueSize, int idle, int hikariActive, int hikariIdle) { + log("POOL", "executor active={} queue={} pool_idle={} | hikari active={} idle={}", + active, queueSize, idle, hikariActive, hikariIdle); + } + + /** Generic warning with player context. */ + public static void warnPlayer(String playerUuid, String detail) { + log("WARN", "[{}] {}", playerUuid, detail); + } + + /** Detected NBT anomaly (suspicious shape / size). */ + public static void nbtAnomaly(String playerUuid, String detail) { + log("NBT_ANOMALY", "[{}] {}", playerUuid, detail); + } + // ------------------------------------------------------------------------- // Internal — async file writing // -------------------------------------------------------------------------