update transformer debug logging and colorization

mutatest/__init__.py

@@ -1,6 +1,6 @@
 """Mutation initialization.
 """
-__version__ = "0.4.1"
+__version__ = "0.4.2-dev1"
 
 __title__ = "mutatest"
 __description__ = "Python mutation testing."

mutatest/controller.py

@@ -30,6 +30,24 @@ class ResultsSummary(NamedTuple):
     total_runtime: timedelta
 
 
+def colorize_output(output: str, color: str) -> str:
+    """Color output for the terminal display as either red or green.
+
+    Args:
+        output: string to colorize
+        color: choice of terminal color, "red" vs. "green"
+
+    Returns:
+        colorized string, or original string for bad color choice.
+    """
+    colors = {
+        "red": f"\033[91m{output}\033[0m",  # Red
+        "green": f"\033[92m{output}\033[0m",  # Green
+    }
+
+    return colors.get(color, output)
+
+
 def get_py_files(src_loc: Union[str, Path]) -> List[Path]:
     """Find all .py files in src_loc and return absolute path
 
@@ -116,7 +134,7 @@ def build_src_trees_and_targets(
 
         # Get the locations for all mutatest potential for the given file
         LOGGER.info("Get mutatest targets from AST.")
-        targets = get_mutation_targets(tree)
+        targets = get_mutation_targets(tree, src_file)
 
         # only add files that have at least one valid target for mutatest
         if targets:
@@ -253,19 +271,40 @@ def run_mutation_trials(
             results.append(trial_results)
 
             if trial_results.status == "SURVIVED" and break_on_survival:
-                LOGGER.info("Surviving mutation detected, stopping further mutations for location.")
+                LOGGER.info(
+                    "%s",
+                    colorize_output(
+                        "Surviving mutation detected, stopping further mutations for location.",
+                        "red",
+                    ),
+                )
                 break
 
             if trial_results.status == "DETECTED" and break_on_detected:
-                LOGGER.info("Detected mutation, stopping further mutations for location.")
+                LOGGER.info(
+                    "%s",
+                    colorize_output(
+                        "Detected mutation, stopping further mutations for location.", "green"
+                    ),
+                )
                 break
 
             if trial_results.status == "ERROR" and break_on_error:
-                LOGGER.info("Error on mutation, stopping further mutations for location.")
+                LOGGER.info(
+                    "%s",
+                    colorize_output(
+                        "Error with mutation, stopping further mutations for location.", "red"
+                    ),
+                )
                 break
 
             if trial_results.status == "UNKNOWN" and break_on_unknown:
-                LOGGER.info("Unknown mutation result, stopping further mutations for location.")
+                LOGGER.info(
+                    "%s",
+                    colorize_output(
+                        "Unknown mutation result, stopping further mutations for location.", "red"
+                    ),
+                )
                 break
 
     end = datetime.now()

mutatest/maker.py

@@ -62,16 +62,17 @@ def capture_output(log_level: int) -> bool:
     return log_level != 10
 
 
-def get_mutation_targets(tree: ast.Module) -> Set[LocIndex]:
+def get_mutation_targets(tree: ast.Module, src_file: Path) -> Set[LocIndex]:
     """Run the mutatest AST search with no targets or mutations to bring back target indicies.
 
     Args:
         tree: the source file AST
+        src_file: source file name, used in logging
 
     Returns:
         Set of potential mutatest targets within AST
     """
-    ro_mast = MutateAST(target_idx=None, mutation=None, readonly=True)
+    ro_mast = MutateAST(target_idx=None, mutation=None, readonly=True, src_file=src_file)
     ro_mast.visit(tree)
     return ro_mast.locs
 
@@ -92,7 +93,9 @@ def create_mutant(
     """
 
     # mutate ast and create code binary
-    mutant_ast = MutateAST(target_idx=target_idx, mutation=mutation_op, readonly=False).visit(tree)
+    mutant_ast = MutateAST(
+        target_idx=target_idx, mutation=mutation_op, src_file=src_file, readonly=False
+    ).visit(tree)
 
     mutant_code = compile(mutant_ast, str(src_file), "exec")
 

mutatest/report.py

@@ -7,6 +7,7 @@
 from pathlib import Path
 from typing import Dict, List, NamedTuple, Tuple, Union
 
+from mutatest.controller import colorize_output
 from mutatest.maker import Mutant, MutantTrialResult
 
 
@@ -114,10 +115,10 @@ def analyze_mutant_trials(trial_results: List[MutantTrialResult]) -> Tuple[str,
             report_sections.append(section)
 
             if rpt_results.status == "SURVIVED":
-                display_survived = f"\033[91m{section}\033[0m"  # Red
+                display_survived = colorize_output(section, "red")
 
             if rpt_results.status == "DETECTED":
-                display_detected = f"\033[92m{section}\033[0m"  # Green
+                display_detected = colorize_output(section, "green")
 
     return (
         "\n".join(report_sections),

mutatest/transformers.py

@@ -35,6 +35,7 @@ def __init__(
         target_idx: Optional[LocIndex] = None,
         mutation: Optional[Any] = None,
         readonly: bool = False,
+        src_file: Optional[Union[Path, str]] = None,
     ) -> None:
         """Create the AST node transformer for mutations.
 
@@ -51,15 +52,18 @@ def __init__(
             target_idx: Location index for the mutatest in the AST
             mutation: the mutatest to apply, may be a type or a value
             readonly: flag for read-only operations, used to visit nodes instead of transform
+            src_file: Source file name, used for logging purposes
         """
         self.locs: Set[LocIndex] = set()
         self.target_idx = target_idx
         self.mutation = mutation
         self.readonly = readonly
+        self.src_file = src_file
 
     def visit_AugAssign(self, node: ast.AugAssign) -> ast.AST:
         """AugAssign is -=, +=, /=, *= for augmented assignment."""
         self.generic_visit(node)
+        log_header = f"visit_AugAssign: {self.src_file}:"
 
         # custom mapping of string keys to ast operations that can be used
         # in the nodes since these overlap with BinOp types
@@ -76,14 +80,20 @@ def visit_AugAssign(self, node: ast.AugAssign) -> ast.AST:
         # edge case protection in case the mapping isn't known for substitution
         # in that instance, return the node and take no action
         if not idx_op:
-            LOGGER.debug("visit_AugAssign: unknown aug_assignment: %s", type(node.op))
+            LOGGER.debug(
+                "%s (%s, %s): unknown aug_assignment: %s",
+                log_header,
+                node.lineno,
+                node.col_offset,
+                type(node.op),
+            )
             return node
 
         idx = LocIndex("AugAssign", node.lineno, node.col_offset, idx_op)
         self.locs.add(idx)
 
         if idx == self.target_idx and self.mutation in aug_mappings and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
             return ast.copy_location(
                 ast.AugAssign(
                     target=node.target,
@@ -93,42 +103,45 @@ def visit_AugAssign(self, node: ast.AugAssign) -> ast.AST:
                 node,
             )
 
-        LOGGER.debug("visit_AugAssign: no mutations applied")
+        LOGGER.debug("%s (%s, %s): no mutations applied.", log_header, node.lineno, node.col_offset)
         return node
 
     def visit_BinOp(self, node: ast.BinOp) -> ast.AST:
         """BinOp nodes are bit-shifts and general operators like add, divide, etc."""
         self.generic_visit(node)
+        log_header = f"visit_BinOp: {self.src_file}:"
 
         idx = LocIndex("BinOp", node.lineno, node.col_offset, type(node.op))
         self.locs.add(idx)
 
         if idx == self.target_idx and self.mutation and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
             return ast.copy_location(
                 ast.BinOp(left=node.left, op=self.mutation(), right=node.right), node
             )
 
-        LOGGER.debug("visit_BinOp: no mutations applied")
+        LOGGER.debug("%s (%s, %s): no mutations applied.", log_header, node.lineno, node.col_offset)
         return node
 
     def visit_BoolOp(self, node: ast.BoolOp) -> ast.AST:
         """Boolean operations, AND/OR."""
         self.generic_visit(node)
+        log_header = f"visit_BoolOp: {self.src_file}:"
 
         idx = LocIndex("BoolOp", node.lineno, node.col_offset, type(node.op))
         self.locs.add(idx)
 
         if idx == self.target_idx and self.mutation and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
             return ast.copy_location(ast.BoolOp(op=self.mutation(), values=node.values), node)
 
-        LOGGER.debug("visit_BoolOp: no mutations applied")
+        LOGGER.debug("%s (%s, %s): no mutations applied.", log_header, node.lineno, node.col_offset)
         return node
 
     def visit_Compare(self, node: ast.Compare) -> ast.AST:
         """Compare nodes are ==, >= etc."""
         self.generic_visit(node)
+        log_header = f"visit_Compare: {self.src_file}:"
 
         # taking only the first operation in the compare node
         # in basic testing, things like (a==b)==1 still end up with lists of 1,
@@ -137,12 +150,12 @@ def visit_Compare(self, node: ast.Compare) -> ast.AST:
         self.locs.add(idx)
 
         if idx == self.target_idx and self.mutation and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
 
             # TODO: Determine when/how this case would actually be called
             if len(node.ops) > 1:
                 # unlikely test case where the comparison has multiple values
-                LOGGER.debug("Multiple compare ops in node, len: %s", len(node.ops))
+                LOGGER.debug("%s multiple compare ops in node, len: %s", log_header, len(node.ops))
                 existing_ops = [i for i in node.ops]
                 mutation_ops = [self.mutation()] + existing_ops[1:]
 
@@ -153,11 +166,11 @@ def visit_Compare(self, node: ast.Compare) -> ast.AST:
 
             else:
                 # typical comparison case, will also catch (a==b)==1 as an example.
-                LOGGER.debug("Single comparison node operation")
+                LOGGER.debug("%s single comparison node operation", log_header)
                 new_node = ast.Compare(
                     left=node.left, ops=[self.mutation()], comparators=node.comparators
                 )
-                LOGGER.debug("New node:\n%s", ast.dump(new_node))
+                LOGGER.debug("%s new node:\n%s", log_header, ast.dump(new_node))
 
                 return ast.copy_location(
                     ast.Compare(
@@ -166,12 +179,13 @@ def visit_Compare(self, node: ast.Compare) -> ast.AST:
                     node,
                 )
 
-        LOGGER.debug("visit_Compare: no mutations applied")
+        LOGGER.debug("%s (%s, %s): no mutations applied.", log_header, node.lineno, node.col_offset)
         return node
 
     def visit_Index(self, node: ast.Index) -> ast.AST:
         """Index visit e.g. i[0], i[0][1]."""
         self.generic_visit(node)
+        log_header = f"visit_Index: {self.src_file}:"
 
         # Index Node has a value attribute that can be either Num node or UnaryOp node
         # depending on whether the value is positive or negative.
@@ -202,28 +216,31 @@ def visit_Index(self, node: ast.Index) -> ast.AST:
             self.locs.add(idx)
 
         if idx == self.target_idx and self.mutation and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
             mutation = index_mutations[self.mutation]
 
             # uses AST.fix_missing_locations since the values of ast.Num and  ast.UnaryOp also need
             # lineno and col-offset values. This is a recursive fix.
             return ast.fix_missing_locations(ast.copy_location(ast.Index(value=mutation), node))
 
-        LOGGER.debug("visit_Index: no mutations applied")
+        LOGGER.debug(
+            "%s (%s, %s): no mutations applied.", log_header, n_value.lineno, n_value.col_offset
+        )
         return node
 
     def visit_NameConstant(self, node: ast.NameConstant) -> ast.AST:
         """NameConstants: True/False/None."""
         self.generic_visit(node)
+        log_header = f"visit_NameConstant: {self.src_file}:"
 
         idx = LocIndex("NameConstant", node.lineno, node.col_offset, node.value)
         self.locs.add(idx)
 
         if idx == self.target_idx and not self.readonly:
-            LOGGER.debug("Mutating idx: %s with %s", self.target_idx, self.mutation)
+            LOGGER.debug("%s mutating idx: %s with %s", log_header, self.target_idx, self.mutation)
             return ast.copy_location(ast.NameConstant(value=self.mutation), node)
 
-        LOGGER.debug("visit_NameConstant: no mutations applied")
+        LOGGER.debug("%s (%s, %s): no mutations applied.", log_header, node.lineno, node.col_offset)
         return node
 
 

tests/test_maker.py

@@ -52,7 +52,7 @@ def test_capture_output():
 def test_get_mutation_targets(binop_file, binop_expected_locs):
     """Test mutation target retrieval from the bin_op test fixture."""
     tree = get_ast_from_src(binop_file)
-    targets = get_mutation_targets(tree)
+    targets = get_mutation_targets(tree, binop_file)
 
     assert len(targets) == 4
     assert targets == binop_expected_locs