diff --git a/src/main/java/noppes/npcs/controllers/data/action/Action.java b/src/main/java/noppes/npcs/controllers/data/action/Action.java index e98b6c70a..9bad65fa8 100644 --- a/src/main/java/noppes/npcs/controllers/data/action/Action.java +++ b/src/main/java/noppes/npcs/controllers/data/action/Action.java @@ -107,7 +107,7 @@ public class Action implements IAction { this.isScheduled = true; if (manager.debug) - manager.logDebug(String.format("Scheduled Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log(String.format("Scheduled Action '%s'", name), queue); } @Override @@ -249,7 +249,7 @@ public class Action implements IAction { done = true; if (manager.debug) - manager.logDebug(String.format("Marked done Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Marked done!", this); } @Override @@ -280,7 +280,7 @@ public class Action implements IAction { duration++; if (manager.debug) - manager.logDebug(String.format("Ticking Action '%s' (duration = %s/%s, count = %s/%s) on queue '%s'", name, duration, maxDuration, count, maxCount, getQueueName())); + manager.LOGGER.log(String.format("Ticking... (duration = %s/%s, count = %s/%s)", duration, maxDuration, count, maxCount), this); if (startAfterTicks > 0) { startAfterTicks--; @@ -289,7 +289,7 @@ public class Action implements IAction { if (maxDuration > -1 && duration >= maxDuration || maxCount == 0) { if (manager.debug) - manager.logDebug(String.format("Reached max duration of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Reached max duration", this); markDone(); return; @@ -300,7 +300,7 @@ public class Action implements IAction { if (maxCount > -1 && count >= maxCount) { if (manager.debug) - manager.logDebug(String.format("Reached max count of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Reached max count of Action '%s' on queue '%s'", this); markDone(); } @@ -316,45 +316,46 @@ public class Action implements IAction { protected void executeOnStart() { if (manager.debug) - manager.logDebug(String.format("Started executing onStart task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Executing onStart task...", this); + try { onStart.accept(this); } catch (Throwable t) { - manager.logDebug("Start Task of " + this + " threw an exception:", t); + manager.LOGGER.error("onStart Task of " + this + " threw an exception:", t); } if (manager.debug) - manager.logDebug(String.format("Finished executing onStart task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Finished executing onStart task", this); } protected void executeTask() { if (manager.debug) - manager.logDebug(String.format("Started executing task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Executing task...", this); try { task.accept(this); count++; } catch (Throwable t) { - manager.logDebug("Task of " + this + " threw an exception:", t); + manager.LOGGER.error("Task of " + this + " threw an exception:", t); markDone(); } if (manager.debug) - manager.logDebug(String.format("Finished executing task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Finished executing task", this); } protected void executeOnDone() { if (manager.debug) - manager.logDebug(String.format("Started executing onDone task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Executing onDone task...", this); try { onDone.accept(this); } catch (Throwable t) { - manager.logDebug("Done Task of " + this + " threw an exception:", t); + manager.LOGGER.error("onDone Task of " + this + " threw an exception:", t); } if (manager.debug) - manager.logDebug(String.format("Finished executing onDone task of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Finished executing onDone task", this); } @@ -368,7 +369,7 @@ public class Action implements IAction { done = true; if (manager.debug) - manager.logDebug(String.format("Killing Action '%s' on queue '%s'", name, queue != null ? getQueueName() : "null")); + manager.LOGGER.log(String.format("Killed Action '%s'", name), queue); } public String toString() { diff --git a/src/main/java/noppes/npcs/controllers/data/action/ActionLogger.java b/src/main/java/noppes/npcs/controllers/data/action/ActionLogger.java new file mode 100644 index 000000000..34eacb9a5 --- /dev/null +++ b/src/main/java/noppes/npcs/controllers/data/action/ActionLogger.java @@ -0,0 +1,190 @@ +package noppes.npcs.controllers.data.action; + +import noppes.npcs.LogWriter; +import noppes.npcs.api.handler.data.IAction; +import noppes.npcs.api.handler.data.IActionQueue; +import org.apache.commons.lang3.StringUtils; +import org.apache.commons.lang3.exception.ExceptionUtils; + +import java.util.*; + +public class ActionLogger { + // private final Map> snapshot = new HashMap<>(); + private final ActionManager manager; + private final Deque stack = new ArrayDeque<>(); + private TreeNode root, currentNode; + + static class TreeNode { + public final Object component; //ActionManager, or ActionQueue, or Action, etc... + public final List children = new ArrayList<>(); + public TreeNode parent; + + public boolean isLastChild() { + if (parent == null) + return true; + List siblings = parent.children; + return siblings.get(siblings.size() - 1) == this; + } + + public TreeNode(Object component) { + this.component = component; + } + + public TreeNode addChild(Object component) { + TreeNode child = new TreeNode(component); + children.add(child); + child.parent = this; + return child; + } + } + + public ActionLogger(ActionManager manager) { + this.manager = manager; + } + + public ActionLogger beginTick(ActionManager manager) { + stack.clear(); + + root = currentNode = new TreeNode(manager); + for (IActionQueue queue : manager.getAllQueues()) { + if (!queue.hasActiveTasks()) + continue; + TreeNode queueNode = root.addChild(queue); + + for (IAction action : queue.getQueue()) + queueNode.addChild(action); + } + + return this; + } + + public ActionLogger push(Object component) { + for (TreeNode child : currentNode.children) { + if (child.component.equals(component)) { + currentNode = child; + break; + } + } + + stack.push(currentNode); + return this; + } + + public ActionLogger pop() { + if (!stack.isEmpty()) + currentNode = stack.pop(); + + return this; + } + + public ActionLogger finish(String finished, Object component) { + log(finished, component); + log(StringUtils.repeat("-", finished.length()), component, true); + return this; + } + + public ActionLogger log(String message, Object source) { + return log(message, source, false); + } + + public ActionLogger log(String message, Object source, boolean isLast) { + StringBuilder prefix = new StringBuilder(); + + ListIterator it = new ArrayList<>(stack).listIterator(stack.size()); + + while (it.hasPrevious()) { + TreeNode node = it.previous(); + if (it.hasPrevious()) { + prefix.append("│ "); + } else { + prefix.append(isLast ? "└──── " : "├──── "); + } + } + + String header = getLogHeader(source); + LogWriter.info(prefix + header + message); + + return this; + } + + public void error(String err, Throwable t) { + if (manager.reportTo != null) + manager.reportTo.appendConsole(err + (t != null ? "\n" + ExceptionUtils.getStackTrace(t) : "")); + + LogWriter.error(err); + if (t != null) + t.printStackTrace(); + } + + private String getLogHeader(Object obj) { + String type = obj.getClass().getSimpleName(); + String name = ""; + + if (obj instanceof ActionManager) { + name = ((ActionManager) obj).getName(); + } else if (obj instanceof IActionQueue) { + name = ((IActionQueue) obj).getName(); + } else if (obj instanceof IAction) { + name = ((IAction) obj).getName(); + } + + return String.format("[%s/'%s'] ", type, name); + } + + + // public ActionLogger beginTick1(ActionManager manager) { + // snapshot.clear(); + // stack.clear(); + // + // List queues = Arrays.stream(manager.getAllQueues()).filter(IActionQueue::hasActiveTasks).collect(Collectors.toList()); + // snapshot.put(manager, queues); + // + // for (IActionQueue queue : queues) { + // LinkedList contents = new LinkedList<>(); + // contents.add(queue); + // + // for (IAction a : queue.getQueue()) + // contents.add(a); + // + // // Actions only (not the queue itself) + // snapshot.put(queue, contents.subList(1, contents.size())); + // } + // + // return this; + // } + + // + // private Object getParent() { + // return stack.isEmpty() ? null : stack.peek().component; + // } + + // public ActionLogger push1(Object component) { + // List siblings = snapshot.get(getParent()); + // boolean isLast = siblings != null && !siblings.isEmpty() && siblings.get(siblings.size() - 1).equals(component); + // + // stack.push(new TreeNode(component)); + // return this; + // } + + // + // public void log(String message, Object source, int in) { + // StringBuilder prefix = new StringBuilder(); + // Deque branches = branchStack.get(); + // int depth = branches.size(); + // + // Iterator iter = branches.descendingIterator(); + // for (int i = 0; i < depth - 1; i++) { + // prefix.append(iter.next() ? " " : "│ "); + // } + // + // if (depth > 0) { + // prefix.append(branches.peek() ? "└── " : "├── "); + // } + // + // String header = getHeader(source); + // int pad = Math.max(0, maxHeaderLength - header.length()); + // String formatted = prefix + header + StringUtils.repeat(" ", pad) + message; + // + // output.accept(formatted); + // } +} diff --git a/src/main/java/noppes/npcs/controllers/data/action/ActionManager.java b/src/main/java/noppes/npcs/controllers/data/action/ActionManager.java index 152048992..f379d5dd5 100644 --- a/src/main/java/noppes/npcs/controllers/data/action/ActionManager.java +++ b/src/main/java/noppes/npcs/controllers/data/action/ActionManager.java @@ -7,7 +7,6 @@ import noppes.npcs.api.handler.data.IActionQueue; import noppes.npcs.api.handler.data.actions.IConditionalAction; import noppes.npcs.controllers.ScriptContainer; import noppes.npcs.controllers.data.action.action.ConditionalAction; -import org.apache.commons.lang3.exception.ExceptionUtils; import java.util.*; import java.util.function.Consumer; @@ -23,6 +22,7 @@ import java.util.function.Function; */ public class ActionManager implements IActionManager { protected boolean isWorking = false; + public ActionLogger LOGGER = new ActionLogger(this); protected String name = ""; protected final ActionQueue sequentialQueue = new ActionQueue(this, "mainSequential"); @@ -368,6 +368,10 @@ public class ActionManager implements IActionManager { return allQueues.toArray(new IActionQueue[0]); } + + public boolean hasActiveTasks() { + return Arrays.stream(getAllQueues()).anyMatch(queue -> queue.hasActiveTasks()); + } @Override public boolean hasAny(String name) { return getAny(name) != null; @@ -423,8 +427,9 @@ public class ActionManager implements IActionManager { public void tick() { if (!isWorking) return; - if (debug) - logDebug(String.format("Started '%s' Tick Cycle", getInternalName())); + boolean active = hasActiveTasks(); + if (debug && active) + LOGGER.beginTick(this).log("Started Tick Cycle", this); // ─── Sequential (head only) ───────────────────────────────── sequentialQueue.tick(); @@ -444,13 +449,13 @@ public class ActionManager implements IActionManager { if (other.isDead()) { other.clear(); if (debug) - logDebug(String.format("Removing queue '%s' from '%s'", other.getName(), getInternalName())); + LOGGER.log(String.format("Removing queue '%s' from '%s'", other.getName(), getInternalName()), this); it.remove(); } } - if (debug) - logDebug(String.format("Finished '%s' Tick Cycle", getInternalName())); + if (debug && active) + LOGGER.finish("Finished Tick Cycle",this); } @Override @@ -461,26 +466,13 @@ public class ActionManager implements IActionManager { otherQueues.forEach((name, queue) -> queue.clear()); if (debug) - logDebug(String.format("Cleared '%s'", getInternalName())); + LOGGER.log("Cleared all queues!", this); } public String getInternalName() { return name.isEmpty() ? "Action Manager" : name; } - public void logDebug(String err) { - logDebug(err, null); - } - - public void logDebug(String err, Throwable t) { - if (this.reportTo != null) - this.reportTo.appendConsole(err + (t != null ? "\n" + ExceptionUtils.getStackTrace(t) : "")); - - System.err.println(err); - if (t != null) - t.printStackTrace(); - } - @Override public IActionChain chain() { return sequentialQueue.chain(); diff --git a/src/main/java/noppes/npcs/controllers/data/action/ActionQueue.java b/src/main/java/noppes/npcs/controllers/data/action/ActionQueue.java index 744822cfd..d55b44101 100644 --- a/src/main/java/noppes/npcs/controllers/data/action/ActionQueue.java +++ b/src/main/java/noppes/npcs/controllers/data/action/ActionQueue.java @@ -102,7 +102,7 @@ public class ActionQueue implements IActionQueue { this.isDead = true; if (manager.debug) - manager.logDebug(String.format("Killing queue '%s' on '%s'", name, manager.getInternalName())); + manager.LOGGER.log(String.format("Killing queue '%s' on '%s'", name, manager.getInternalName()), this); return this; } @@ -188,6 +188,7 @@ public class ActionQueue implements IActionQueue { /////////////////////////////////////////////////// // Queue Data + @Override public boolean hasActiveTasks() { return !queue.isEmpty(); } @@ -261,7 +262,17 @@ public class ActionQueue implements IActionQueue { // Handling protected boolean tick(Action a) { + if (a == null) + return false; + + if (manager.debug) + manager.LOGGER.push(this).log(String.format("Started ticking Action '%s' ", a.name), this).push(a); + a.tick(); + + if (manager.debug) + manager.LOGGER.pop().finish(String.format("Finished ticking Action '%s' ", a.name), this).pop(); + if (a.isDone()) { if (a.onDone != null) a.execute("done", a::executeOnDone); @@ -269,7 +280,7 @@ public class ActionQueue implements IActionQueue { a.kill(); if (manager.debug) - a.manager.logDebug(String.format("Removing Action '%s' from queue '%s'", a.name, name)); + manager.LOGGER.finish(String.format("Removing Action '%s' from queue", a.name), this); return true; } @@ -280,8 +291,9 @@ public class ActionQueue implements IActionQueue { if (!isWorking || isDead) return; - if (manager.debug) - manager.logDebug(String.format("Started ticking queue '%s'", name)); + boolean active = hasActiveTasks(); + if (manager.debug && active) + manager.LOGGER.push(manager).log(String.format("Started ticking queue '%s' ", name), manager).push(this); if (!isParallel) { if (tick((Action) getCurrentAction())) @@ -295,19 +307,19 @@ public class ActionQueue implements IActionQueue { killWhenEmpty(); - if (manager.debug) - manager.logDebug(String.format("Finished ticking queue '%s'", name)); + if (manager.debug && active) + manager.LOGGER.pop().finish(String.format("Finished ticking queue '%s' ", name), manager).pop(); } protected void killWhenEmpty() { if (killWhenEmpty && !hasActiveTasks() && autoKill == null) { if (manager.debug) - manager.logDebug(String.format("Queue '%s' is empty! Killing in %s ticks", name, killWhenEmptyAfter)); + manager.LOGGER.log(String.format("Queue is empty! Killing in %s ticks", killWhenEmptyAfter), this); - autoKill = (Action) manager.create(killWhenEmptyAfter, (act) -> { + autoKill = (Action) manager.create(String.format("Kill '%s'", name), killWhenEmptyAfter, (act) -> { if (hasActiveTasks()) { if (manager.debug) - manager.logDebug(String.format("Scheduled Actions found! Aborted kill process for queue '%s'", name)); + manager.LOGGER.log("Scheduled Actions found! Aborted kill process", this); return; } @@ -328,7 +340,7 @@ public class ActionQueue implements IActionQueue { queue.clear(); if (manager.debug) - manager.logDebug(String.format("Cleared queue '%s' on '%s'", name, manager.getInternalName())); + manager.LOGGER.log("Cleared queue!", this); } @Override diff --git a/src/main/java/noppes/npcs/controllers/data/action/ActionThread.java b/src/main/java/noppes/npcs/controllers/data/action/ActionThread.java index 684031c4e..c4df4858c 100644 --- a/src/main/java/noppes/npcs/controllers/data/action/ActionThread.java +++ b/src/main/java/noppes/npcs/controllers/data/action/ActionThread.java @@ -41,7 +41,7 @@ public class ActionThread { if (action.manager.debug) - action.manager.logDebug(String.format("Stopping thread of Action '%s' on queue '%s'", action.name, action.getQueueName())); + action.manager.LOGGER.log("Stopping thread", action); } public void pauseFor(long millis) { @@ -51,7 +51,7 @@ public class ActionThread { try { threadSleeping = true; if (action.manager.debug) - action.manager.logDebug(String.format("Sleeping thread of Action '%s' on queue '%s' for %s ticks", action.name, action.getQueueName(), millis / 50)); + action.manager.LOGGER.log(String.format("Sleeping thread for %s ticks", millis / 50), action); Thread.sleep(millis); } catch (InterruptedException e) { @@ -60,7 +60,7 @@ public class ActionThread { threadSleeping = false; if (action.manager.debug) - action.manager.logDebug(String.format("Woken up thread of Action '%s' on queue '%s' after sleeping for %s ticks", action.name, action.getQueueName(), millis / 50)); + action.manager.LOGGER.log(String.format("Woken up thread after sleeping for %s ticks", millis / 50), action); } } @@ -77,7 +77,7 @@ public class ActionThread { while (threadPaused) { try { if (action.manager.debug) - action.manager.logDebug(String.format("Pausing thread of Action '%s' on queue '%s'", action.name, action.getQueueName())); + action.manager.LOGGER.log(String.format("Pausing thread"), action); lock.wait(); // Wait until notified } catch (InterruptedException e) { @@ -99,7 +99,7 @@ public class ActionThread { lock.notify(); if (action.manager.debug) - action.manager.logDebug(String.format("Resumed thread of Action '%s' on queue '%s'", action.name, action.getQueueName())); + action.manager.LOGGER.log(String.format("Resumed thread"), action); } if (threadSleeping) diff --git a/src/main/java/noppes/npcs/controllers/data/action/action/ConditionalAction.java b/src/main/java/noppes/npcs/controllers/data/action/action/ConditionalAction.java index bec6b50d0..4b04ece5d 100644 --- a/src/main/java/noppes/npcs/controllers/data/action/action/ConditionalAction.java +++ b/src/main/java/noppes/npcs/controllers/data/action/action/ConditionalAction.java @@ -105,11 +105,11 @@ public class ConditionalAction extends Action implements IConditionalAction { duration++; if (manager.inDebugMode()) - manager.logDebug(String.format("Ticking ConditionalAction '%s' (duration = %s/%s, count = %s/%s, checkCount = %s/%s) on queue '%s'", name, duration, maxDuration, count, maxCount, checkCount, maxChecks, getQueueName())); + manager.LOGGER.log(String.format("Ticking... (duration = %s/%s, count = %s/%s, checkCount = %s/%s)", duration, maxDuration, count, maxCount, checkCount, maxChecks), this); if (maxDuration > -1 && duration >= maxDuration || maxCount == 0) { if (manager.inDebugMode()) - manager.logDebug(String.format("Reached max duration of Action '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Reached max duration", this); markDone(); return; @@ -117,7 +117,7 @@ public class ConditionalAction extends Action implements IConditionalAction { if (maxChecks > -1 && checkCount > maxChecks) { if (manager.inDebugMode()) - manager.logDebug(String.format("Reached max check count of ConditionalAction '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Reached max check count", this); markDone(); return; @@ -142,7 +142,7 @@ public class ConditionalAction extends Action implements IConditionalAction { if (maxCount > -1 && count >= maxCount) { if (manager.inDebugMode()) - manager.logDebug(String.format("Reached max count of ConditionalAction '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Reached max count", this); markDone(); } @@ -150,34 +150,33 @@ public class ConditionalAction extends Action implements IConditionalAction { protected void executeTask() { if (manager.inDebugMode()) - manager.logDebug(String.format("Started executing task of ConditionalAction '%s' on queue '%s'", name, getQueueName())); - + manager.LOGGER.log("Executing task...", this); try { task.accept(this); count++; taskExecuted = true; } catch (Throwable t) { - manager.logDebug("Task of " + this + " threw an exception:", t); + manager.LOGGER.error("Task of " + this + " threw an exception:", t); markDone(); } if (manager.inDebugMode()) - manager.logDebug(String.format("Finished executing task of ConditionalAction '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Finished executing task", this); } protected void executeOnTermination() { if (manager.inDebugMode()) - manager.logDebug(String.format("Started executing onTermination task of ConditionalAction '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Executing onTermination task...", this); try { onTermination.accept(this); } catch (Throwable t) { - manager.logDebug("Termination Task of " + this + " threw an exception:", t); + manager.LOGGER.error("Termination Task of " + this + " threw an exception:", t); } if (manager.inDebugMode()) - manager.logDebug(String.format("Finished executing onTermination task of ConditionalAction '%s' on queue '%s'", name, getQueueName())); + manager.LOGGER.log("Finished executing onTermination task", this); } diff --git a/src/main/java/noppes/npcs/scripted/NpcAPI.java b/src/main/java/noppes/npcs/scripted/NpcAPI.java index 86e237352..34dc85b54 100644 --- a/src/main/java/noppes/npcs/scripted/NpcAPI.java +++ b/src/main/java/noppes/npcs/scripted/NpcAPI.java @@ -570,7 +570,7 @@ public class NpcAPI extends AbstractNpcAPI { public IActionManager getActionManager() { if (actionManager.getName().isEmpty()) - actionManager.setName("Global Action Manager"); + actionManager.setName("Global"); return actionManager; } diff --git a/src/main/java/noppes/npcs/scripted/entity/ScriptNpc.java b/src/main/java/noppes/npcs/scripted/entity/ScriptNpc.java index ab1d21f4e..356d3bf5a 100644 --- a/src/main/java/noppes/npcs/scripted/entity/ScriptNpc.java +++ b/src/main/java/noppes/npcs/scripted/entity/ScriptNpc.java @@ -1409,7 +1409,7 @@ public class ScriptNpc extends ScriptLiving imp public IActionManager getActionManager() { if (npc.actionManager.getName().isEmpty()) - npc.actionManager.setName(String.format("%s's Action Manager", npc.getCommandSenderName())); + npc.actionManager.setName(npc.getCommandSenderName()); return npc.actionManager; } diff --git a/src/main/java/noppes/npcs/scripted/entity/ScriptPlayer.java b/src/main/java/noppes/npcs/scripted/entity/ScriptPlayer.java index d3cf85e61..346a3385a 100644 --- a/src/main/java/noppes/npcs/scripted/entity/ScriptPlayer.java +++ b/src/main/java/noppes/npcs/scripted/entity/ScriptPlayer.java @@ -852,7 +852,7 @@ public class ScriptPlayer extends ScriptLivingBase @Override public IActionManager getActionManager() { if (data.actionManager.getName().isEmpty()) - data.actionManager.setName(String.format("%s's Action Manager", player.getDisplayName())); + data.actionManager.setName(player.getDisplayName()); return data.actionManager; }