More ActionLogger and ActionThread optimisations

src/main/java/noppes/npcs/controllers/data/action/Action.java

@@ -368,6 +368,9 @@ public class Action implements IAction {
 
     @Override
     public void kill() {
+        if (manager.debug)
+            manager.LOGGER.log(String.format("Killing Action '%s'...", name), queue);
+
         if (actionThread != null)
             actionThread.stop();
 
@@ -375,8 +378,6 @@ public class Action implements IAction {
         isScheduled = false;
         done = true;
 
-        if (manager.debug)
-            manager.LOGGER.log(String.format("Killed Action '%s'", name), queue);
     }
 
     public String toString() {

src/main/java/noppes/npcs/controllers/data/action/ActionLogger.java

@@ -93,17 +93,14 @@ public class ActionLogger {
         ListIterator<TreeNode> it = new ArrayList<>(stack).listIterator(stack.size());
 
         while (it.hasPrevious()) {
-            TreeNode node = it.previous();
-            if (it.hasPrevious()) {
+            if (it.hasPrevious())
                 prefix.append("│    ");
-            } else {
+            else
                 prefix.append(isLast ? "└──── " : "├──── ");
-            }
         }
 
         String header = getLogHeader(source);
-        LogWriter.info(prefix + header + message);
-
+        println(prefix + header + message);
         return this;
     }
 
@@ -126,11 +123,20 @@ public class ActionLogger {
             name = ((IActionQueue) obj).getName();
         } else if (obj instanceof IAction) {
             name = ((IAction) obj).getName();
+        } else if (obj instanceof ActionThread) {
+            name = ((ActionThread) obj).getAction().getName();
         }
 
         return String.format("[%s/'%s'] ", type, name);
     }
 
+    private static final String ANSI_CYAN = "\u001B[96m";
+    private static final String ANSI_GOLD = "\u001B[93m";
+    private static final String ANSI_RESET = "\u001B[0m";
+
+    public void println(String str) {
+        System.out.printf("[%tT] %s[%s]:%s %s%s%n", new Date(), ANSI_CYAN, Thread.currentThread().getName(), ANSI_GOLD, str, ANSI_RESET);
+    }
 
     //    public ActionLogger beginTick1(ActionManager manager) {
     //        snapshot.clear();

src/main/java/noppes/npcs/controllers/data/action/ActionManager.java

@@ -66,6 +66,9 @@ public class ActionManager implements IActionManager {
     @Override
     public IActionManager setDebugMode(boolean debug) {
         this.debug = debug;
+
+        if (debug)
+            LOGGER.log("Enabled debug mode", this);
         return this;
     }
 

src/main/java/noppes/npcs/controllers/data/action/ActionQueue.java

@@ -261,18 +261,7 @@ 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();
-
+    public boolean finish(Action a) {
         if (a.isDone()) {
             if (a.onDone != null)
                 a.execute("done", a::executeOnDone);
@@ -286,6 +275,21 @@ public class ActionQueue implements IActionQueue {
 
         return false;
     }
+    protected boolean tick(Action a) {
+        if (a == null)
+            return false;
+
+        boolean wasDone = a.isDone();
+        if (manager.debug && !wasDone)
+            manager.LOGGER.push(this).log(String.format("Started ticking Action '%s' ", a.name), this).push(a);
+
+        a.tick();
+
+        if (manager.debug && !wasDone)
+            manager.LOGGER.pop().finish(String.format("Finished ticking Action '%s' ", a.name), this).pop();
+
+        return finish(a);
+    }
 
     protected void tick() {
         if (!isWorking || isDead)

src/main/java/noppes/npcs/controllers/data/action/ActionThread.java

@@ -29,6 +29,9 @@ public class ActionThread {
             thread.setName(String.format("ActionThread (%s)", action.getName()));
             return thread;
         });
+
+        if (action.manager.debug)
+            action.manager.LOGGER.log("Created Action thread!", this);
     }
 
     public void stop() {
@@ -41,7 +44,11 @@ public class ActionThread {
 
 
         if (action.manager.debug)
-            action.manager.LOGGER.log("Stopping thread", action);
+            action.manager.LOGGER.log("Stopping thread", this);
+    }
+
+    public Action getAction() {
+        return action;
     }
 
     public void pauseFor(long millis) {
@@ -51,7 +58,7 @@ public class ActionThread {
         try {
             threadSleeping = true;
             if (action.manager.debug)
-                action.manager.LOGGER.log(String.format("Sleeping thread for %s ticks", millis / 50), action);
+                action.manager.LOGGER.log(String.format("Sleeping thread for %s ticks", millis / 50), this);
 
             Thread.sleep(millis);
         } catch (InterruptedException e) {
@@ -60,7 +67,7 @@ public class ActionThread {
             threadSleeping = false;
 
             if (action.manager.debug)
-                action.manager.LOGGER.log(String.format("Woken up thread after sleeping for %s ticks", millis / 50), action);
+                action.manager.LOGGER.log(String.format("Woken up thread after sleeping for %s ticks", millis / 50), this);
         }
     }
 
@@ -77,7 +84,7 @@ public class ActionThread {
             while (threadPaused) {
                 try {
                     if (action.manager.debug)
-                        action.manager.LOGGER.log(String.format("Pausing thread"), action);
+                        action.manager.LOGGER.log(String.format("Pausing thread"), this);
 
                     lock.wait(); // Wait until notified
                 } catch (InterruptedException e) {
@@ -99,7 +106,7 @@ public class ActionThread {
                 lock.notify();
 
                 if (action.manager.debug)
-                    action.manager.LOGGER.log(String.format("Resumed thread"), action);
+                    action.manager.LOGGER.log(String.format("Resumed thread"), this);
             }
 
             if (threadSleeping)
@@ -130,14 +137,27 @@ public class ActionThread {
         if (!runningKeys.add(taskKey))
             return;
 
+        if (action.manager.debug)
+            action.manager.LOGGER.log(String.format("Delegating task '%s' to Action thread...", taskKey), action);
+
         final AtomicReference<Future<?>> taskRef = new AtomicReference<>();
         taskRef.set(executor.submit(() -> {
+            if (action.manager.debug)
+                action.manager.LOGGER.log(String.format("Started executing task '%s' on Action thread...", taskKey), this);
+
             runningTasks.add(taskRef.get());
             try {
                 task.run();
             } finally {
                 runningTasks.remove(taskRef.get());
                 runningKeys.remove(taskKey);
+
+                if (action.manager.debug)
+                    action.manager.LOGGER.log(String.format("Finished executing task '%s' on Action thread", taskKey), this);
+
+                if (((ActionQueue) action.queue).finish(action))
+                    action.queue.getQueue().remove(action);
+
             }
         }));
     }