Phase 5: structured logging + periodic pool-stats reporter
SyncLogger additions
- containerForceClosed(uuid, reason)
- modCompatSkip / modCompatSaved / modCompatRestored (per-mod tracing)
- storageSave(storageUuid, kind, detail) for backpack/SS/RS2 lines
- poolStats(exec active/queue/idle, hikari active/idle)
- warnPlayer / nbtAnomaly generic helpers
PoolStatsReporter.java
- Dedicated single-thread daemon scheduler, 5-min cadence.
- Reads VanillaSync.executorService stats via reflection.
- Reads HikariCP MBean via new JDBCsetUp.getPoolMXBean().
- Emits WARN logs when executor queue > 400/512 or Hikari active >= 14/15
so admins see saturation trends before they become outages.
JDBCsetUp.getPoolMXBean()
- Public accessor for the HikariCP pool MBean. Returns null when pool
is uninitialised / closed.
Wire-in: PlayerSync.onServerStarting starts the reporter, onServerShutdown
stops it before pool close.
Instrumentation
- VanillaSync.onPlayerLogout logs containerForceClosed for self + viewer
containers.
- ModCompatSync.snapshotAccessories logs modCompatSkip when cap==null.
This commit is contained in:
parent
c70ca9f464
commit
bd0482cb76
|
|
@ -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!");
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -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) {}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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<String, String> flatMap = new HashMap<>();
|
||||
for (Map.Entry<String, io.wispforest.accessories.api.AccessoriesContainer> entry : cap.getContainers().entrySet()) {
|
||||
String slotType = entry.getKey();
|
||||
|
|
|
|||
|
|
@ -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
|
||||
// -------------------------------------------------------------------------
|
||||
|
|
|
|||
|
|
@ -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;
|
||||
}
|
||||
}
|
||||
|
|
@ -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
|
||||
// -------------------------------------------------------------------------
|
||||
|
|
|
|||
Loading…
Reference in New Issue
Block a user