From cb43a582908cf02c4fd286d76b3036ea6e408d9b Mon Sep 17 00:00:00 2001 From: LevelX2 Date: Tue, 12 Mar 2013 17:31:22 +0100 Subject: [PATCH] Some changes to AI logging. --- .../src/mage/player/ai/ComputerPlayer6.java | 81 ++++++++++++------- .../src/mage/player/ai/ComputerPlayer7.java | 57 ++++++++----- 2 files changed, 89 insertions(+), 49 deletions(-) diff --git a/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer6.java b/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer6.java index acf96a5a9c9..3df928d7bef 100644 --- a/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer6.java +++ b/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer6.java @@ -219,7 +219,7 @@ public class ComputerPlayer6 extends ComputerPlayer implements boolean usedStack = false; while (actions.peek() != null) { Ability ability = actions.poll(); - logger.info(new StringBuilder("[").append(game.getPlayer(playerId).getName()).append("] Action: ").append(ability.toString()).toString()); + logger.info(new StringBuilder("Act -------------> [").append(game.getPlayer(playerId).getName()).append("] Action: ").append(ability.toString()).toString()); if (ability.getTargets().size() > 0) { for (Target target : ability.getTargets()) { for (UUID id : target.getTargets()) { @@ -318,6 +318,7 @@ public class ComputerPlayer6 extends ComputerPlayer implements } protected int minimaxAB(SimulationNode2 node, int depth, int alpha, int beta) { + logger.info("Simulating minimaxAB -- alpha: " + alpha + " beta: " + beta + " depth:" + depth + " node-score: " + (node != null ? node.getScore() : "null")); UUID currentPlayerId = node.getGame().getPlayerList().get(); SimulationNode2 bestChild = null; for (SimulationNode2 child : node.getChildren()) { @@ -412,6 +413,11 @@ public class ComputerPlayer6 extends ComputerPlayer implements game.getPlayerList().setCurrent(game.getActivePlayerId()); } + /** + * Base call for simulation of AI actions + * + * @return + */ protected Integer addActionsTimed() { FutureTask task = new FutureTask(new Callable() { @@ -442,7 +448,9 @@ public class ComputerPlayer6 extends ComputerPlayer implements } protected int addActions(SimulationNode2 node, int depth, int alpha, int beta) { - logger.debug("addActions: " + depth + ", alpha=" + alpha + ", beta=" + beta); + if (logger.isInfoEnabled() && node !=null && node.getAbilities() != null && !node.getAbilities().toString().equals("[Pass]")){ + logger.info("Add actions [" + depth +"] " + (node.getAbilities().toString()+ " -- a: " + alpha + " b: " + beta)); + } Game game = node.getGame(); int val; if (Thread.interrupted()) { @@ -452,17 +460,17 @@ public class ComputerPlayer6 extends ComputerPlayer implements return val; } if (depth <= 0 || SimulationNode2.nodeCount > maxNodes || game.isGameOver()) { - logger.trace("Simulating -- reached end state, node count=" + SimulationNode2.nodeCount + ", depth=" + depth); + logger.trace("Add actions -- reached end state, node count=" + SimulationNode2.nodeCount + ", depth=" + depth); val = GameStateEvaluator2.evaluate(playerId, game); UUID currentPlayerId = node.getGame().getPlayerList().get(); //logger.info("reached - " + val + ", playerId=" + playerId + ", node.pid="+currentPlayerId); return val; } else if (node.getChildren().size() > 0) { - logger.trace("Simulating -- something added children:" + node.getChildren().size()); + logger.trace("Add actions -- something added children:" + node.getChildren().size()); val = minimaxAB(node, depth - 1, alpha, beta); return val; } else { - logger.trace("Simulating -- alpha: " + alpha + " beta: " + beta + " depth:" + depth + " step:" + game.getTurn().getStepType() + " for player:" + (node.getPlayerId().equals(playerId) ? "yes" : "no")); + logger.trace("Add actions -- alpha: " + alpha + " beta: " + beta + " depth:" + depth + " step:" + game.getTurn().getStepType() + " for player:" + (node.getPlayerId().equals(playerId) ? "yes" : "no")); if (allPassed(game)) { if (!game.getStack().isEmpty()) { resolve(node, depth, game); @@ -476,7 +484,7 @@ public class ComputerPlayer6 extends ComputerPlayer implements val = GameStateEvaluator2.evaluate(playerId, game); } else if (node.getChildren().size() > 0) { //declared attackers or blockers or triggered abilities - logger.debug("simulating -- attack/block/trigger added children:" + node.getChildren().size()); + logger.debug("Add actions -- attack/block/trigger added children:" + node.getChildren().size()); val = minimaxAB(node, depth - 1, alpha, beta); } else { val = simulatePriority(node, game, depth, alpha, beta); @@ -496,23 +504,26 @@ public class ComputerPlayer6 extends ComputerPlayer implements } node.setGameValue(game.getState().getValue(true).hashCode()); SimulatedPlayer2 currentPlayer = (SimulatedPlayer2) game.getPlayer(game.getPlayerList().get()); - //logger.info("simulating -- player " + currentPlayer.getName()); + //logger.info("Sim Prio -- player " + currentPlayer.getName()); SimulationNode2 bestNode = null; List allActions = currentPlayer.simulatePriority(game); optimize(game, allActions); - logger.debug("Simulating -- (depth=" + depth + ") adding " + allActions.size() + " children:" + allActions); + if (logger.isInfoEnabled() && allActions.size() > 0 && depth == maxDepth) { + logger.info("Sim Prio [" + depth + "] player " + currentPlayer.getName() + " adding " + allActions.size() + " actions:" + allActions); + } int counter = 0; for (Ability action : allActions) { - logger.debug(new StringBuilder("Simulating -- actions: [" + ++counter + "] " + " -> " + action)); + counter++; if (Thread.interrupted()) { Thread.currentThread().interrupt(); - logger.debug("Simulating -- interrupted"); + logger.info("Sim Prio [" + depth + "] -- interrupted"); break; } Game sim = game.copy(); if (sim.getPlayer(currentPlayer.getId()).activateAbility((ActivatedAbility) action.copy(), sim)) { sim.applyEffects(); if (checkForRepeatedAction(sim, node, action, currentPlayer.getId())) { + logger.info("Sim Prio [" + depth + "] -- repeated action: " + action.toString()); continue; } if (!sim.isGameOver() && action.isUsesStack()) { @@ -525,7 +536,19 @@ public class ComputerPlayer6 extends ComputerPlayer implements sim.checkStateAndTriggered(); int val = addActions(newNode, depth - 1, alpha, beta); - logger.debug("Simulating -- val = " + val + " depth= " + depth + " (" + action +")"); + + if (logger.isInfoEnabled() && depth == maxDepth) { + StringBuilder sb = new StringBuilder("Sim Prio [").append(depth).append("] #").append(counter).append(" -- val = ").append(val).append(" (").append(action).append(")"); + SimulationNode2 logNode = newNode; + while (logNode.getChildren() != null && logNode.getChildren().size()>0) { + logNode = logNode.getChildren().get(0); + if (logNode.getAbilities() != null && logNode.getAbilities().size()>0) { + sb.append(" --> ").append(logNode.getAbilities().get(0).toString()); + } + } + logger.info(sb.toString()); + } + if (!currentPlayer.getId().equals(playerId)) { if (val < beta) { beta = val; @@ -538,7 +561,7 @@ public class ComputerPlayer6 extends ComputerPlayer implements // no need to check other actions if (val == GameStateEvaluator2.LOSE_GAME_SCORE) { - logger.debug("Simulating -- lose - break"); + logger.debug("Sim Prio -- lose - break"); break; } } else { @@ -555,7 +578,7 @@ public class ComputerPlayer6 extends ComputerPlayer implements * choices = node.getChoices(); */ if (depth == maxDepth) { - logger.info(new StringBuilder("Simulating -- Saved (depth=").append(depth).append(") Score: ").append(bestNode.getScore()).append(" abilities: ").append(bestNode.getAbilities().toString()).toString()); + logger.info(new StringBuilder("Sim Prio [").append(depth).append("] -- Saved best node yet with score: ").append(bestNode.getScore()).append(" abilities: ").append(bestNode.getAbilities().toString()).toString()); node.children.clear(); node.children.add(bestNode); node.setScore(bestNode.getScore()); @@ -564,35 +587,33 @@ public class ComputerPlayer6 extends ComputerPlayer implements // no need to check other actions if (val == GameStateEvaluator2.WIN_GAME_SCORE) { - logger.debug("Simulating -- win - break"); + logger.debug("Sim Prio -- win - break"); break; } } if (alpha >= beta) { - //logger.info("simulating -- pruning"); + //logger.info("Sim Prio -- pruning"); break; } if (SimulationNode2.nodeCount > maxNodes) { - logger.debug("Simulating -- reached end-state"); + logger.debug("Sim Prio -- reached end-state"); break; } } + } // end for allActions + if (depth == maxDepth) { + logger.info(new StringBuilder("Sim Prio [").append(depth).append("] -- End for Max Depth").toString()); } if (bestNode != null) { node.children.clear(); node.children.add(bestNode); node.setScore(bestNode.getScore()); + if (logger.isTraceEnabled() && !bestNode.getAbilities().toString().equals("[Pass]") ) { + logger.trace(new StringBuilder("Sim Prio [").append(depth).append("] -- Set after (depth=").append(depth).append(") Score: ").append(bestNode.getScore()).append(" abilities: ").append(bestNode.getAbilities().toString()).toString()); + } } - if (!currentPlayer.getId().equals(playerId)) { - /* - * if (beta == Integer.MAX_VALUE) { int val = - * GameStateEvaluator2.evaluate(playerId, game); - * logger.info("returning priority beta: " + val); return val; - } - */ - //logger.info("returning priority beta: " + beta); - return beta; - } else { + + if (currentPlayer.getId().equals(playerId)) { /* * if (alpha == Integer.MIN_VALUE) { int val = * GameStateEvaluator2.evaluate(playerId, game); @@ -601,6 +622,13 @@ public class ComputerPlayer6 extends ComputerPlayer implements */ //logger.info("returning priority alpha: " + alpha); return alpha; + } else { +// if (beta == Integer.MAX_VALUE) { +// int val = GameStateEvaluator2.evaluate(playerId, game); +// logger.info("returning priority beta: " + val); +// return val; +// } + return beta; } } @@ -1258,7 +1286,6 @@ public class ComputerPlayer6 extends ComputerPlayer implements */ protected Game createSimulation(Game game) { Game sim = game.copy(); - for (Player copyPlayer : sim.getState().getPlayers().values()) { Player origPlayer = game.getState().getPlayers().get(copyPlayer.getId()).copy(); logger.debug(origPlayer.getName() + " suggested: " + suggested); diff --git a/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer7.java b/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer7.java index 45b8f669ee7..317f9a43998 100644 --- a/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer7.java +++ b/Mage.Server.Plugins/Mage.Player.AI.MA/src/mage/player/ai/ComputerPlayer7.java @@ -137,21 +137,22 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { currentScore = GameStateEvaluator2.evaluate(playerId, game); Game sim = createSimulation(game); SimulationNode2.resetCount(); + logger.info("Sim Calculate pre combat actions -----------------------------------------------------------------------------------------"); root = new SimulationNode2(null, sim, maxDepth, playerId); - logger.debug("simulating pre combat actions -----------------------------------------------------------------------------------------"); - + addActionsTimed(); + logger.trace("After add actions timed: root.children.size = " + root.children.size()); if (root.children.size() > 0) { root = root.children.get(0); - int bestScore = root.getScore(); - //if (bestScore > currentScore || allowBadMoves) { + // int bestScore = root.getScore(); + // if (bestScore > currentScore || allowBadMoves) { actions = new LinkedList(root.abilities); combat = root.combat; for (Ability ability : actions) { actionCache.add(ability.getRule() + "_" + ability.getSourceId()); } } else { - logger.debug("[" + game.getPlayer(playerId).getName() + "][pre] Action: skip"); + logger.info("[" + game.getPlayer(playerId).getName() + "][pre] Action: skip"); } } } @@ -162,7 +163,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { Game sim = createSimulation(game); SimulationNode2.resetCount(); root = new SimulationNode2(null, sim, maxDepth, playerId); - logger.debug("simulating post combat actions ----------------------------------------------------------------------------------------"); + logger.debug("Sim Calculate post combat actions ----------------------------------------------------------------------------------------"); addActionsTimed(); if (root.children.size() > 0) { @@ -185,22 +186,34 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { protected int addActions(SimulationNode2 node, int depth, int alpha, int beta) { boolean stepFinished = false; int val; + if (logger.isTraceEnabled() && node !=null && node.getAbilities() != null && !node.getAbilities().toString().equals("[Pass]")){ + logger.trace("Add Action [" + depth + "] " + node.getAbilities().toString() + " a: " + alpha + " b: " + beta); + } Game game = node.getGame(); if (Thread.interrupted()) { Thread.currentThread().interrupt(); logger.debug("interrupted"); return GameStateEvaluator2.evaluate(playerId, game); } - if (depth <= 0 || SimulationNode2.nodeCount > maxNodes || game.isGameOver()) { - logger.debug("Simulating -- reached end state"); + if (depth <= 0 || SimulationNode2.nodeCount > maxNodes || game.isGameOver()) { val = GameStateEvaluator2.evaluate(playerId, game); + if (logger.isDebugEnabled()) { + StringBuilder sb = new StringBuilder("Add Action [").append(depth).append("] -- reached end state val = ").append(val); + SimulationNode2 logNode = node; + StringBuilder sb2 = new StringBuilder(" --> ").append(node.getAbilities().get(0).toString()); + while(logNode.getParent() != null) { + logNode = logNode.getParent(); + sb2.insert(0,"["+node.getDepth()+"] s:" + logNode.score).insert(0," (0/"+node.getAbilities().size()+" " + node.getAbilities().get(0).toString()).insert(0, ") --> "); + } + logger.debug(sb.append(sb2)); + } } else if (node.getChildren().size() > 0) { - logger.debug("Simulating -- something added children:" + node.getChildren().size()); + logger.debug("Add Action -- something added children:" + node.getChildren().size()); val = minimaxAB(node, depth-1, alpha, beta); } else { - logger.trace("Simulating -- alpha: " + alpha + " beta: " + beta + " depth:" + depth + " step:" + game.getTurn().getStepType() + " for player:" + game.getPlayer(game.getPlayerList().get()).getName()); + logger.trace("Add Action -- alpha: " + alpha + " beta: " + beta + " depth:" + depth + " step:" + game.getTurn().getStepType() + " for player:" + game.getPlayer(game.getPlayerList().get()).getName()); if (allPassed(game)) { if (!game.getStack().isEmpty()) { resolve(node, depth, game); @@ -219,7 +232,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { if (game.getActivePlayerId().equals(playerId)) { if (testScore < currentScore) { // if score at end of step is worse than original score don't check further - //logger.debug("simulating -- abandoning check, no immediate benefit"); + //logger.debug("Add Action -- abandoning check, no immediate benefit"); val = testScore; } else { @@ -247,7 +260,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { } } else if (node.getChildren().size() > 0) { - logger.debug("Simulating -- trigger added children:" + node.getChildren().size()); + logger.debug("Add Action -- trigger added children:" + node.getChildren().size()); val = minimaxAB(node, depth, alpha, beta); } else { @@ -319,10 +332,10 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { logger.debug(attacker.getName() + "'s possible attackers: " + attacker.getAvailableAttackers(game)); for (Combat engagement: attacker.addAttackers(game)) { if (logger.isDebugEnabled()) { - logger.debug("Attackers: " + engagement.getAttackers() + ", blockers: " + engagement.getBlockers()); + logger.debug("Sim Attackers: " + engagement.getAttackers() + ", blockers: " + engagement.getBlockers()); } if (alpha >= beta) { - logger.debug("simulating -- pruning attackers"); + logger.debug("Sim Attackers -- pruning attackers"); break; } Game sim = game.copy(); @@ -335,11 +348,11 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { sim.fireEvent(GameEvent.getEvent(GameEvent.EventType.DECLARED_ATTACKERS, attackerId, attackerId)); SimulationNode2 newNode = new SimulationNode2(node, sim, depth, attackerId); if (logger.isDebugEnabled()) - logger.debug("simulating attack for player:" + game.getPlayer(attackerId).getName()); + logger.debug("Sim attack for player:" + game.getPlayer(attackerId).getName()); sim.checkStateAndTriggered(); while (!sim.getStack().isEmpty()) { sim.getStack().resolve(sim); - logger.debug("resolving triggered abilities"); + logger.debug("Sim attack: resolving triggered abilities"); sim.applyEffects(); } sim.fireEvent(GameEvent.getEvent(GameEvent.EventType.DECLARE_ATTACKERS_STEP_POST, sim.getActivePlayerId(), sim.getActivePlayerId())); @@ -375,7 +388,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { node.setScore(bestNode.getScore()); } if (logger.isDebugEnabled()) - logger.debug("returning -- combat attacker score: " + val + " depth:" + depth + " for player:" + game.getPlayer(node.getPlayerId()).getName()); + logger.debug("Sim attackers: returning score: " + val + " depth:" + depth + " for player:" + game.getPlayer(node.getPlayerId()).getName()); return val; } @@ -395,7 +408,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { List combats = defender.addBlockers(game); for (Combat engagement: combats) { if (alpha >= beta) { - logger.debug("simulating -- pruning blockers"); + logger.debug("Sim blockers -- pruning blockers"); break; } Game sim = game.copy(); @@ -410,11 +423,11 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { sim.fireEvent(GameEvent.getEvent(GameEvent.EventType.DECLARED_BLOCKERS, defenderId, defenderId)); SimulationNode2 newNode = new SimulationNode2(node, sim, depth, defenderId); if (logger.isDebugEnabled()) - logger.debug("simulating block for player:" + game.getPlayer(defenderId).getName()); + logger.debug("Sim block for player:" + game.getPlayer(defenderId).getName()); sim.checkStateAndTriggered(); while (!sim.getStack().isEmpty()) { sim.getStack().resolve(sim); - logger.debug("resolving triggered abilities"); + logger.debug("Sim blockers: resolving triggered abilities"); sim.applyEffects(); } sim.fireEvent(GameEvent.getEvent(GameEvent.EventType.DECLARE_BLOCKERS_STEP_POST, sim.getActivePlayerId(), sim.getActivePlayerId())); @@ -454,7 +467,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { node.setScore(bestNode.getScore()); } if (logger.isDebugEnabled()) - logger.debug("returning -- combat blocker score: " + val + " depth:" + depth + " for player:" + game.getPlayer(node.getPlayerId()).getName()); + logger.debug("Sim blockers: returning score: " + val + " depth:" + depth + " for player:" + game.getPlayer(node.getPlayerId()).getName()); return val; } @@ -522,7 +535,7 @@ public class ComputerPlayer7 extends ComputerPlayer6 implements Player { logger.debug("interrupted"); return GameStateEvaluator2.evaluate(playerId, game); } - logger.debug("simulating -- post combat main"); + logger.debug("Sim [" + depth + "] -- post combat main"); game.getTurn().setPhase(new PostCombatMainPhase()); if (game.getPhase().beginPhase(game, game.getActivePlayerId())) { game.getPhase().setStep(new PostCombatMainStep());