remove logging and cleanup more

pyt/base_cfg.py

@@ -5,8 +5,6 @@
 from .label_visitor import LabelVisitor
 from .right_hand_side_visitor import RHSVisitor
 from .vars_visitor import VarsVisitor
-from pyt.utils.log import enable_logger, logger
-enable_logger(to_file='./pyt.log')
 
 
 ControlFlowNode = namedtuple('ControlFlowNode',
@@ -327,23 +325,15 @@ def stmt_star_handler(self, stmts, use_prev_node=True):
                 cfg_statements.append(node)
 
         self.use_prev_node.pop()
-        logger.debug("[Flux] BEFORE So cfg_statements are %s", cfg_statements)
         self.connect_nodes(cfg_statements)
-        logger.debug("[Flux] AFTER So cfg_statements are %s", cfg_statements)
 
         if cfg_statements:
             if first_node:
                 first_statement = first_node
             else:
                 first_statement = self.get_first_statement(cfg_statements[0])
-            logger.debug("[zzz] cfg_statements[0] is %s", cfg_statements[0])
-            logger.debug("[zzz] self.get_first_statement(cfg_statements[0]) is %s", self.get_first_statement(cfg_statements[0]))
-            logger.debug("[zzz] type(self.get_first_statement(cfg_statements[0])) is %s", type(self.get_first_statement(cfg_statements[0])))
-            logger.debug("[Kaffe1668] first_statement is %s", first_statement)
-            logger.debug("[Kaffe1668] Whereas self.get_first_statement(cfg_statements[0]) is %s", self.get_first_statement(cfg_statements[0]))
 
             last_statements = self.get_last_statements(cfg_statements)
-            logger.debug("[zzz] last_statements is %s", last_statements)
             return ConnectStatements(first_statement=first_statement, last_statements=last_statements, break_statements=break_nodes)
         else: # When body of module only contains ignored nodes
             return IgnoredNode()
@@ -371,16 +361,7 @@ def handle_or_else(self, orelse, test):
             test.connect(control_flow_node.test)
             return control_flow_node.last_nodes
         else:
-            logger.debug("[Integral] type(orelse[0]) is %s", type(orelse[0]))
-            label_visitor = LabelVisitor()
-            label_visitor.visit(orelse[0])
-            logger.debug("[Integral] result of orelse[0] is %s", label_visitor.result)
-            logger.debug("[Integral][Flux] type(test) is %s", type(test))
-            logger.debug("[Integral][Flux] result of test is %s", test)
-
             else_connect_statements = self.stmt_star_handler(orelse, use_prev_node=False)
-            logger.debug("[foo] test is %s", test)
-            logger.debug("[foo] else_connect_statements.first_statement is %s", else_connect_statements.first_statement)
             test.connect(else_connect_statements.first_statement)
             return else_connect_statements.last_statements
 
@@ -432,18 +413,6 @@ def handle_stmt_star_ignore_node(self, body, fallback_cfg_node):
 
     def visit_Try(self, node):
         try_node = self.append_node(Node('Try', node, line_number=node.lineno, path=self.filenames[-1]))
-        # logger.debug("[Integral] visit_Try node.body[0] is %s", node.body[0])
-        # label_visitor = LabelVisitor()
-        # label_visitor.visit(node.body[0])
-        # logger.debug("[Integral] result of node.body[0] is %s", label_visitor.result)
-        # logger.debug("[Integral] visit_Try node.orelse[0] is %s", node.orelse[0])
-        # label_visitor = LabelVisitor()
-        # label_visitor.visit(node.orelse[0])
-        # logger.debug("[Integral] result of node.orelse[0] is %s", label_visitor.result)
-        # logger.debug("[Integral] visit_Try node.handlers[0] is %s", node.handlers[0])
-        # label_visitor = LabelVisitor()
-        # label_visitor.visit(node.handlers[0])
-        # logger.debug("[Integral] result of node.handlers[0] is %s", label_visitor.result)
         body = self.stmt_star_handler(node.body)
         body = self.handle_stmt_star_ignore_node(body, try_node)
 
@@ -461,23 +430,7 @@ def visit_Try(self, node):
             last_statements.extend(handler_body.last_statements)
 
         if node.orelse:
-            logger.debug("body.last_statements are %s", body.last_statements)
             orelse_last_nodes = self.handle_or_else(node.orelse, body.last_statements[-1])
-            logger.debug("orelse_last_nodes is %s", orelse_last_nodes)
-            logger.debug("type of orelse_last_nodes is %s", type(orelse_last_nodes))
-            # Perhaps
-            # for last in body.last_statements:
-            #     logger.debug("[ghi] last is %s", last)
-            #     logger.debug("[ghi] type(last) is %s", type(last))
-            #     logger.debug("[ghi] node.orelse[0] is %s", node.orelse[0])
-            #     logger.debug("[ghi] type(node.orelse[0]) is %s", type(node.orelse[0]))
-            #     last.connect(node.orelse[0])
-            # HERE
-            # HERE
-            # HERE
-            # Does that included return nodes? I hope not.
-            # Does the return type of self.handle_or_else even have a .first_statement attribute?
-
             body.last_statements.extend(orelse_last_nodes)
 
         if node.finalbody:
@@ -491,7 +444,6 @@ def visit_Try(self, node):
             body.last_statements.extend(finalbody.last_statements)
 
         last_statements.extend(self.remove_breaks(body.last_statements))
-        logger.debug("Enough is enough, self.nodes are %s", self.nodes)
 
         return ControlFlowNode(try_node, last_statements, break_statements=body.break_statements)
 
@@ -605,12 +557,8 @@ def assignment_call_node(self, left_hand_label, ast_node):
         else: #  assignment to builtin
             call_label = call.label
             rhs_visitor = RHSVisitor()
-            logger.debug("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\nBEGIN ANALYZING THE IMPORTANT NODE")
-            logger.debug("type(ast_node) is %s", ast_node)
-            logger.debug("type(ast_node.value) is %s", ast_node.value)
             rhs_visitor.visit(ast_node.value)
 
-            logger.debug("rhs_visitor.result is %s", rhs_visitor.result)
             # Necessary to know `image_name = image_name.replace('..', '')` is a reassignment.
             vars_visitor = VarsVisitor()
             vars_visitor.visit(ast_node.value)

pyt/interprocedural_cfg.py

@@ -31,8 +31,7 @@
 )
 from .project_handler import get_directory_modules
 from .right_hand_side_visitor import RHSVisitor
-from pyt.utils.log import enable_logger, logger
-enable_logger(to_file='./pyt.log')
+
 
 SavedVariable = namedtuple('SavedVariable', 'LHS RHS')
 NOT_A_BLACKBOX = set(['Flask',
@@ -236,27 +235,17 @@ def save_local_scope(self, line_number, original_previous_node):
             saved_variables_so_far.add(assignment.left_hand_side)
             save_name = 'save_' + str(self.function_index) + '_' +\
                         assignment.left_hand_side
-            logger.debug("previous_node is")
             previous_node = self.nodes[-1]
-            logger.debug(previous_node)
 
             r = RestoreNode(save_name + ' = ' + assignment.left_hand_side,
                             save_name, [assignment.left_hand_side],
                             line_number=line_number, path=self.filenames[-1])
             saved_scope_node = self.append_node(r)
-            logger.debug("saved_scope_node is %s", saved_scope_node)
             saved_variables.append(SavedVariable(LHS=save_name,
                                                  RHS=assignment.left_hand_side))
-            logger.debug("[Flux]self.use_prev_node is %s", self.use_prev_node)
 
             if self.use_prev_node[-1] or previous_node is not original_previous_node:
                 previous_node.connect(saved_scope_node)
-                logger.debug("[Flux]Connecting")
-            else:
-                logger.debug("original previous node is %s", original_previous_node)
-                logger.debug("[Flux]Not connecting")
-                # try_orelse hits here.
-                # raise
 
         return saved_variables
 
@@ -276,14 +265,8 @@ def save_actual_parameters_in_temp(self, args, arguments, line_number, original_
                                        rhs_visitor.result,
                                        line_number=line_number,
                                        path=self.filenames[-1])
-            logger.debug("[Flux] KILL self.nodes[-1] is %s", self.nodes[-1])
             if self.use_prev_node[-1] or self.nodes[-1] is not original_previous_node:
                 self.nodes[-1].connect(restore_node)
-                logger.debug("[2Flux]Connecting")
-            else:
-                logger.debug("[2Flux]Not connecting")
-                # example/example_inputs/try_orelse_with_no_variables_to_save.py
-                # raise
 
             self.nodes.append(restore_node)
 
@@ -335,8 +318,6 @@ def restore_saved_local_scope(self, saved_variables, parameters,
             n.connect(successor)
 
         if restore_nodes:
-            logger.debug("[Flux]A5 self.nodes[-1] is %s", self.nodes[-1])
-            logger.debug("[Flux]A5 restore_nodes are %s", restore_nodes)
             self.nodes[-1].connect(restore_nodes[0])
             self.nodes.extend(restore_nodes)
 
@@ -396,12 +377,7 @@ def get_function_nodes(self, definition, original_previous_node):
                                                       definition.name))
         if self.use_prev_node[-1] or previous_node is not original_previous_node:
             previous_node.connect(entry_node)
-            logger.debug("[3Flux]Connecting")
-        else:
-            logger.debug("[3Flux]Not connecting")
-            logger.debug("[3Flux]original_previous_node is %s", original_previous_node)
-            # example/example_inputs/try_orelse_with_no_variables_to_save_and_no_args.py
-            # raise
+
         function_body_connect_statements = self.stmt_star_handler(definition.node.body)
 
         entry_node.connect(function_body_connect_statements.first_statement)

pyt/reaching_definitions_taint.py

@@ -14,9 +14,6 @@ def fixpointmethod(self, cfg_node):
 
             # vv_result is necessary to know `image_name = image_name.replace('..', '')` is a reassignment.
             if cfg_node.vv_result:
-                for var in cfg_node.right_hand_side_variables:
-                    if var not in cfg_node.vv_result:
-                        raise
                 if cfg_node.left_hand_side not in cfg_node.vv_result:
                     # Get previous assignments of cfg_node.left_hand_side and remove them from JOIN
                     arrow_result = self.arrow(JOIN, cfg_node.left_hand_side)

pyt/vulnerabilities.py

@@ -15,8 +15,6 @@
     Vulnerability,
     VulnerabilityLog
 )
-from pyt.utils.log import enable_logger, logger
-enable_logger(to_file='./pyt.log')
 
 
 Sanitiser = namedtuple('Sanitiser', 'trigger_word cfg_node')
@@ -69,13 +67,6 @@ def identify_triggers(cfg, sources, sinks, lattice):
                                          node) for node in tainted_nodes]
     sources_in_file = find_triggers(assignment_nodes, sources)
     sources_in_file.extend(tainted_trigger_nodes)
-    logger.debug("sources[0] are %s", sources[0])
-    logger.debug("type(sources[0]) are %s", type(sources[0]))
-    try:
-        logger.debug("assignment_nodes[0] are %s", assignment_nodes[0])
-        logger.debug("type(assignment_nodes[0]) are %s", type(assignment_nodes[0]))
-    except Exception:
-        pass
 
     find_secondary_sources(assignment_nodes, sources_in_file, lattice)
 
@@ -125,42 +116,20 @@ def update_assignments(l, assignment_nodes, source, lattice):
 
 def append_if_reassigned(l, secondary, node, lattice):
     try:
-        logger.debug("[DED]secondary is %s", secondary)
-        logger.debug("[DED]node is %s", node)
-        logger.debug("[DED] So lattice.in_constraint is %s", lattice.in_constraint(secondary, node))
-        logger.debug("[DED]type(node) is %s", type(node))
-        logger.debug("[DED]node.left_hand_side is %s", node.left_hand_side)
-        logger.debug("[DED]node.right_hand_side_variables is %s", node.right_hand_side_variables)
-        if node.vv_result:
-            logger.debug("[DED]node.vv_result is %s", node.vv_result)
-
         # vv_result is necessary to know `image_name = image_name.replace('..', '')` is a reassignment.
         if node.vv_result:
-            logger.debug("[DED] IMPORTANT secondary.left_hand_side is %s and node.vv_result is %s", secondary.left_hand_side, node.vv_result)
             if secondary.left_hand_side in node.vv_result:
-                logger.debug("Hmm, reaches `if secondary.left_hand_side in node.vv_result`")
-                # if node.left_hand_side in node.vv_result:
                 if lattice.in_constraint(secondary, node):
-                    logger.debug("IPHONE")
                     l.append(node)
                     return
         elif secondary.left_hand_side in node.right_hand_side_variables:
             if lattice.in_constraint(secondary, node):
-                logger.debug("Added")
                 l.append(node)
                 return
         if secondary.left_hand_side == node.left_hand_side:
             if lattice.in_constraint(secondary, node):
-                logger.debug("Added")
                 l.append(node)
                 return
-            else:
-                logger.debug("So node %s is not in the constraint of secondary %s", node, secondary)
-                logger.debug("So node.ingoing is %s ", node.ingoing)
-                logger.debug("So node.outgoing is %s ", node.outgoing)
-                logger.debug("So secondary.ingoing is %s ", secondary.ingoing)
-                logger.debug("So secondary.outgoing is %s ", secondary.outgoing)
-        logger.debug("Not added")
     except AttributeError:
         print(secondary)
         print('EXCEPT' + secondary)
@@ -287,17 +256,12 @@ def get_sink_args(cfg_node):
     if isinstance(cfg_node.ast_node, ast.Call):
         rhs_visitor = RHSVisitor()
         rhs_visitor.visit(cfg_node.ast_node)
-        logger.debug("returning rhs_visitor.result %s", rhs_visitor.result)
         return rhs_visitor.result
     elif isinstance(cfg_node.ast_node, ast.Assign):
-        logger.debug("returning cfg_node.right_hand_side_variables %s", cfg_node.right_hand_side_variables)
         return cfg_node.right_hand_side_variables
-    else:
-        vv = VarsVisitor()
-        logger.debug("So cfg_node.ast_node is %s", cfg_node.ast_node)
-        logger.debug("So type of cfg_node.ast_node is %s", type(cfg_node.ast_node))
-        vv.visit(cfg_node.ast_node)
-        logger.debug("So vv.result is %s", vv.result)
+
+    vv = VarsVisitor()
+    vv.visit(cfg_node.ast_node)
     return vv.result
 
 
@@ -321,15 +285,6 @@ def get_vulnerability(source, sink, triggers, lattice, trim_reassigned_in, black
 
     secondary_in_sink = list()
 
-    logger.debug("[vuln] Hmm so source.secondary_nodes is %s", source.secondary_nodes)
-    logger.debug("[vuln] Hmm so source is %s", source)
-    logger.debug("[vuln] Hmm so source.cfg_node is %s", source.cfg_node)
-
-    for node in source.secondary_nodes:
-        if lattice.in_constraint(source.cfg_node, node):
-            logger.debug("secondary node %s is reachable from %s", node, source.cfg_node)
-        else:
-            logger.debug("secondary node %s is NOT reachable from %s", node, source.cfg_node)
     if source.secondary_nodes:
         secondary_in_sink = [secondary for secondary in source.secondary_nodes
                              if lattice.in_constraint(secondary,
@@ -338,7 +293,6 @@ def get_vulnerability(source, sink, triggers, lattice, trim_reassigned_in, black
     trigger_node_in_sink = source_in_sink or secondary_in_sink
 
     sink_args = get_sink_args(sink.cfg_node)
-    logger.debug(".... so sink_args is %s", sink_args)
     secondary_node_in_sink_args = None
     if sink_args:
         for node in secondary_in_sink:

tests/cfg_test.py

@@ -1,8 +1,6 @@
 from .base_test_case import BaseTestCase
 from pyt.base_cfg import EntryOrExitNode, Node
 # from pyt.project_handler import get_modules
-from pyt.utils.log import enable_logger, logger
-enable_logger(to_file='./pyt.log')
 
 
 class CFGGeneralTest(BaseTestCase):
@@ -178,8 +176,6 @@ def test_orelse(self):
         self.cfg_create_from_file('example/example_inputs/try_orelse.py')
 
         self.nodes = self.cfg_list_to_dict(self.cfg.nodes)
-        logger.debug("Nodes are")
-        logger.debug(self.cfg.nodes)
         self.assert_length(self.cfg.nodes, expected_length=18)
 
         entry = 0
@@ -778,7 +774,6 @@ def test_call_with_attribute(self):
         self.assertEqual(call.label, "request.args.get('param', 'not set')")
 
         l = zip(range(1, length), range(length))
-        logger.debug("self.cfg.nodes is %s", self.cfg.nodes)
         self.assertInCfg(list(l))
 
     def test_call_with_attribute_line_numbers(self):